diff --git a/src/main/java/com/profiler/Agent.java b/src/main/java/com/profiler/Agent.java index 50b70e5f1..2094da5a4 100644 --- a/src/main/java/com/profiler/Agent.java +++ b/src/main/java/com/profiler/Agent.java @@ -119,8 +119,10 @@ public class Agent { public void start() { logger.info("Starting HIPPO Agent."); // trace context 새롭게 생성. - TraceContext.initialize(); this.dataSender = UdpDataSender.getInstance(); + // TraceContext의 생명주기 관리 방안이 없는지 강구. + TraceContext traceContext = TraceContext.getTraceContext(); + traceContext.setDataSender(this.dataSender); systemMonitor.setDataSender(dataSender); systemMonitor.start(); } diff --git a/src/main/java/com/profiler/StopWatch.java b/src/main/java/com/profiler/StopWatch.java index 2c8226cf4..af4c11a0d 100644 --- a/src/main/java/com/profiler/StopWatch.java +++ b/src/main/java/com/profiler/StopWatch.java @@ -5,49 +5,50 @@ import java.util.Map; import com.profiler.util.NamedThreadLocal; +@Deprecated public class StopWatch { - private static ThreadLocal> local = new NamedThreadLocal>("StopWatch"); + private static ThreadLocal> local = new NamedThreadLocal>("StopWatch"); - public static void start(int id) { - start(String.valueOf(id)); - } + public static void start(int id) { + start(String.valueOf(id)); + } - public static long stopAndGetElapsed(int id) { - return stopAndGetElapsed(String.valueOf(id)); - } + public static long stopAndGetElapsed(int id) { + return stopAndGetElapsed(String.valueOf(id)); + } - public static void start(String id) { - Map map = local.get(); - if (map == null) { - map = new HashMap(1); - map.put(id, System.nanoTime()); - local.set(map); - } else { - map.put(id, System.nanoTime()); - } - } + public static void start(String id) { + Map map = local.get(); + if (map == null) { + map = new HashMap(1); + map.put(id, System.nanoTime()); + local.set(map); + } else { + map.put(id, System.nanoTime()); + } + } - public static long stopAndGetElapsed(String id) { - Map map = local.get(); - if (map == null) { - // throw new IllegalStateException("Stopwatch is not started."); - // TODO application 에러로 전달되는경우가 있어서 일단 0으로 - return -1; - } else { - Long startTime = map.get(id); + public static long stopAndGetElapsed(String id) { + Map map = local.get(); + if (map == null) { + // throw new IllegalStateException("Stopwatch is not started."); + // TODO application 에러로 전달되는경우가 있어서 일단 0으로 + return -1; + } else { + Long startTime = map.get(id); - map.remove(id); - // TODO: if using thread pool, this is unnecessary. - // if (map.size() == 0) { - // local.remove(); - // } + map.remove(id); + // TODO: if using thread pool, this is unnecessary. + // if (map.size() == 0) { + // local.remove(); + // } - if (startTime != null) { - return System.nanoTime() - startTime; - } else { - return -1; - } - } - } + if (startTime != null) { + return System.nanoTime() - startTime; + } else { + return -1; + } + } + } } diff --git a/src/main/java/com/profiler/context/CallStack.java b/src/main/java/com/profiler/context/CallStack.java new file mode 100644 index 000000000..18e17bf55 --- /dev/null +++ b/src/main/java/com/profiler/context/CallStack.java @@ -0,0 +1,53 @@ +package com.profiler.context; + +/** + * @author netspider + */ +public class CallStack { + // CallStack을 동시성 환경에서 복사해서 볼수 있는 방법이 필요함. + private StackFrame[] stack = new StackFrame[4]; + + // TODO 개별변수에 volatile을해도 동시성이 해결되지 않으므로 일단 제거. + private int index = 0; + + + public StackFrame getCurrentStackFrame() { + return stack[index]; + } + + public StackFrame getParentStackFrame() { + if (index > 0) { + return stack[index - 1]; + } + return null; + } + + + public void setStackFrame(StackFrame stackFrame) { + stack[index] = stackFrame; + } + + public void push() { + index++; + if (index > stack.length - 1) { + StackFrame[] old = stack; + stack = new StackFrame[index + 4]; + System.arraycopy(old, 0, stack, 0, old.length); + } + } + + public int getStackFrameIndex() { + return index; + } + + public void pop() { + if (index > 0) { +// TODO 이전 reference를 제거해야 되나? + index--; + } + } + + public void currentStackFrameClear() { + stack[index] = null; + } +} diff --git a/src/main/java/com/profiler/context/DeadlineSpanMap.java b/src/main/java/com/profiler/context/DeadlineSpanMap.java index d2174854f..fdc33463d 100644 --- a/src/main/java/com/profiler/context/DeadlineSpanMap.java +++ b/src/main/java/com/profiler/context/DeadlineSpanMap.java @@ -7,52 +7,52 @@ import java.util.concurrent.ConcurrentMap; public class DeadlineSpanMap { - private static final long FLUSH_TIMEOUT = 120000L; // 2 minutes + private static final long FLUSH_TIMEOUT = 120000L; // 2 minutes - private final ConcurrentMap map = new ConcurrentHashMap(256); + private final ConcurrentMap map = new ConcurrentHashMap(256); - private final Timer timer = new Timer(true); + private final Timer timer = new Timer(true); - public Span update(TraceID traceId, SpanUpdater spanUpdater) { - TraceID.TraceKey traceIdKey = traceId.getTraceKey(); - Span span = map.get(traceIdKey); + public Span update(TraceID traceId, SpanUpdater spanUpdater) { + TraceID.TraceKey traceIdKey = traceId.getTraceKey(); + Span span = map.get(traceIdKey); - if (span == null) { - span = new Span(traceId, null, null); - map.put(traceIdKey, span); + if (span == null) { + span = new Span(traceId, null, null); + map.put(traceIdKey, span); - TimerTask task = new FlushTimedoutSpanTask(span); - span.setTimerTask(task); + TimerTask task = new FlushTimedoutSpanTask(span); + span.setTimerTask(task); - timer.schedule(task, FLUSH_TIMEOUT); - } + timer.schedule(task, FLUSH_TIMEOUT); + } - return spanUpdater.updateSpan(span); - } + return spanUpdater.updateSpan(span); + } - public Span remove(TraceID traceId) { - return map.remove(traceId.getTraceKey()); - } + public Span remove(TraceID traceId) { + return map.remove(traceId.getTraceKey()); + } - public int size() { - return map.size(); - } + public int size() { + return map.size(); + } - private static final class FlushTimedoutSpanTask extends TimerTask { - private final Span span; + private static final class FlushTimedoutSpanTask extends TimerTask { + private final Span span; - public FlushTimedoutSpanTask(Span span) { - this.span = span; - } + public FlushTimedoutSpanTask(Span span) { + this.span = span; + } - @Override - public void run() { - Trace.logSpan(this.span); - } - } + @Override + public void run() { +// Trace.logSpan(this.span); + } + } - @Override - public String toString() { - return map.toString(); - } + @Override + public String toString() { + return map.toString(); + } } diff --git a/src/main/java/com/profiler/context/StackFrame.java b/src/main/java/com/profiler/context/StackFrame.java new file mode 100644 index 000000000..33dc0028c --- /dev/null +++ b/src/main/java/com/profiler/context/StackFrame.java @@ -0,0 +1,52 @@ +package com.profiler.context; + +/** + * + */ +public class StackFrame { + private TraceID traceID; + private int stackId; + private long time; + private Span span; + + public StackFrame() { + } + + + public TraceID getTraceID() { + return traceID; + } + + public void setTraceID(TraceID traceID) { + this.traceID = traceID; + } + + public int getStackFrameId() { + return stackId; + } + + public void setStackFrameId(int stackId) { + this.stackId = stackId; + } + + public void markBeforeTime() { + this.time = System.currentTimeMillis(); + } + + public long afterTime() { + return System.currentTimeMillis() - this.time; + } + + public long getTime() { + return this.time; + } + + + public void setSpan(Span span) { + this.span = span; + } + + public Span getSpan() { + return span; + } +} diff --git a/src/main/java/com/profiler/context/Trace.java b/src/main/java/com/profiler/context/Trace.java index ec611b170..b63924968 100644 --- a/src/main/java/com/profiler/context/Trace.java +++ b/src/main/java/com/profiler/context/Trace.java @@ -3,8 +3,7 @@ package com.profiler.context; import com.profiler.common.util.AnnotationTranscoder; import com.profiler.common.util.AnnotationTranscoder.Encoded; import com.profiler.sender.DataSender; -import com.profiler.sender.UdpDataSender; -import com.profiler.util.NamedThreadLocal; +import com.profiler.sender.LoggingDataSender; import java.util.logging.Level; import java.util.logging.Logger; @@ -14,118 +13,117 @@ import java.util.logging.Logger; */ public final class Trace { - private static final Logger logger = Logger.getLogger(Trace.class.getName()); + private final Logger logger = Logger.getLogger(Trace.class.getName()); - private static final DeadlineSpanMap spanMap = new DeadlineSpanMap(); - private static final ThreadLocal traceIdLocal = new NamedThreadLocal("TraceId"); - private static volatile boolean tracingEnabled = true; + public static final int HANDLER_STACKID = -2; + public static final int NOCHECK_STACKID = -1; + public static final int ROOT_STACKID = 0; + // private static final DeadlineSpanMap spanMap = new DeadlineSpanMap(); + // private static final ThreadLocal traceIdLocal = new NamedThreadLocal("TraceId"); + private boolean tracingEnabled = true; + + private TraceID root; + private CallStack callStack; private static final AnnotationTranscoder transcoder = new AnnotationTranscoder(); + private static final DataSender DEFULT_DATA_SENDER = new LoggingDataSender(); + private DataSender dataSender = DEFULT_DATA_SENDER; - private Trace() { + public Trace() { + this.root = TraceID.newTraceId(); + this.callStack = new CallStack(); + StackFrame stackFrame = createCallInfo(root, ROOT_STACKID); + this.callStack.setStackFrame(stackFrame); } - public static void handle(TraceHandler handler) { - TraceIDStack traceIDStack = traceIdLocal.get(); - if (traceIDStack == null) { - traceIDStack = new TraceIDStack(); - traceIdLocal.set(traceIDStack); - } + public Trace(TraceID continueRoot) { + this.root = continueRoot; + this.callStack = new CallStack(); + StackFrame stackFrame = createCallInfo(continueRoot, ROOT_STACKID); + this.callStack.setStackFrame(stackFrame); + } + public DataSender getDataSender() { + return dataSender; + } + + public void setDataSender(DataSender dataSender) { + this.dataSender = dataSender; + } + + public void handle(TraceHandler handler) { try { TraceID nextId = getNextTraceId(); - traceIDStack.push(); - - if (traceIDStack.getTraceId() == null) { - if (logger.isLoggable(Level.FINE)) { - logger.fine(getCurrentTraceId().toString()); - } - traceIDStack.setTraceId(nextId); - } - - handler.handle(); + callStack.push(); + StackFrame stackFrame = createCallInfo(nextId, HANDLER_STACKID); + callStack.setStackFrame(stackFrame); + handler.handle(nextId); } catch (Exception e) { e.printStackTrace(); } finally { - traceIDStack.pop(); + // stackID check하면 좋을듯. + callStack.pop(); } } - public static void traceBlockBegin() { - TraceIDStack traceIDStack = traceIdLocal.get(); - if (traceIDStack == null) { - traceIDStack = new TraceIDStack(); - traceIdLocal.set(traceIDStack); - } + private StackFrame createCallInfo(TraceID nextId, int stackId) { + StackFrame stackFrame = new StackFrame(); + stackFrame.setStackFrameId(stackId); + stackFrame.setTraceID(nextId); + Span span = new Span(nextId, null, null); + stackFrame.setSpan(span); + return stackFrame; + } + + public void traceBlockBegin() { + traceBlockBegin(NOCHECK_STACKID); + } + + public void markBeforeTime() { + StackFrame context = getCurrentStackContext(); + context.markBeforeTime(); + } + + public long afterTime() { + StackFrame context = getCurrentStackContext(); + return context.afterTime(); + } + + public void traceBlockBegin(int stackId) { try { TraceID nextId = getNextTraceId(); - traceIDStack.push(); - - if (traceIDStack.getTraceId() == null) { - traceIDStack.setTraceId(nextId); - } + callStack.push(); + StackFrame stackFrame = createCallInfo(nextId, stackId); + callStack.setStackFrame(stackFrame); } catch (Exception e) { e.printStackTrace(); } } - public static void traceBlockEnd() { - TraceIDStack traceIDStack = traceIdLocal.get(); - traceIDStack.pop(); + public void traceBlockEnd() { + traceBlockEnd(NOCHECK_STACKID); } - /** - * Get current TraceID or if's not exists create new one and return it. - * - * @return - */ - public static TraceID getTraceIdOrCreateNew() { - // TraceID id = traceIdLocal.get(); - TraceIDStack stack = traceIdLocal.get(); - TraceID id = null; - if (stack != null) { - id = stack.getTraceId(); + public void traceBlockEnd(int stackId) { + StackFrame currentStackFrame = callStack.getCurrentStackFrame(); + if (currentStackFrame.getStackFrameId() != stackId) { + // 자체 stack dump를 하면 오류발견이 쉬울것으로 생각됨. + logger.warning("Corrupted CallStack found. StackId not matched"); } - - if (id == null) { - id = TraceID.newTraceId(); - if (logger.isLoggable(Level.INFO)) { - logger.info("create new traceid:" + id); - } - - if (stack == null) { - traceIdLocal.set(new TraceIDStack()); - } - - traceIdLocal.get().setTraceId(id); - return id; - } - - return id; + callStack.pop(); } - public static boolean removeCurrentTraceIdFromStack() { - TraceIDStack stack = traceIdLocal.get(); - TraceID traceId = null; + public StackFrame getCurrentStackContext() { + return callStack.getCurrentStackFrame(); + } - if (stack != null) { - traceId = stack.getTraceId(); - } else { - if (logger.isLoggable(Level.FINE)) { - logger.log(Level.FINE, - "#############################################################" + - "\n# Something's going wrong. Stack is not exists. #" + - "\n#############################################################"); - } - - stack = new TraceIDStack(); - traceIdLocal.set(stack); - } - - if (traceId != null) { - stack.clear(); - spanMap.remove(traceId); + public boolean removeCurrentTraceIdFromStack() { + StackFrame currentStackFrame = callStack.getCurrentStackFrame(); + if (currentStackFrame != null) { + TraceID traceId = currentStackFrame.getTraceID(); + callStack.currentStackFrameClear(); +// spanMap.remove(traceId); return true; } return false; @@ -136,66 +134,38 @@ public final class Trace { * * @return */ - public static TraceID getCurrentTraceId() { - // return traceIdLocal.get(); - TraceIDStack stack = traceIdLocal.get(); - - if (stack == null) { - return null; - } - - return stack.getTraceId(); + public TraceID getCurrentTraceId() { + return callStack.getCurrentStackFrame().getTraceID(); } - public static void enable() { + public void enable() { tracingEnabled = true; } - public static void disable() { + public void disable() { tracingEnabled = false; } - public static TraceID getNextTraceId() { - TraceID current = getTraceIdOrCreateNew(); + public TraceID getNextTraceId() { + TraceID current = getCurrentTraceId(); return current.getNextTraceId(); } - public static void setTraceId(TraceID traceId) { - if (getCurrentTraceId() != null) { - if (logger.isLoggable(Level.FINE)) { - logger.log(Level.FINE, - "###############################################################################################################" + - "\n# [DEBUG MSG] TraceID is overwritten." + - "\n# Before : " + getCurrentTraceId() + - "\n# After : " + traceId + - "\n###############################################################################################################"); - new RuntimeException("TraceID overwritten.").printStackTrace(); - } - } - - TraceIDStack stack = traceIdLocal.get(); - - if (stack == null) - traceIdLocal.set(new TraceIDStack()); - - Trace.traceIdLocal.get().setTraceId(traceId); - // Trace.traceIdLocal.set(traceId); - } - - private static void mutate(TraceID traceId, SpanUpdater spanUpdater) { - Span span = spanMap.update(traceId, spanUpdater); + private void spanUpdate(SpanUpdater spanUpdater) { + StackFrame currentStackFrame = getCurrentStackContext(); + Span span = spanUpdater.updateSpan(currentStackFrame.getSpan()); if (span.isExistsAnnotationKey(Annotation.ClientRecv.getCode()) || span.isExistsAnnotationKey(Annotation.ServerSend.getCode())) { - // remove current context threadId from stack - removeCurrentTraceIdFromStack(); + // remove current context threadId from callStack +// removeCurrentTraceIdFromStack(); logSpan(span); } } - static void logSpan(Span span) { + void logSpan(Span span) { try { - if (logger.isLoggable(Level.FINE)) { - logger.info("[WRITE SPAN]" + span + " size=" + spanMap.size() + " CurrentThreadID=" + Thread.currentThread().getId() + ",\n\t CurrentThreadName=" + Thread.currentThread().getName() + "\n\n"); + if (logger.isLoggable(Level.INFO)) { + logger.info("[WRITE SPAN]" + span + " CurrentThreadID=" + Thread.currentThread().getId() + ",\n\t CurrentThreadName=" + Thread.currentThread().getName() + "\n\n"); } // TODO: remove this, just for debugging @@ -206,38 +176,38 @@ public final class Trace { // System.out.println("current spamMap=" + spanMap); // } - UdpDataSender.getInstance().send(span.toThrift()); - - span.cancelTimer(); + dataSender.send(span.toThrift()); +// span.cancelTimer(); } catch (Exception e) { logger.log(Level.SEVERE, e.getMessage(), e); } } - public static void record(Annotation annotation) { + public void record(Annotation annotation) { if (!tracingEnabled) return; annotate(annotation.getCode(), null); } - public static void record(Annotation annotation, long duration) { + public void record(Annotation annotation, long duration) { if (!tracingEnabled) return; annotate(annotation.getCode(), duration); } - public static void recordAttribute(final String key, final String value) { + public void recordAttribute(final String key, final String value) { recordAttibute(key, (Object) value); } - public static void recordAttibute(final String key, final Object value) { + public void recordAttibute(final String key, final Object value) { if (!tracingEnabled) return; try { - mutate(getTraceIdOrCreateNew(), new SpanUpdater() { + + spanUpdate(new SpanUpdater() { @Override public Span updateSpan(Span span) { // TODO 사용자 thread에서 encoding을 하지 않도록 변경. @@ -251,19 +221,19 @@ public final class Trace { } } - public static void recordMessage(String message) { + public void recordMessage(String message) { if (!tracingEnabled) return; annotate(message, null); } - public static void recordRpcName(final String service, final String rpc) { + public void recordRpcName(final String service, final String rpc) { if (!tracingEnabled) return; try { - mutate(getTraceIdOrCreateNew(), new SpanUpdater() { + spanUpdate(new SpanUpdater() { @Override public Span updateSpan(Span span) { span.setServiceName(service); @@ -276,21 +246,21 @@ public final class Trace { } } - public static void recordTerminalEndPoint(final String endPoint) { + public void recordTerminalEndPoint(final String endPoint) { recordEndPoint(endPoint, true); } - public static void recordEndPoint(final String endPoint) { + public void recordEndPoint(final String endPoint) { recordEndPoint(endPoint, false); } // TODO: final String... endPoint로 받으면 합치는데 비용이 들어가 그냥 한번에 받는게 나을것 같음. - private static void recordEndPoint(final String endPoint, final boolean isTerminal) { + private void recordEndPoint(final String endPoint, final boolean isTerminal) { if (!tracingEnabled) return; try { - mutate(getTraceIdOrCreateNew(), new SpanUpdater() { + spanUpdate(new SpanUpdater() { @Override public Span updateSpan(Span span) { // set endpoint to both span and annotations @@ -304,12 +274,12 @@ public final class Trace { } } - private static void annotate(final String key, final Long duration) { + private void annotate(final String key, final Long duration) { if (!tracingEnabled) return; try { - mutate(getTraceIdOrCreateNew(), new SpanUpdater() { + spanUpdate(new SpanUpdater() { @Override public Span updateSpan(Span span) { span.addAnnotation(new HippoAnnotation(System.currentTimeMillis(), key, duration)); @@ -320,4 +290,6 @@ public final class Trace { logger.log(Level.SEVERE, e.getMessage(), e); } } + + } \ No newline at end of file diff --git a/src/main/java/com/profiler/context/TraceContext.java b/src/main/java/com/profiler/context/TraceContext.java index 6dbd23914..d962938eb 100644 --- a/src/main/java/com/profiler/context/TraceContext.java +++ b/src/main/java/com/profiler/context/TraceContext.java @@ -1,25 +1,58 @@ package com.profiler.context; +import com.profiler.sender.DataSender; +import com.profiler.sender.LoggingDataSender; +import com.profiler.util.NamedThreadLocal; + public class TraceContext { - private static TraceContext CONTEXT = new TraceContext(); + private static TraceContext CONTEXT = new TraceContext(); + // initailze관련 생명주기가 뭔가 애매함. 추후 방안을 더 고려해보자. public static TraceContext initialize() { return CONTEXT = new TraceContext(); } + // 얻는 것도 뭔가 모양이 마음에 안듬. public static TraceContext getTraceContext() { return CONTEXT; } -// private ThreadLocal threadLocal = new NamedThreadLocal("threadLocalTraceContext"); + private ThreadLocal threadLocal = new NamedThreadLocal("TraceContext"); private final ActiveThreadCounter activeThreadCounter = new ActiveThreadCounter(); + private static final DataSender DEFAULT_DATA_SENDER = new LoggingDataSender(); + private DataSender dataSender = DEFAULT_DATA_SENDER; + public TraceContext() { } + public Trace currentTraceObject() { + 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; + } + throw new IllegalStateException("already Trace Object exist"); + } + + public void detachTraceObject() { + this.threadLocal.set(null); + } + public ActiveThreadCounter getActiveThreadCounter() { return activeThreadCounter; } + + public void setDataSender(DataSender dataSender) { + this.dataSender = dataSender; + } } diff --git a/src/main/java/com/profiler/context/TraceHandler.java b/src/main/java/com/profiler/context/TraceHandler.java index 728a9deb1..ba5dddaab 100644 --- a/src/main/java/com/profiler/context/TraceHandler.java +++ b/src/main/java/com/profiler/context/TraceHandler.java @@ -1,5 +1,5 @@ package com.profiler.context; public interface TraceHandler { - public void handle(); + public void handle(TraceID traceID); } \ No newline at end of file diff --git a/src/main/java/com/profiler/context/TraceIDStack.java b/src/main/java/com/profiler/context/TraceIDStack.java deleted file mode 100644 index 20e364e16..000000000 --- a/src/main/java/com/profiler/context/TraceIDStack.java +++ /dev/null @@ -1,49 +0,0 @@ -package com.profiler.context; - -/** - * @author netspider - */ -public class TraceIDStack { - - private TraceID[] stack = new TraceID[4]; - - // TODO 개별변수에 volatile 을 건다고 해서 전체의 동시성이 해결되지 않으므로 일단 제거. - private int index = 0; - - - public TraceID getTraceId() { - return stack[index]; - } - - public TraceID getParentTraceId() { - if (index > 0) { - return stack[index - 1]; - } - return null; - } - - public void setTraceId(TraceID traceId) { - stack[index] = traceId; - } - - public void push() { - index++; - if (index > stack.length - 1) { - TraceID[] old = stack; - stack = new TraceID[index + 4]; - System.arraycopy(old, 0, stack, 0, old.length); - } - } - - public void pop() { - if (index > 0) { -// TODO 이전 reference를 제거해야 될거 같음. -// stack[index] = null; - index--; - } - } - - public void clear() { - stack[index] = null; - } -} diff --git a/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java b/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java index e8b834e9f..a9e8f046c 100644 --- a/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java +++ b/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java @@ -54,9 +54,9 @@ public class DefaultModifierRegistry implements ModifierRegistry { public void addConnectorModifier() { HTTPClientModifier httpClientModifier = new HTTPClientModifier(byteCodeInstrumentor); addModifier(httpClientModifier); - - ArcusClientModifier arcusClientModifier = new ArcusClientModifier(byteCodeInstrumentor); - addModifier(arcusClientModifier); +// 잠시 arcus안되게 주석처리. +// ArcusClientModifier arcusClientModifier = new ArcusClientModifier(byteCodeInstrumentor); +// addModifier(arcusClientModifier); } public void addTomcatModifier() { diff --git a/src/main/java/com/profiler/modifier/connector/interceptors/ExecuteMethodInterceptor.java b/src/main/java/com/profiler/modifier/connector/interceptors/ExecuteMethodInterceptor.java index b17201159..9f271628c 100644 --- a/src/main/java/com/profiler/modifier/connector/interceptors/ExecuteMethodInterceptor.java +++ b/src/main/java/com/profiler/modifier/connector/interceptors/ExecuteMethodInterceptor.java @@ -1,15 +1,16 @@ package com.profiler.modifier.connector.interceptors; +import com.profiler.context.*; +import com.profiler.util.StringUtils; import org.apache.http.HttpHost; import org.apache.http.HttpRequest; -import com.profiler.StopWatch; -import com.profiler.context.Annotation; -import com.profiler.context.Header; -import com.profiler.context.Trace; -import com.profiler.context.TraceID; import com.profiler.interceptor.StaticAroundInterceptor; +import java.util.Arrays; +import java.util.logging.Level; +import java.util.logging.Logger; + /** * Method interceptor *

@@ -25,37 +26,50 @@ import com.profiler.interceptor.StaticAroundInterceptor; */ public class ExecuteMethodInterceptor implements StaticAroundInterceptor { + private final Logger logger = Logger.getLogger(ExecuteMethodInterceptor.class.getName()); + @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { + if (logger.isLoggable(Level.INFO)) { + logger.info("before " + StringUtils.toString(target) + " " + className + "." + methodName + parameterDescription + " args:" + Arrays.toString(args)); + } + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { + return; + } + trace.traceBlockBegin(); + + trace.markBeforeTime(); + TraceID nextId = trace.getCurrentTraceId(); final HttpHost host = (HttpHost) args[0]; final HttpRequest request = (HttpRequest) args[1]; + // UUID format을 그대로. + request.addHeader(Header.HTTP_TRACE_ID.toString(), nextId.getId().toString()); + request.addHeader(Header.HTTP_SPAN_ID.toString(), Long.toString(nextId.getSpanId())); + request.addHeader(Header.HTTP_PARENT_SPAN_ID.toString(), Long.toString(nextId.getParentSpanId())); + request.addHeader(Header.HTTP_SAMPLED.toString(), String.valueOf(nextId.isSampled())); + request.addHeader(Header.HTTP_FLAGS.toString(), String.valueOf(nextId.getFlags())); - try { - Trace.traceBlockBegin(); - TraceID nextId = Trace.getNextTraceId(); + trace.recordRpcName(request.getProtocolVersion().toString(), "CLIENT"); + trace.recordEndPoint(request.getProtocolVersion().toString() + ":" + host.getHostName() + ":" + host.getPort()); + trace.recordAttibute("http.url", request.getRequestLine().getUri()); + trace.record(Annotation.ClientSend); - // UUID format을 그대로. - request.addHeader(Header.HTTP_TRACE_ID.toString(), nextId.getId().toString()); - request.addHeader(Header.HTTP_SPAN_ID.toString(), Long.toString(nextId.getSpanId())); - request.addHeader(Header.HTTP_PARENT_SPAN_ID.toString(), Long.toString(nextId.getParentSpanId())); - request.addHeader(Header.HTTP_SAMPLED.toString(), String.valueOf(nextId.isSampled())); - request.addHeader(Header.HTTP_FLAGS.toString(), String.valueOf(nextId.getFlags())); - - Trace.recordRpcName(request.getProtocolVersion().toString(), "CLIENT"); - Trace.recordEndPoint(request.getProtocolVersion().toString() + ":" + host.getHostName() + ":" + host.getPort()); - Trace.recordAttibute("http.url", request.getRequestLine().getUri()); - Trace.record(Annotation.ClientSend); - } finally { - Trace.traceBlockEnd(); - } - - StopWatch.start("ExecuteMethodInterceptor"); } @Override public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { - Trace.traceBlockBegin(); - Trace.record(Annotation.ClientRecv, StopWatch.stopAndGetElapsed("ExecuteMethodInterceptor")); - Trace.traceBlockEnd(); + if (logger.isLoggable(Level.INFO)) { + logger.info("after " + StringUtils.toString(target) + " " + className + "." + methodName + parameterDescription + " args:" + Arrays.toString(args) + " result:" + result); + } + + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { + return; + } + trace.record(Annotation.ClientRecv, trace.afterTime()); + trace.traceBlockEnd(); } } \ No newline at end of file diff --git a/src/main/java/com/profiler/modifier/db/ConnectionTrace.java b/src/main/java/com/profiler/modifier/db/ConnectionTrace.java deleted file mode 100644 index b321cb418..000000000 --- a/src/main/java/com/profiler/modifier/db/ConnectionTrace.java +++ /dev/null @@ -1,35 +0,0 @@ -package com.profiler.modifier.db; - -import java.sql.Connection; -import java.util.List; -import java.util.Set; -import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.ConcurrentMap; - -public class ConnectionTrace { - - public ConcurrentMap connectionMap = new ConcurrentHashMap(); - - private static ConnectionTrace CONNECTION_TRACE = new ConnectionTrace(); - - public static ConnectionTrace getConnectionTrace() { - return CONNECTION_TRACE; - } - - public void createConnection(Connection connection, String url) { - this.connectionMap.put(connection, url); - } - - public String getConnectionUrl(Connection connection) { - return this.connectionMap.get(connection); - } - - - public void closeConnection(Connection connection) { - this.connectionMap.remove(connection); - } - - public Set getConnectionList() { - return connectionMap.keySet(); - } -} diff --git a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementBindVariableInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementBindVariableInterceptor.java index 558dc3def..a967688e7 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementBindVariableInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementBindVariableInterceptor.java @@ -1,6 +1,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAfterInterceptor; import com.profiler.util.MetaObject; import com.profiler.util.NumberUtils; @@ -27,9 +28,13 @@ public class PreparedStatementBindVariableInterceptor implements StaticAfterInte logger.info("internal jdbc scope. skip trace"); return; } - if (Trace.getCurrentTraceId() == null) { + + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } + Map bindList = getBindValue.invoke(target); if (bindList == null) { if (logger.isLoggable(Level.WARNING)) { diff --git a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementCreateInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementCreateInterceptor.java index 38d115ace..b45539461 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementCreateInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementCreateInterceptor.java @@ -1,6 +1,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAfterInterceptor; import com.profiler.util.InterceptorUtils; import com.profiler.util.MetaObject; @@ -32,7 +33,9 @@ public class PreparedStatementCreateInterceptor implements StaticAfterIntercepto if (!InterceptorUtils.isSuccess(result)) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } if (target instanceof Connection) { diff --git a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementExecuteQueryInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementExecuteQueryInterceptor.java index 9655acea1..3650b6028 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementExecuteQueryInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/PreparedStatementExecuteQueryInterceptor.java @@ -2,6 +2,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.context.Annotation; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.util.InterceptorUtils; import com.profiler.util.MetaObject; @@ -33,30 +34,30 @@ public class PreparedStatementExecuteQueryInterceptor implements StaticAroundInt logger.info("internal jdbc scope. skip trace"); return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); + trace.traceBlockBegin(); try { String url = getUrl.invoke(target); - Trace.recordRpcName("MYSQL", url); - Trace.recordTerminalEndPoint(url); + trace.recordRpcName("MYSQL", url); + trace.recordTerminalEndPoint(url); String sql = getSql.invoke(target); - Trace.recordAttibute("PreparedStatement", sql); + trace.recordAttibute("PreparedStatement", sql); Map bindValue = getBindValue.invoke(target); String bindString = toBindVariable(bindValue); - Trace.recordAttibute("BindValue", bindString); + trace.recordAttibute("BindValue", bindString); clean(target); - Trace.record(Annotation.ClientSend); + trace.record(Annotation.ClientSend); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } - } finally { - Trace.traceBlockEnd(); } } @@ -86,26 +87,27 @@ public class PreparedStatementExecuteQueryInterceptor implements StaticAroundInt if (JDBCScope.isInternal()) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); try { // TODO 일단 테스트로 실패일경우 종료 아닐경우 resultset fetch까지 계산. fetch count는 옵션으로 빼는게 좋을듯. boolean success = InterceptorUtils.isSuccess(result); - Trace.recordAttibute("Success", success); + trace.recordAttibute("Success", success); if (!success) { Throwable th = (Throwable) result; - Trace.recordAttibute("Exception", th.getMessage()); + trace.recordAttibute("Exception", th.getMessage()); } - Trace.record(Annotation.ClientRecv); + trace.record(Annotation.ClientRecv); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } } finally { - Trace.traceBlockEnd(); + trace.traceBlockEnd(); } } diff --git a/src/main/java/com/profiler/modifier/db/interceptor/StatementCreateInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/StatementCreateInterceptor.java index ea25ad22b..4bd07e9c7 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/StatementCreateInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/StatementCreateInterceptor.java @@ -1,6 +1,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAfterInterceptor; import com.profiler.util.InterceptorUtils; import com.profiler.util.MetaObject; @@ -32,7 +33,9 @@ public class StatementCreateInterceptor implements StaticAfterInterceptor { if (!InterceptorUtils.isSuccess(result)) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } if (target instanceof Connection) { diff --git a/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteQueryInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteQueryInterceptor.java index f676843a3..25270b28b 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteQueryInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteQueryInterceptor.java @@ -3,6 +3,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.StopWatch; import com.profiler.context.Annotation; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.util.InterceptorUtils; import com.profiler.util.MetaObject; @@ -30,33 +31,29 @@ public class StatementExecuteQueryInterceptor implements StaticAroundInterceptor logger.info("internal jdbc scope. skip trace"); return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); - + trace.traceBlockBegin(); + trace.markBeforeTime(); try { /** * If method was not called by request handler, we skip tagging. */ String url = (String) this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", url); - Trace.recordTerminalEndPoint(url); - + trace.recordRpcName("MYSQL", url); + trace.recordTerminalEndPoint(url); if (args.length > 0) { - Trace.recordAttibute("Statement", args[0]); + trace.recordAttibute("Statement", args[0]); } - - Trace.record(Annotation.ClientSend); - - StopWatch.start("StatementExecuteQueryInterceptor"); + trace.record(Annotation.ClientSend); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } - } finally { - Trace.traceBlockEnd(); } } @@ -69,13 +66,14 @@ public class StatementExecuteQueryInterceptor implements StaticAroundInterceptor if (JDBCScope.isInternal()) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); - Trace.recordAttibute("Success", InterceptorUtils.isSuccess(result)); - Trace.record(Annotation.ClientRecv, StopWatch.stopAndGetElapsed("StatementExecuteQueryInterceptor")); - Trace.traceBlockEnd(); + trace.recordAttibute("Success", InterceptorUtils.isSuccess(result)); + trace.record(Annotation.ClientRecv, trace.afterTime()); + trace.traceBlockEnd(); } } diff --git a/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteUpdateInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteUpdateInterceptor.java index 4234977ed..e1f44f0df 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteUpdateInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/StatementExecuteUpdateInterceptor.java @@ -3,6 +3,7 @@ package com.profiler.modifier.db.interceptor; import com.profiler.StopWatch; import com.profiler.context.Annotation; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.util.MetaObject; import com.profiler.util.StringUtils; @@ -31,31 +32,31 @@ public class StatementExecuteUpdateInterceptor implements StaticAroundIntercepto logger.info("internal jdbc scope. skip trace"); return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); + trace.traceBlockBegin(); + trace.markBeforeTime(); try { if (args.length > 0) { String url = (String) this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", url); - Trace.recordAttibute("Query", url); - Trace.recordTerminalEndPoint(url); + trace.recordRpcName("MYSQL", url); + trace.recordAttibute("Query", url); + trace.recordTerminalEndPoint(url); } else { - Trace.recordRpcName("MYSQL", "UNKNOWN"); - Trace.recordTerminalEndPoint("UNKNOWN"); + trace.recordRpcName("MYSQL", "UNKNOWN"); + trace.recordTerminalEndPoint("UNKNOWN"); } - Trace.record(Annotation.ClientSend); + trace.record(Annotation.ClientSend); - StopWatch.start("StatementExecuteUpdateInterceptor"); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } - } finally { - Trace.traceBlockEnd(); } } @@ -67,13 +68,14 @@ public class StatementExecuteUpdateInterceptor implements StaticAroundIntercepto if (JDBCScope.isInternal()) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } - Trace.traceBlockBegin(); // TODO 결과, 수행시간을.알수 있어야 될듯. - Trace.record(Annotation.ClientRecv, StopWatch.stopAndGetElapsed("StatementExecuteUpdateInterceptor")); - Trace.traceBlockEnd(); + trace.record(Annotation.ClientRecv, trace.afterTime()); + trace.traceBlockEnd(); } } diff --git a/src/main/java/com/profiler/modifier/db/interceptor/TransactionInterceptor.java b/src/main/java/com/profiler/modifier/db/interceptor/TransactionInterceptor.java index 4386358f7..9a894bd26 100644 --- a/src/main/java/com/profiler/modifier/db/interceptor/TransactionInterceptor.java +++ b/src/main/java/com/profiler/modifier/db/interceptor/TransactionInterceptor.java @@ -7,6 +7,7 @@ import java.util.logging.Logger; import com.profiler.context.Annotation; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.util.InterceptorUtils; import com.profiler.util.MetaObject; @@ -27,17 +28,19 @@ public class TransactionInterceptor implements StaticAroundInterceptor { logger.info("internal jdbc scope. skip trace"); return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } if (target instanceof Connection) { Connection con = (Connection) target; if ("setAutoCommit".equals(methodName)) { - beforeStartTransaction(con); + beforeStartTransaction(trace, con); } else if ("commit".equals(methodName)) { - beforeCommit(con); + beforeCommit(trace, con); } else if ("rollback".equals(methodName)) { - beforeRollback(con); + beforeRollback(trace, con); } } } @@ -50,148 +53,129 @@ public class TransactionInterceptor implements StaticAroundInterceptor { if (JDBCScope.isInternal()) { return; } - if (Trace.getCurrentTraceId() == null) { + TraceContext traceContext = TraceContext.getTraceContext(); + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { return; } if (target instanceof Connection) { Connection con = (Connection) target; if ("setAutoCommit".equals(methodName)) { - afterStartTransaction(con, args[0], result); + afterStartTransaction(trace, con, args[0], result); } else if ("commit".equals(methodName)) { - afterCommit(con, result); + afterCommit(trace, con, result); } else if ("rollback".equals(methodName)) { - afterRollback(con, result); + afterRollback(trace, con, result); } } } - private void beforeStartTransaction(Connection target) { + private void beforeStartTransaction(Trace trace, Connection target) { - Trace.traceBlockBegin(); - try { - String connectionUrl = this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", connectionUrl); - Trace.recordTerminalEndPoint(connectionUrl); - Trace.record(Annotation.ClientSend); - } finally { - Trace.traceBlockEnd(); - } + trace.traceBlockBegin(); + String connectionUrl = this.getUrl.invoke(target); + trace.recordRpcName("MYSQL", connectionUrl); + trace.recordTerminalEndPoint(connectionUrl); + trace.record(Annotation.ClientSend); } - private void afterStartTransaction(Connection target, Object arg, Object result) { - Trace.traceBlockBegin(); + private void afterStartTransaction(Trace trace, Connection target, Object arg, Object result) { try { Boolean autocommit = (Boolean) arg; boolean success = InterceptorUtils.isSuccess(result); if (!autocommit) { // transaction start; if (success) { - Trace.recordAttibute("Transaction", "begin"); + trace.recordAttibute("Transaction", "begin"); } else { - Trace.recordAttibute("Transaction", "begin fail"); + trace.recordAttibute("Transaction", "begin fail"); Throwable th = (Throwable) result; - Trace.recordAttibute("Exception", th.getMessage()); + trace.recordAttibute("Exception", th.getMessage()); } - Trace.record(Annotation.ClientRecv); + trace.record(Annotation.ClientRecv); } else { if (success) { - Trace.recordAttibute("Transaction", "autoCommit:false"); + trace.recordAttibute("Transaction", "autoCommit:false"); } else { - Trace.recordAttibute("Transaction", "autoCommit:false fail"); + trace.recordAttibute("Transaction", "autoCommit:false fail"); Throwable th = (Throwable) result; - Trace.recordAttibute("Exception", th.getMessage()); + trace.recordAttibute("Exception", th.getMessage()); } - Trace.record(Annotation.ClientRecv); + trace.record(Annotation.ClientRecv); } } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } } finally { - Trace.traceBlockEnd(); + trace.traceBlockEnd(); } } - private void beforeCommit(Connection target) { - Trace.traceBlockBegin(); - try { - String connectionUrl = this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", connectionUrl); - Trace.recordTerminalEndPoint(connectionUrl); - Trace.record(Annotation.ClientSend); - } finally { - Trace.traceBlockEnd(); - } + private void beforeCommit(Trace trace, Connection target) { + trace.traceBlockBegin(); + String connectionUrl = this.getUrl.invoke(target); + trace.recordRpcName("MYSQL", connectionUrl); + trace.recordTerminalEndPoint(connectionUrl); + trace.record(Annotation.ClientSend); + } - private void afterCommit(Connection target, Object result) { - Trace.traceBlockBegin(); + private void afterCommit(Trace trace, Connection target, Object result) { try { String connectionUrl = this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", connectionUrl); - Trace.recordTerminalEndPoint(connectionUrl); + trace.recordRpcName("MYSQL", connectionUrl); + trace.recordTerminalEndPoint(connectionUrl); boolean success = InterceptorUtils.isSuccess(result); if (success) { - Trace.recordAttibute("Transaction", "commit"); + trace.recordAttibute("Transaction", "commit"); } else { - Trace.recordAttibute("Transaction", "commit fail"); + trace.recordAttibute("Transaction", "commit fail"); Throwable th = (Throwable) result; - Trace.recordAttibute("Exception", th.getMessage()); + trace.recordAttibute("Exception", th.getMessage()); } - Trace.record(Annotation.ClientRecv); + trace.record(Annotation.ClientRecv); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } } finally { - Trace.traceBlockEnd(); + trace.traceBlockEnd(); } } - private void beforeRollback(Connection target) { - Trace.traceBlockBegin(); - try { - String connectionUrl = this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", connectionUrl); - Trace.recordTerminalEndPoint(connectionUrl); - Trace.record(Annotation.ClientSend); - } finally { - Trace.traceBlockEnd(); - } + private void beforeRollback(Trace trace, Connection target) { + trace.traceBlockBegin(); + String connectionUrl = this.getUrl.invoke(target); + trace.recordRpcName("MYSQL", connectionUrl); + trace.recordTerminalEndPoint(connectionUrl); + trace.record(Annotation.ClientSend); } - private void afterRollback(Connection target, Object result) { - Trace.traceBlockBegin(); + private void afterRollback(Trace trace, Connection target, Object result) { try { - // TODO 너무 인터널 레벨로 byte code를 수정하다보니, 드라이버내의 close() 메소드가 rollback을 호출하는 것 까지 보임. - // ex : mysql - //java.lang.Exception - // at com.profiler.modifier.db.mysql.interceptor.TransactionInterceptor.after(TransactionInterceptor.java:24) - // at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4761) 여기에서 다시 부름. - // at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4345) - // at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1564) String connectionUrl = this.getUrl.invoke(target); - Trace.recordRpcName("MYSQL", connectionUrl); - Trace.recordTerminalEndPoint(connectionUrl); + trace.recordRpcName("MYSQL", connectionUrl); + trace.recordTerminalEndPoint(connectionUrl); boolean success = InterceptorUtils.isSuccess(result); if (success) { - Trace.recordAttibute("Transaction", "rollback"); + trace.recordAttibute("Transaction", "rollback"); } else { - Trace.recordAttibute("Transaction", "rollback fail"); + trace.recordAttibute("Transaction", "rollback fail"); Throwable th = (Throwable) result; - Trace.recordAttibute("Exception", th.getMessage()); + trace.recordAttibute("Exception", th.getMessage()); } - Trace.record(Annotation.ClientRecv); + trace.record(Annotation.ClientRecv); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { logger.log(Level.WARNING, e.getMessage(), e); } } finally { - Trace.traceBlockEnd(); + trace.traceBlockEnd(); } } diff --git a/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java b/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java index e7a916139..86ddb596a 100644 --- a/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java +++ b/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java @@ -8,7 +8,6 @@ import java.util.logging.Logger; import javax.servlet.http.HttpServletRequest; -import com.profiler.StopWatch; import com.profiler.context.Annotation; import com.profiler.context.Header; import com.profiler.context.SpanID; @@ -38,30 +37,31 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept String parameters = getRequestParameter(request); TraceID traceId = populateTraceIdFromRequest(request); + Trace trace; if (traceId != null) { - Trace.setTraceId(traceId); + TraceID nextTraceId = traceId.getNextTraceId(); + trace = traceContext.attachTraceObject(nextTraceId); } else { TraceID newTraceID = TraceID.newTraceId(); if (logger.isLoggable(Level.INFO)) { logger.info("TraceID not exist. start new trace. " + newTraceID); - // 좀더 자세한 정보는 debug레벨로 logger.log(Level.FINE, "requestUrl:" + requestURL + " clientIp" + clientIP + " parameter:" + parameters); } - Trace.setTraceId(newTraceID); + trace = traceContext.attachTraceObject(newTraceID); } - Trace.recordRpcName("TOMCAT", requestURL); - Trace.recordEndPoint(request.getProtocol() + ":" + request.getLocalName() + ":" + request.getLocalPort()); - Trace.recordAttibute("http.url", request.getRequestURI()); + trace.markBeforeTime(); + trace.recordRpcName("TOMCAT", requestURL); + trace.recordEndPoint(request.getProtocol() + ":" + request.getLocalName() + ":" + request.getLocalPort()); + trace.recordAttibute("http.url", request.getRequestURI()); if (parameters != null && parameters.length() > 0) { - Trace.recordAttibute("http.params", parameters); + trace.recordAttibute("http.params", parameters); } - Trace.record(Annotation.ServerRecv); + trace.record(Annotation.ServerRecv); - StopWatch.start("StandardHostValveInvokeModifier-starttime"); } catch (Exception e) { if (logger.isLoggable(Level.WARNING)) { - logger.log(Level.WARNING, "Tomcat StandardHostValve trace start fail", e); + logger.log(Level.WARNING, "Tomcat StandardHostValve trace start fail. Caused:" + e.getMessage(), e); } } } @@ -74,13 +74,18 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept TraceContext traceContext = TraceContext.getTraceContext(); traceContext.getActiveThreadCounter().end(); - + Trace trace = traceContext.currentTraceObject(); + if (trace == null) { + return; + } + traceContext.detachTraceObject(); + if (trace.getCurrentStackContext().getStackFrameId() != 0) { + logger.warning("Corrupted CallStack found. StackId not Root(0)"); + // 문제 있는 callstack을 dump하면 도움이 될듯. + } // TODO result 가 Exception 타입일경우 호출 실패임. - Trace.record(Annotation.ServerSend, StopWatch.stopAndGetElapsed("StandardHostValveInvokeModifier-starttime")); -// RequestTracer.endTransaction(); + trace.record(Annotation.ServerSend, trace.afterTime()); - // TODO: I'v changed point of removing. Trace.mutate() - // Trace.removeTraceId(); } /** diff --git a/src/main/java/com/profiler/util/ShortRangeStopWatch.java b/src/main/java/com/profiler/util/ShortRangeStopWatch.java deleted file mode 100644 index 34ff0d89b..000000000 --- a/src/main/java/com/profiler/util/ShortRangeStopWatch.java +++ /dev/null @@ -1,4 +0,0 @@ -package com.profiler.util; - -public class ShortRangeStopWatch { -} diff --git a/src/test/java/com/profiler/context/CallStackTest.java b/src/test/java/com/profiler/context/CallStackTest.java new file mode 100644 index 000000000..b68221c9c --- /dev/null +++ b/src/test/java/com/profiler/context/CallStackTest.java @@ -0,0 +1,26 @@ +package com.profiler.context; + +import org.junit.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * + */ +public class CallStackTest { + + private Logger logger = LoggerFactory.getLogger(this.getClass()); + + @Test + public void testPush() throws Exception { + CallStack callStack = new CallStack(); + int stackIndex = callStack.getStackFrameIndex(); + logger.info(String.valueOf(stackIndex)); + + } + + @Test + public void testPop() throws Exception { + + } +} \ No newline at end of file diff --git a/src/test/java/com/profiler/context/SpanTest.java b/src/test/java/com/profiler/context/SpanTest.java index 41be272a3..ae445dbdc 100644 --- a/src/test/java/com/profiler/context/SpanTest.java +++ b/src/test/java/com/profiler/context/SpanTest.java @@ -10,60 +10,60 @@ import org.junit.Test; public class SpanTest { - @Test - public void span() { - int testSize = 1; + @Test + public void span() { + int testSize = 1; - final CountDownLatch startLatch = new CountDownLatch(1); - final CountDownLatch endLatch = new CountDownLatch(testSize); - Executor exec = Executors.newFixedThreadPool(testSize); + final CountDownLatch startLatch = new CountDownLatch(1); + final CountDownLatch endLatch = new CountDownLatch(testSize); + Executor exec = Executors.newFixedThreadPool(testSize); - for (int i = 0; i < testSize; i++) { - exec.execute(new TraceTest(startLatch, endLatch)); - } + for (int i = 0; i < testSize; i++) { + exec.execute(new TraceTest(startLatch, endLatch)); + } - startLatch.countDown(); + startLatch.countDown(); - try { - endLatch.await(); - } catch (InterruptedException e) { - e.printStackTrace(); - Assert.fail(e.getMessage()); - } - } + try { + endLatch.await(); + } catch (InterruptedException e) { + e.printStackTrace(); + Assert.fail(e.getMessage()); + } + } - private static final class TraceTest implements Runnable { - private final CountDownLatch startLatch; - private final CountDownLatch endLatch; + private static final class TraceTest implements Runnable { + private final CountDownLatch startLatch; + private final CountDownLatch endLatch; - public TraceTest(CountDownLatch startLatch, CountDownLatch endLatch) { - this.startLatch = startLatch; - this.endLatch = endLatch; - } + public TraceTest(CountDownLatch startLatch, CountDownLatch endLatch) { + this.startLatch = startLatch; + this.endLatch = endLatch; + } - @Override - public void run() { - try { - startLatch.await(); - } catch (InterruptedException e) { - e.printStackTrace(); - } + @Override + public void run() { + try { + startLatch.await(); + } catch (InterruptedException e) { + e.printStackTrace(); + } + Trace trace = new Trace(); +// trace.setTraceId(Trace.getNextTraceId()); - Trace.setTraceId(Trace.getNextTraceId()); + trace.recordMessage("msg:client send"); + trace.record(Annotation.ClientSend); - Trace.recordMessage("msg:client send"); - Trace.record(Annotation.ClientSend); + trace.recordMessage("msg:server recv"); + trace.record(Annotation.ServerRecv); - Trace.recordMessage("msg:server recv"); - Trace.record(Annotation.ServerRecv); + trace.recordMessage("msg:server send"); + trace.record(Annotation.ServerSend); - Trace.recordMessage("msg:server send"); - Trace.record(Annotation.ServerSend); + trace.recordMessage("msg:client recv"); + trace.record(Annotation.ClientRecv); - Trace.recordMessage("msg:client recv"); - Trace.record(Annotation.ClientRecv); - - endLatch.countDown(); - } - } + endLatch.countDown(); + } + } } diff --git a/src/test/java/com/profiler/context/TraceTest.java b/src/test/java/com/profiler/context/TraceTest.java index 10c29ae97..cc1c8c854 100644 --- a/src/test/java/com/profiler/context/TraceTest.java +++ b/src/test/java/com/profiler/context/TraceTest.java @@ -4,37 +4,40 @@ import org.junit.Test; public class TraceTest { - @Test - public void trace() { - Trace.traceBlockBegin(); - Trace.setTraceId(TraceID.newTraceId()); + @Test + public void trace() { + TraceID traceID = TraceID.newTraceId(); + Trace trace = new Trace(traceID); + trace.traceBlockBegin(); - // http server receive - Trace.recordRpcName("service_name", "http://"); - Trace.recordEndPoint("http:localhost:8080"); - Trace.recordAttibute("KEY", "VALUE"); - Trace.record(Annotation.ServerRecv); + // http server receive + trace.recordRpcName("service_name", "http://"); + trace.recordEndPoint("http:localhost:8080"); + trace.recordAttibute("KEY", "VALUE"); + trace.record(Annotation.ServerRecv); - // get data form db - getDataFromDB(); + // get data form db + getDataFromDB(trace); - // response to client - Trace.record(Annotation.ServerSend); + // response to client + trace.record(Annotation.ServerSend); - Trace.traceBlockEnd(); - } + trace.traceBlockEnd(); + } - private void getDataFromDB() { - Trace.traceBlockBegin(); + private void getDataFromDB(Trace trace) { + trace.traceBlockBegin(); + trace.record(Annotation.ClientSend); - // db server request - Trace.recordRpcName("mysql", "rpc"); - Trace.recordAttibute("mysql.query", "SELECT * FROM TABLE"); - Trace.record(Annotation.ClientSend); + // db server request + trace.recordRpcName("mysql", "rpc"); + trace.recordAttibute("mysql.query", "SELECT * FROM TABLE"); - // get a db response - Trace.record(Annotation.ClientRecv); + // get a db response - Trace.traceBlockEnd(); - } + trace.record(Annotation.ClientRecv); + trace.traceBlockEnd(); + + + } } diff --git a/src/test/java/com/profiler/modifier/db/mysql/MySQLConnectionImplModifierTest.java b/src/test/java/com/profiler/modifier/db/mysql/MySQLConnectionImplModifierTest.java index 992214752..0ce65eaf5 100644 --- a/src/test/java/com/profiler/modifier/db/mysql/MySQLConnectionImplModifierTest.java +++ b/src/test/java/com/profiler/modifier/db/mysql/MySQLConnectionImplModifierTest.java @@ -2,6 +2,8 @@ package com.profiler.modifier.db.mysql; import com.mysql.jdbc.JDBC4PreparedStatement; import com.profiler.context.Trace; +import com.profiler.context.TraceContext; +import com.profiler.context.TraceID; import com.profiler.util.MetaObject; import com.profiler.util.TestClassLoader; import org.junit.Assert; @@ -18,10 +20,14 @@ public class MySQLConnectionImplModifierTest { private final Logger logger = LoggerFactory.getLogger(MySQLConnectionImplModifierTest.class.getName()); private TestClassLoader loader; + @Before public void setUp() throws Exception { loader = new TestClassLoader(); + MySQLNonRegisteringDriverModifier driverModifier = new MySQLNonRegisteringDriverModifier(loader.getInstrumentor()); + loader.addModifier(driverModifier); + MySQLConnectionImplModifier connectionModifier = new MySQLConnectionImplModifier(loader.getInstrumentor()); loader.addModifier(connectionModifier); @@ -38,6 +44,7 @@ public class MySQLConnectionImplModifierTest { } private MetaObject getUrl = new MetaObject("__getUrl"); + @Test public void testModify() throws Exception { @@ -49,9 +56,13 @@ public class MySQLConnectionImplModifierTest { Properties properties = new Properties(); properties.setProperty("user", "lucytest"); properties.setProperty("password", "testlucy"); + + TraceContext traceContext = new TraceContext(); + TraceID traceID = TraceID.newTraceId(); + traceContext.attachTraceObject(traceID); + Connection connection = driver.connect("jdbc:mysql://10.98.133.22:3306/hippo", properties); - Trace.getTraceIdOrCreateNew(); logger.info("Connection class name:" + connection.getClass().getName()); logger.info("Connection class cl:" + connection.getClass().getClassLoader()); @@ -70,7 +81,7 @@ public class MySQLConnectionImplModifierTest { String clearUrl = getUrl.invoke(connection); Assert.assertNull(clearUrl); - Trace.removeCurrentTraceIdFromStack(); + traceContext.detachTraceObject(); } private void statement(Connection connection) throws SQLException { @@ -109,8 +120,6 @@ public class MySQLConnectionImplModifierTest { connection.commit(); - - connection.setAutoCommit(true); } diff --git a/src/test/java/com/profiler/modifier/db/util/ConnectionStringParserTest.java b/src/test/java/com/profiler/modifier/db/util/ConnectionStringParserTest.java new file mode 100644 index 000000000..c4a6d5208 --- /dev/null +++ b/src/test/java/com/profiler/modifier/db/util/ConnectionStringParserTest.java @@ -0,0 +1,37 @@ +package com.profiler.modifier.db.util; + +import junit.framework.Assert; +import org.junit.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import java.net.URI; + +/** + * + */ +public class ConnectionStringParserTest { + + private Logger logger = LoggerFactory.getLogger(ConnectionStringParser.class); + + @Test + public void testURIParse() throws Exception { + + URI uri = URI.create("mysql:replication://10.98.133.22:3306/test_lucy_db"); + logger.debug(uri.toString()); + logger.debug(uri.getScheme()); + + // URI로 파싱하는건 제한적임 한계가 있음. + try { + URI oracleRac = URI.create("jdbc:oracle:thin:@(DESCRIPTION=(LOAD_BALANCE=on)" + + "(ADDRESS=(PROTOCOL=TCP)(HOST=1.2.3.4) (PORT=1521))" + + "(ADDRESS=(PROTOCOL=TCP)(HOST=1.2.3.5) (PORT=1521))" + + "(CONNECT_DATA=(SERVICE_NAME=service)))"); + + logger.debug(oracleRac.toString()); + logger.debug(oracleRac.getScheme()); + Assert.fail(); + } catch (Exception e) { + } + } +} diff --git a/src/test/java/com/profiler/modifier/tomcat/InvokeMethodInterceptorTest.java b/src/test/java/com/profiler/modifier/tomcat/InvokeMethodInterceptorTest.java index bf97a88ca..b2cf7ab79 100644 --- a/src/test/java/com/profiler/modifier/tomcat/InvokeMethodInterceptorTest.java +++ b/src/test/java/com/profiler/modifier/tomcat/InvokeMethodInterceptorTest.java @@ -4,10 +4,12 @@ import static org.mockito.Mockito.mock; import static org.mockito.Mockito.when; import java.util.Enumeration; +import java.util.UUID; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; +import com.profiler.context.TraceContext; import org.junit.Test; import com.profiler.context.Header; @@ -15,53 +17,83 @@ import com.profiler.modifier.tomcat.interceptors.StandardHostValveInvokeIntercep public class InvokeMethodInterceptorTest { - @Test - public void testHeaderNOTExists() { - HttpServletRequest request = mock(HttpServletRequest.class); - HttpServletResponse response = mock(HttpServletResponse.class); + @Test + public void testHeaderNOTExists() { + TraceContext.initialize(); + HttpServletRequest request = mock(HttpServletRequest.class); + HttpServletResponse response = mock(HttpServletResponse.class); - when(request.getRequestURI()).thenReturn("/hellotest.nhn"); - when(request.getRemoteAddr()).thenReturn("10.0.0.1"); - when(request.getHeader(Header.HTTP_TRACE_ID.toString())).thenReturn(null); - when(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString())).thenReturn(null); - when(request.getHeader(Header.HTTP_SPAN_ID.toString())).thenReturn(null); - when(request.getHeader(Header.HTTP_SAMPLED.toString())).thenReturn(null); - when(request.getHeader(Header.HTTP_FLAGS.toString())).thenReturn(null); + when(request.getRequestURI()).thenReturn("/hellotest.nhn"); + when(request.getRemoteAddr()).thenReturn("10.0.0.1"); + when(request.getHeader(Header.HTTP_TRACE_ID.toString())).thenReturn(null); + when(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString())).thenReturn(null); + when(request.getHeader(Header.HTTP_SPAN_ID.toString())).thenReturn(null); + when(request.getHeader(Header.HTTP_SAMPLED.toString())).thenReturn(null); + when(request.getHeader(Header.HTTP_FLAGS.toString())).thenReturn(null); - Enumeration enumeration = mock(Enumeration.class); - when(request.getParameterNames()).thenReturn(enumeration); + Enumeration enumeration = mock(Enumeration.class); + when(request.getParameterNames()).thenReturn(enumeration); - StandardHostValveInvokeInterceptor interceptor = new StandardHostValveInvokeInterceptor(); + StandardHostValveInvokeInterceptor interceptor = new StandardHostValveInvokeInterceptor(); - interceptor.before("target", "classname", "methodname", null, new Object[] { request, response }); - interceptor.after("target", "classname", "methodname", null, new Object[] { request, response }, new Object()); + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); - interceptor.before("target", "classname", "methodname", null, new Object[] { request, response }); - interceptor.after("target", "classname", "methodname", null, new Object[] { request, response }, new Object()); - } + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); + } - @Test - public void testHeaderExists() { - HttpServletRequest request = mock(HttpServletRequest.class); - HttpServletResponse response = mock(HttpServletResponse.class); + @Test + public void testInvalidHeaderExists() { + TraceContext.initialize(); + // TODO 결과값 검증 필요. + HttpServletRequest request = mock(HttpServletRequest.class); + HttpServletResponse response = mock(HttpServletResponse.class); - when(request.getRequestURI()).thenReturn("/hellotest.nhn"); - when(request.getRemoteAddr()).thenReturn("10.0.0.1"); - when(request.getHeader(Header.HTTP_TRACE_ID.toString())).thenReturn("TRACEID"); - when(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString())).thenReturn("PARENTSPANID"); - when(request.getHeader(Header.HTTP_SPAN_ID.toString())).thenReturn("SPANID"); - when(request.getHeader(Header.HTTP_SAMPLED.toString())).thenReturn("false"); - when(request.getHeader(Header.HTTP_FLAGS.toString())).thenReturn("0"); + when(request.getRequestURI()).thenReturn("/hellotest.nhn"); + when(request.getRemoteAddr()).thenReturn("10.0.0.1"); + when(request.getHeader(Header.HTTP_TRACE_ID.toString())).thenReturn("TRACEID"); + when(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString())).thenReturn("PARENTSPANID"); + when(request.getHeader(Header.HTTP_SPAN_ID.toString())).thenReturn("SPANID"); + when(request.getHeader(Header.HTTP_SAMPLED.toString())).thenReturn("false"); + when(request.getHeader(Header.HTTP_FLAGS.toString())).thenReturn("0"); - Enumeration enumeration = mock(Enumeration.class); - when(request.getParameterNames()).thenReturn(enumeration); + Enumeration enumeration = mock(Enumeration.class); + when(request.getParameterNames()).thenReturn(enumeration); - StandardHostValveInvokeInterceptor interceptor = new StandardHostValveInvokeInterceptor(); + StandardHostValveInvokeInterceptor interceptor = new StandardHostValveInvokeInterceptor(); - interceptor.before("target", "classname", "methodname", null, new Object[] { request, response }); - interceptor.after("target", "classname", "methodname", null, new Object[] { request, response }, new Object()); + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); - interceptor.before("target", "classname", "methodname", null, new Object[] { request, response }); - interceptor.after("target", "classname", "methodname", null, new Object[] { request, response }, new Object()); - } + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); + } + + @Test + public void testValidHeaderExists() { + TraceContext.initialize(); + // TODO 결과값 검증 필요. + HttpServletRequest request = mock(HttpServletRequest.class); + HttpServletResponse response = mock(HttpServletResponse.class); + + when(request.getRequestURI()).thenReturn("/hellotest.nhn"); + when(request.getRemoteAddr()).thenReturn("10.0.0.1"); + when(request.getHeader(Header.HTTP_TRACE_ID.toString())).thenReturn(UUID.randomUUID().toString()); + when(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString())).thenReturn("PARENTSPANID"); + when(request.getHeader(Header.HTTP_SPAN_ID.toString())).thenReturn("SPANID"); + when(request.getHeader(Header.HTTP_SAMPLED.toString())).thenReturn("false"); + when(request.getHeader(Header.HTTP_FLAGS.toString())).thenReturn("0"); + + Enumeration enumeration = mock(Enumeration.class); + when(request.getParameterNames()).thenReturn(enumeration); + + StandardHostValveInvokeInterceptor interceptor = new StandardHostValveInvokeInterceptor(); + + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); + + interceptor.before("target", "classname", "methodname", null, new Object[]{request, response}); + interceptor.after("target", "classname", "methodname", null, new Object[]{request, response}, new Object()); + } }