[강운덕] [LUCYSUS-1744] Span 데이터 구조를 api 호출 방식으로 변경하기 위해서 start end time위주로 변경함.

git-svn-id: http://svn.bds.nhncorp.com/pe/hippo-tomcat-profiler/trunk@874 84d0f5b1-2673-498c-a247-62c4ff18d310
This commit is contained in:
Woonduk Kang
2012-11-19 08:09:14 +00:00
parent b8c73bfdef
commit 6ca5154931
11 changed files with 116 additions and 101 deletions
@@ -1,15 +1,22 @@
package com.profiler.context;
public enum Annotation {
ClientSend("CS"), ClientRecv("CR"), ServerSend("SS"), ServerRecv("SR");
@Deprecated
ClientSend("CS"),
@Deprecated
ClientRecv("CR"),
@Deprecated
ServerSend("SS"),
@Deprecated
ServerRecv("SR");
private String code;
private String code;
Annotation(String code) {
this.code = code;
}
Annotation(String code) {
this.code = code;
}
public String getCode() {
return this.code;
}
public String getCode() {
return this.code;
}
}
@@ -1,18 +1,20 @@
package com.profiler.context;
import java.util.Arrays;
import java.util.logging.Level;
import java.util.logging.Logger;
/**
* @author netspider
*/
public class CallStack {
// CallStack을 동시성 환경에서 복사해서 볼수 있는 방법이 필요함.
private StackFrame[] stack = new StackFrame[4];
// 추적 depth크기 제한을 위해서 필요. 해당 사이즈를 넘어갈경우 부드럽게 트레이스를 무시하는 로직이 필요함.
private final int TRACE_STACK_MAX_SIZE = 64;
private int index = 0;
private int index = -1;
// copy시의 락 생각할 경우 좀더 정교하게 잡을수 있을듯.
// push, pop, copy만 락을 잡아도 될거 같은 생각이 듬.
@@ -46,9 +48,16 @@ public class CallStack {
}
public synchronized void pop() {
if (index > 0) {
if (index >= 0) {
stack[index] = null;
index--;
} else {
Logger logger = Logger.getLogger(this.getClass().getName());
if (logger.isLoggable(Level.WARNING)) {
// 자체 stack dump 필요.
Exception ex = new Exception("Profiler CallStack check. index:" + index);
logger.log(Level.WARNING, "invalid callStack found", ex);
}
}
}
+24 -24
View File
@@ -1,10 +1,7 @@
package com.profiler.context;
import java.util.ArrayList;
import java.util.HashSet;
import java.util.List;
import java.util.Set;
import java.util.TimerTask;
import com.profiler.Agent;
@@ -16,7 +13,10 @@ import com.profiler.Agent;
public class Span {
private final TraceID traceID;
private final long createTime;
private long startTime;
private long endTime;
private String serviceName;
private String name;
@@ -25,23 +25,18 @@ public class Span {
private final List<HippoAnnotation> annotations = new ArrayList<HippoAnnotation>(5);
private long rpcStartTime;
private long rpcEndTime;
public Span(TraceID traceId, String name, String endPoint) {
this.traceID = traceId;
this.name = name;
this.endPoint = endPoint;
this.createTime = System.currentTimeMillis();
}
public TraceID getTraceID() {
return traceID;
}
public boolean addAnnotation(HippoAnnotation annotation) {
if (annotation.getKey().equals(Annotation.ClientSend.getCode()) || annotation.getKey().equals(Annotation.ServerRecv.getCode())) {
rpcStartTime = annotation.getTimestamp();
}
if (annotation.getKey().equals(Annotation.ClientRecv.getCode()) || annotation.getKey().equals(Annotation.ServerSend.getCode())) {
rpcEndTime = annotation.getTimestamp();
}
return annotations.add(annotation);
}
@@ -82,25 +77,29 @@ public class Span {
this.isTerminal = isTerminal;
}
public long getRpcStartTime() {
return rpcStartTime;
public void setStartTime(long startTime) {
this.startTime = startTime;
}
public long getRpcEndTime() {
return rpcEndTime;
public long getStartTime() {
return startTime;
}
public long getCreateTime() {
return createTime;
public void setEndTime(long endTime) {
this.endTime = endTime;
}
public long getEndTime() {
return endTime;
}
public String toString() {
StringBuilder sb = new StringBuilder();
sb.append("{");
sb.append("\n\t TraceID = ").append(traceID);
sb.append(",\n\t CreateTime = ").append(createTime);
sb.append(",\n\t StartTime = ").append(startTime);
sb.append(",\n\t EndTime = ").append(endTime);
sb.append(",\n\t Name = ").append(name);
sb.append(",\n\t ServiceName = ").append(serviceName);
sb.append(",\n\t EndPoint = ").append(endPoint);
@@ -120,7 +119,9 @@ public class Span {
com.profiler.common.dto.thrift.Span span = new com.profiler.common.dto.thrift.Span();
span.setAgentId(Agent.getInstance().getAgentId());
span.setTimestamp(createTime);
span.setTimestamp(startTime);
// TODO api를 생성하고 여기를 고치자.
//span.setEndTime(startTime);
span.setMostTraceId(traceID.getId().getMostSignificantBits());
span.setLeastTraceId(traceID.getId().getLeastSignificantBits());
span.setName(name);
@@ -130,8 +131,7 @@ public class Span {
span.setEndPoint(endPoint);
span.setTerminal(isTerminal);
// TODO: set duration.
// 여기서 데이터 인코딩을 하자.
List<com.profiler.common.dto.thrift.Annotation> annotationList = new ArrayList<com.profiler.common.dto.thrift.Annotation>(annotations.size());
for (HippoAnnotation a : annotations) {
annotationList.add(a.toThrift());
@@ -4,21 +4,17 @@ package com.profiler.context;
*
*/
public class StackFrame {
private TraceID traceID;
private int stackId;
private long time;
private Span span;
public StackFrame() {
public StackFrame(Span span) {
this.span = span;
}
public TraceID getTraceID() {
return traceID;
}
public void setTraceID(TraceID traceID) {
this.traceID = traceID;
return span.getTraceID();
}
public int getStackFrameId() {
@@ -30,15 +26,17 @@ public class StackFrame {
}
public void markBeforeTime() {
this.time = System.currentTimeMillis();
this.span.setStartTime(System.currentTimeMillis());
}
public void markAfterTime() {
this.span.setEndTime(System.currentTimeMillis());
}
public long afterTime() {
return System.currentTimeMillis() - this.time;
}
public long getTime() {
return this.time;
long end = System.currentTimeMillis();
this.span.setEndTime(end);
return end - this.span.getStartTime();
}
+27 -26
View File
@@ -34,6 +34,7 @@ public final class Trace {
// traceObject에서 spanid의 유효성을 히스토리를 관리한다면 같은 thread에서는 span랜덤생성아이디의 충돌을 방지할수 있기는 함.
this.root = TraceID.newTraceId();
this.callStack = new CallStack();
this.callStack.push();
StackFrame stackFrame = createStackFrame(root, ROOT_STACKID);
this.callStack.setStackFrame(stackFrame);
}
@@ -41,6 +42,7 @@ public final class Trace {
public Trace(TraceID continueRoot) {
this.root = continueRoot;
this.callStack = new CallStack();
this.callStack.push();
StackFrame stackFrame = createStackFrame(continueRoot, ROOT_STACKID);
this.callStack.setStackFrame(stackFrame);
}
@@ -76,12 +78,9 @@ public final class Trace {
}
private StackFrame createStackFrame(TraceID nextId, int stackId) {
StackFrame stackFrame = new StackFrame();
stackFrame.setStackFrameId(stackId);
stackFrame.setTraceID(nextId);
Span span = new Span(nextId, null, null);
stackFrame.setSpan(span);
StackFrame stackFrame = new StackFrame(span);
stackFrame.setStackFrameId(stackId);
return stackFrame;
}
@@ -115,12 +114,22 @@ public final class Trace {
traceBlockEnd(NOCHECK_STACKID);
}
// public void traceBlockFinalEnd() {
// StackFrame currentStackFrame = callStack.getCurrentStackFrame();
// if (currentStackFrame.getStackFrameId() != ROOT_STACKID) {
// // 자체 stack dump를 하면 오류발견이 쉬울것으로 생각됨.
// logger.warning("Corrupted RootCallStack found. StackId not matched");
// }
// logSpan(currentStackFrame);
// }
public void traceBlockEnd(int stackId) {
StackFrame currentStackFrame = callStack.getCurrentStackFrame();
if (currentStackFrame.getStackFrameId() != stackId) {
// 자체 stack dump를 하면 오류발견이 쉬울것으로 생각됨.
logger.warning("Corrupted CallStack found. StackId not matched");
}
logSpan(currentStackFrame);
callStack.pop();
}
@@ -128,16 +137,16 @@ public final class Trace {
return callStack.getCurrentStackFrame();
}
public boolean removeCurrentTraceIdFromStack() {
StackFrame currentStackFrame = callStack.getCurrentStackFrame();
if (currentStackFrame != null) {
TraceID traceId = currentStackFrame.getTraceID();
callStack.currentStackFrameClear();
// spanMap.remove(traceId);
return true;
}
return false;
}
// public boolean removeCurrentTraceIdFromStack() {
// StackFrame currentStackFrame = callStack.getCurrentStackFrame();
// if (currentStackFrame != null) {
// TraceID traceId = currentStackFrame.getTraceID();
// callStack.currentStackFrameClear();
//// spanMap.remove(traceId);
// return true;
// }
// return false;
// }
/**
* Get current TraceID. If it was not set this will return null.
@@ -162,16 +171,8 @@ public final class Trace {
}
private void logSpan(String key, Span span) {
if (key == null) {
return;
}
if (key.equals(Annotation.ClientRecv.getCode()) || key.equals(Annotation.ServerSend.getCode())) {
logSpan(span);
}
}
void logSpan(Span span) {
void logSpan(StackFrame stackFrame) {
Span span = stackFrame.getSpan();
try {
if (logger.isLoggable(Level.INFO)) {
logger.info("[WRITE SPAN]" + span + " CurrentThreadID=" + Thread.currentThread().getId() + ",\n\t CurrentThreadName=" + Thread.currentThread().getName() + "\n\n");
@@ -272,7 +273,7 @@ public final class Trace {
try {
Span span = getCurrentStackFrame().getSpan();
span.addAnnotation(new HippoAnnotation(System.currentTimeMillis(), key, duration));
logSpan(key, span);
} catch (Exception e) {
logger.log(Level.SEVERE, e.getMessage(), e);
}
@@ -35,16 +35,15 @@ public class TraceContext {
return threadLocal.get();
}
public Trace attachTraceObject(TraceID traceID) {
Trace trace = this.threadLocal.get();
if (trace == null) {
// TraceID traceID = TraceID.newTraceId();
Trace newTrace = new Trace(traceID);
newTrace.setDataSender(this.dataSender);
threadLocal.set(newTrace);
return newTrace;
public void attachTraceObject(Trace trace) {
Trace old = this.threadLocal.get();
if (old != null) {
// 잘못된 상황의 old를 덤프할것.
throw new IllegalStateException("already Trace Object exist.");
}
throw new IllegalStateException("already Trace Object exist");
// datasender연결 부분 수정 필요.
trace.setDataSender(this.dataSender);
threadLocal.set(trace);
}
public void detachTraceObject() {
@@ -2,7 +2,6 @@ package com.profiler.modifier.arcus.interceptors;
import com.profiler.context.Annotation;
import com.profiler.context.AsyncTrace;
import com.profiler.context.TraceContext;
import com.profiler.interceptor.StaticBeforeInterceptor;
import com.profiler.util.InterceptorUtils;
import com.profiler.util.MetaObject;
@@ -65,7 +64,7 @@ public class BaseOperationTransitionStateInterceptor implements StaticBeforeInte
TimeObject timeObject = (TimeObject) asyncTrace.getAttachObject();
timeObject.markSendTime();
long createTime = asyncTrace.getSpan().getCreateTime();
long createTime = asyncTrace.getSpan().getStartTime();
asyncTrace.record(Annotation.ClientSend, System.currentTimeMillis() - createTime);
} else if (newState == OperationState.COMPLETE || newState == OperationState.TIMEDOUT) {
if (logger.isLoggable(Level.FINE)) {
@@ -12,8 +12,9 @@ import java.util.logging.Logger;
public class ConnectionCloseInterceptor implements StaticBeforeInterceptor {
private final Logger logger = Logger.getLogger(ConnectionCloseInterceptor.class.getName());
private static final Object[] EMPTY = new Object[]{null};
private final MetaObject setUrl = new MetaObject("__setUrl", String.class);
private final MetaObject setUrl = new MetaObject("__setUrl", Object.class);
@Override
public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) {
@@ -26,7 +27,7 @@ public class ConnectionCloseInterceptor implements StaticBeforeInterceptor {
}
// close의 경우 호출이 실패하더라도 데이터를 삭제해야함.
if (target instanceof Connection) {
this.setUrl.invoke(target, new Object[]{null});
this.setUrl.invoke(target, EMPTY);
}
}
}
@@ -56,7 +56,7 @@ public class PreparedStatementExecuteQueryInterceptor implements StaticAroundInt
Map bindValue = getBindValue.invoke(target);
String bindString = toBindVariable(bindValue);
trace.recordAttribute("BindValue", bindString);
trace.recordAttribute("API", descriptor.getClassName() + "." + descriptor.getMethodName() + descriptor.getSimpleParameterDescriptor());
trace.recordAttribute("API", descriptor.getClassName() + "." + descriptor.getMethodName() + descriptor.getSimpleParameterDescriptor() + ":" + descriptor.getLineNumber());
clean(target);
@@ -40,19 +40,19 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept
TraceID traceId = populateTraceIdFromRequest(request);
Trace trace;
if (traceId != null) {
TraceID nextTraceId = traceId.getNextTraceId();
trace = new Trace(traceId);
if (logger.isLoggable(Level.INFO)) {
logger.info("TraceID exist. continue trace. " + nextTraceId);
logger.info("TraceID exist. continue trace. " + trace.getCurrentTraceId());
logger.log(Level.FINE, "requestUrl:" + requestURL + " clientIp" + clientIP + " parameter:" + parameters);
}
trace = traceContext.attachTraceObject(nextTraceId);
traceContext.attachTraceObject(trace);
} else {
TraceID newTraceID = TraceID.newTraceId();
trace = new Trace();
if (logger.isLoggable(Level.INFO)) {
logger.info("TraceID not exist. start new trace. " + newTraceID);
logger.info("TraceID not exist. start new trace. " + trace.getCurrentTraceId());
logger.log(Level.FINE, "requestUrl:" + requestURL + " clientIp" + clientIP + " parameter:" + parameters);
}
trace = traceContext.attachTraceObject(newTraceID);
traceContext.attachTraceObject(trace);
}
trace.markBeforeTime();
@@ -90,7 +90,7 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept
}
// TODO result 가 Exception 타입일경우 호출 실패임.
trace.record(Annotation.ServerSend, trace.afterTime());
trace.traceBlockEnd();
}
/**