diff --git a/src/main/java/com/profiler/ClassFileTransformerDispatcher.java b/src/main/java/com/profiler/ClassFileTransformerDispatcher.java index 9f6ccbe12..57a728a63 100644 --- a/src/main/java/com/profiler/ClassFileTransformerDispatcher.java +++ b/src/main/java/com/profiler/ClassFileTransformerDispatcher.java @@ -17,7 +17,7 @@ import java.security.ProtectionDomain; public class ClassFileTransformerDispatcher implements ClassFileTransformer { private final Logger logger = LoggerFactory.getLogger(this.getClass().getName()); - private final boolean isFine = logger.isDebugEnabled(); + private final boolean isDebug = logger.isDebugEnabled(); private final ClassLoader agentClassLoader = this.getClass().getClassLoader(); @@ -29,7 +29,7 @@ public class ClassFileTransformerDispatcher implements ClassFileTransformer { public ClassFileTransformerDispatcher(Agent agent) { - if(agent == null) { + if (agent == null) { throw new NullPointerException("agent must not be null"); } this.agent = agent; @@ -49,6 +49,11 @@ public class ClassFileTransformerDispatcher implements ClassFileTransformer { // agent의 clssLoader에 로드된 클래스는 스킵한다. return null; } + // 자기 자신의 패키지도 제외 + // TODO 향후 패키지명 변경에 의해 코드 변경이 필요함. + if (className.startsWith("com/profiler/")) { + return null; + } Modifier findModifier = this.modifierRegistry.findModifier(className); if (findModifier == null) { @@ -62,8 +67,8 @@ public class ClassFileTransformerDispatcher implements ClassFileTransformer { } } - if (isFine) { - logger.debug("[transform] cl" + classLoader + " className:" + className + " Modifier:" + findModifier.getClass().getName()); + if (isDebug) { + logger.debug("[transform] cl:{} className:{} Modifier:{}", new Object[]{ classLoader, className, findModifier.getClass().getName()}); } String javassistClassName = className.replace('/', '.'); @@ -71,7 +76,7 @@ public class ClassFileTransformerDispatcher implements ClassFileTransformer { return findModifier.modify(classLoader, javassistClassName, protectionDomain, classFileBuffer); } catch (Throwable e) { - logger.error("Modifier:" + findModifier.getTargetClass() + " modify fail. Cause:" + e.getMessage(), e); + logger.error("Modifier:{} modify fail. Cause:{}", new Object[] { findModifier.getTargetClass(), e.getMessage(), e}); return null; } } diff --git a/src/main/java/com/profiler/context/DefaultTrace.java b/src/main/java/com/profiler/context/DefaultTrace.java index 1e5e32c8a..ece605792 100644 --- a/src/main/java/com/profiler/context/DefaultTrace.java +++ b/src/main/java/com/profiler/context/DefaultTrace.java @@ -151,7 +151,7 @@ public final class DefaultTrace implements Trace { if (stackFrameId != stackId) { // 자체 stack dump를 하면 오류발견이 쉬울것으로 생각됨 if (logger.isWarnEnabled()) { - logger.warn("Corrupted CallStack found. StackId not matched. expected:" + stackId + " current:" + stackFrameId); + logger.warn("Corrupted CallStack found. StackId not matched. expected:{} current:{}", stackId, stackFrameId); } } if (currentStackFrame instanceof RootStackFrame) { diff --git a/src/main/java/com/profiler/context/DefaultTraceContext.java b/src/main/java/com/profiler/context/DefaultTraceContext.java index fb0903458..d9bf2eca5 100644 --- a/src/main/java/com/profiler/context/DefaultTraceContext.java +++ b/src/main/java/com/profiler/context/DefaultTraceContext.java @@ -6,6 +6,7 @@ import com.profiler.common.dto.thrift.ApiMetaData; import com.profiler.common.dto.thrift.SqlMetaData; import com.profiler.common.util.ParsingResult; import com.profiler.common.util.SqlParser; +import com.profiler.exception.PinPointException; import com.profiler.interceptor.MethodDescriptor; import com.profiler.logging.Logger; import com.profiler.logging.LoggerFactory; @@ -52,16 +53,37 @@ public class DefaultTraceContext implements TraceContext { public DefaultTraceContext() { } + /** + * sampling 여부까지 체크하여 유효성을 검증한 후 Trace를 리턴한다. + * @return + */ public Trace currentTraceObject() { + Trace trace = threadLocal.get(); + if (trace == null) { + return null; + } + if (trace.isSampling()) { + return trace; + } + return null; + } + + /** + * 유효성을 검증하지 않고 Trace를 리턴한다. + * @return + */ + public Trace currentRawTraceObject() { return threadLocal.get(); } + public void disableSampling() { + checkBeforeTraceObject(); + threadLocal.set(DisableTrace.INSTANCE); + } + public Trace continueTraceObject(TraceID traceID) { - Trace old = this.threadLocal.get(); - if (old != null) { - // 잘못된 상황의 old를 덤프할것. - throw new IllegalStateException("already Trace Object exist."); - } + checkBeforeTraceObject(); + // datasender연결 부분 수정 필요. DefaultTrace trace = new DefaultTrace(traceID); Storage storage = storageFactory.createStorage(); @@ -73,12 +95,19 @@ public class DefaultTraceContext implements TraceContext { return trace; } - public Trace newTraceObject() { + private void checkBeforeTraceObject() { Trace old = this.threadLocal.get(); if (old != null) { // 잘못된 상황의 old를 덤프할것. - throw new IllegalStateException("already Trace Object exist."); + if (logger.isDebugEnabled()) { + logger.warn("beforeTrace:{}", old); + } + throw new PinPointException("already Trace Object exist."); } + } + + public Trace newTraceObject() { + checkBeforeTraceObject(); // datasender연결 부분 수정 필요. DefaultTrace trace = new DefaultTrace(); Storage storage = storageFactory.createStorage(); @@ -178,8 +207,7 @@ public class DefaultTraceContext implements TraceContext { // newValue란 의미는 cache에 인입됬다는 의미이고 이는 신규 sql문일 가능성이 있다는 의미임. // 그러므로 메타데이터를 서버로 전송해야 한다. - // 프로파일 데이터를 보내는데 사용되는 queue가 아니고, - // 좀더 급한 메시지만 별도 처리할수 있는 상대적으로 더 한가한 queue와 datasender를 별도로 가지고 있는게 좋을듯 하다. + SqlMetaData sqlMetaData = new SqlMetaData(); sqlMetaData.setAgentId(DefaultAgent.getInstance().getAgentId()); sqlMetaData.setAgentIdentifier(DefaultAgent.getInstance().getIdentifier()); @@ -188,6 +216,7 @@ public class DefaultTraceContext implements TraceContext { sqlMetaData.setHashCode(normalizedSql.hashCode()); sqlMetaData.setSql(normalizedSql); + // 좀더 신뢰성이 있는 tcp connection이 필요함. this.priorityDataSender.send(sqlMetaData); } // hashId그냥 return String에서 까보면 됨. diff --git a/src/main/java/com/profiler/context/DisableTrace.java b/src/main/java/com/profiler/context/DisableTrace.java new file mode 100644 index 000000000..a83eeb534 --- /dev/null +++ b/src/main/java/com/profiler/context/DisableTrace.java @@ -0,0 +1,185 @@ +package com.profiler.context; + +import com.profiler.common.AnnotationKey; +import com.profiler.common.ServiceType; +import com.profiler.common.util.ParsingResult; +import com.profiler.interceptor.MethodDescriptor; + +import java.util.List; + +/** + * + */ +public class DisableTrace implements Trace { + + public static final DisableTrace INSTANCE = new DisableTrace(); + // 구지 객체를 생성하여 사용할 필요가 없을듯. + private DisableTrace() { + } + + @Override + public AsyncTrace createAsyncTrace() { + throw new UnsupportedOperationException(); + } + + @Override + public void traceBlockBegin() { + throw new UnsupportedOperationException(); + } + + @Override + public void markBeforeTime() { + throw new UnsupportedOperationException(); + } + + @Override + public long getBeforeTime() { + throw new UnsupportedOperationException(); + } + + @Override + public void markAfterTime() { + throw new UnsupportedOperationException(); + } + + @Override + public long getAfterTime() { + throw new UnsupportedOperationException(); + } + + @Override + public void traceBlockBegin(int stackId) { + throw new UnsupportedOperationException(); + } + + @Override + public void traceRootBlockEnd() { + throw new UnsupportedOperationException(); + } + + @Override + public void traceBlockEnd() { + throw new UnsupportedOperationException(); + } + + @Override + public void traceBlockEnd(int stackId) { + throw new UnsupportedOperationException(); + } + + @Override + public TraceID getTraceId() { + throw new UnsupportedOperationException(); + } + + @Override + public boolean isSampling() { + // sampling false를 항상 false를 리턴한다. + return false; + } + + @Override + public void recordException(Object result) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordApi(MethodDescriptor methodDescriptor) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordApi(MethodDescriptor methodDescriptor, Object[] args) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordApi(int apiId) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordApi(int apiId, Object[] args) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordAttribute(AnnotationKey key, String value) { + throw new UnsupportedOperationException(); + } + + @Override + public ParsingResult recordSqlInfo(String sql) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordSqlParsingResult(ParsingResult parsingResult) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordAttribute(AnnotationKey key, Object value) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordServiceType(ServiceType serviceType) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordRpcName(String rpc) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordDestinationId(String destinationId) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordDestinationAddress(List address) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordDestinationAddressList(List addressList) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordEndPoint(String endPoint) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordRemoteAddr(String remoteAddr) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordNextSpanId(int spanId) { + throw new UnsupportedOperationException(); + } + + @Override + public void setTraceContext(TraceContext traceContext) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordParentApplication(String parentApplicationName, short parentApplicationType) { + throw new UnsupportedOperationException(); + } + + @Override + public void recordAcceptorHost(String host) { + throw new UnsupportedOperationException(); + } + + @Override + public int getStackFrameId() { + throw new UnsupportedOperationException(); + } +} diff --git a/src/main/java/com/profiler/interceptor/bci/JavaAssistByteCodeInstrumentor.java b/src/main/java/com/profiler/interceptor/bci/JavaAssistByteCodeInstrumentor.java index 6bc20b76d..e850ac599 100644 --- a/src/main/java/com/profiler/interceptor/bci/JavaAssistByteCodeInstrumentor.java +++ b/src/main/java/com/profiler/interceptor/bci/JavaAssistByteCodeInstrumentor.java @@ -61,7 +61,7 @@ public class JavaAssistByteCodeInstrumentor implements ByteCodeInstrumentor { classPool.appendClassPath(pathName); } catch (NotFoundException e) { if (logger.isWarnEnabled()) { - logger.warn("appendClassPath fail. lib not found. " + e.getMessage(), e); + logger.warn("appendClassPath fail. lib not found. {}", e.getMessage(), e); } } } @@ -118,7 +118,7 @@ public class JavaAssistByteCodeInstrumentor implements ByteCodeInstrumentor { // 재귀하면서 최하위부터 로드 defineNestedClass(nested, classLoader, protectedDomain); if (logger.isInfoEnabled()) { - logger.info("defineNestedClass class:" + nested.getName() + " cl:" + classLoader); + logger.info("defineNestedClass class:{} cl:{}", nested.getName(), classLoader); } nested.toClass(classLoader, protectedDomain); } @@ -190,11 +190,11 @@ public class JavaAssistByteCodeInstrumentor implements ByteCodeInstrumentor { classPool.appendClassPath(filePath); // 만약 한개만 로딩해도 된다면. return true 할것 if (logger.isInfoEnabled()) { - logger.info("Loaded " + filePath + " library."); + logger.info("Loaded {}", filePath); } } catch (NotFoundException e) { if (logger.isWarnEnabled()) { - logger.warn("lib load fail. path:" + filePath + " cl:" + classLoader + " Cause:" + e.getMessage(), e); + logger.warn("lib load fail. path:{} cl:{} Cause:{}", new Object[] {filePath, classLoader, e.getMessage(), e}); } } } diff --git a/src/main/java/com/profiler/logging/Slf4jLoggerAdapter.java b/src/main/java/com/profiler/logging/Slf4jLoggerAdapter.java index 1330910af..dffaa6ffb 100644 --- a/src/main/java/com/profiler/logging/Slf4jLoggerAdapter.java +++ b/src/main/java/com/profiler/logging/Slf4jLoggerAdapter.java @@ -1,14 +1,17 @@ package com.profiler.logging; -import com.profiler.logging.Logger; import org.slf4j.Marker; +import java.util.Arrays; + /** * */ public class Slf4jLoggerAdapter implements Logger { private final org.slf4j.Logger logger; + public static final int BUFFER_SIZE = 512; + public Slf4jLoggerAdapter(org.slf4j.Logger logger) { this.logger = logger; } @@ -19,12 +22,39 @@ public class Slf4jLoggerAdapter implements Logger { @Override public void beforeInterceptor(Object target, String className, String methodName, String parameterDescription, Object[] args) { - LoggingUtils.logBefore(this, target, className, methodName, parameterDescription, args); + StringBuilder sb = new StringBuilder(BUFFER_SIZE); + sb.append("before "); + logMethod(sb, target, className, methodName, parameterDescription, args); + logger.debug(sb.toString()); } @Override public void afterInterceptor(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { - LoggingUtils.logAfter(this, target, className, methodName, parameterDescription, args, result); + StringBuilder sb = new StringBuilder(BUFFER_SIZE); + sb.append("after "); + logMethod(sb, target, className, methodName, parameterDescription, args); + sb.append(" result:"); + sb.append(result); + logger.debug(sb.toString()); + } + + @Override + public void afterInterceptor(Object target, String className, String methodName, String parameterDescription, Object[] args) { + StringBuilder sb = new StringBuilder(BUFFER_SIZE); + sb.append("after "); + logMethod(sb, target, className, methodName, parameterDescription, args); + logger.debug(sb.toString()); + } + + private static void logMethod(StringBuilder sb, Object target, String className, String methodName, String parameterDescription, Object[] args) { + sb.append(target); + sb.append(' '); + sb.append(className); + sb.append(' '); + sb.append(methodName); + sb.append(parameterDescription); + sb.append(" args:"); + sb.append(Arrays.toString(args)); } @Override diff --git a/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java b/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java index 652fbd725..b9860a65e 100644 --- a/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java +++ b/src/main/java/com/profiler/modifier/DefaultModifierRegistry.java @@ -42,9 +42,9 @@ import com.profiler.modifier.tomcat.TomcatConnectorModifier; import com.profiler.modifier.tomcat.TomcatStandardServiceModifier; public class DefaultModifierRegistry implements ModifierRegistry { - // TODO 혹시 동시성을 고려 해야 되는지 검토. - // 왠간해서는 동시성 상황이 안나올것으로 보임. - private Map registry = new HashMap(512); + + // 왠간해서는 동시성 상황이 안나올것으로 보임. 사이즈를 크게 잡아서 체인을 가능한 뒤지지 않도록함. + private final Map registry = new HashMap(512); private final ByteCodeInstrumentor byteCodeInstrumentor; private final ProfilerConfig profilerConfig; @@ -167,7 +167,7 @@ public class DefaultModifierRegistry implements ModifierRegistry { MySQLPreparedStatementJDBC4Modifier myqlPreparedStatementJDBC4Modifier = new MySQLPreparedStatementJDBC4Modifier(byteCodeInstrumentor, agent); addModifier(myqlPreparedStatementJDBC4Modifier); - +// result set fectch counter를 만들어야 될듯. // Modifier mysqlResultSetModifier = new MySQLResultSetModifier(byteCodeInstrumentor, agent); // addModifier(mysqlResultSetModifier); } diff --git a/src/main/java/com/profiler/modifier/bloc/handler/interceptors/ExecuteMethodInterceptor.java b/src/main/java/com/profiler/modifier/bloc/handler/interceptors/ExecuteMethodInterceptor.java index 798f72239..fc628fd07 100644 --- a/src/main/java/com/profiler/modifier/bloc/handler/interceptors/ExecuteMethodInterceptor.java +++ b/src/main/java/com/profiler/modifier/bloc/handler/interceptors/ExecuteMethodInterceptor.java @@ -12,7 +12,7 @@ import com.profiler.interceptor.MethodDescriptor; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.interceptor.TraceContextSupport; import com.profiler.logging.LoggerFactory; -import com.profiler.logging.LoggingUtils; +import com.profiler.sampler.util.SamplingFlagUtils; import com.profiler.util.NumberUtils; /** @@ -22,6 +22,7 @@ public class ExecuteMethodInterceptor implements StaticAroundInterceptor, ByteCo private final Logger logger = LoggerFactory.getLogger(ExecuteMethodInterceptor.class.getName()); private final boolean isDebug = logger.isDebugEnabled(); + private final boolean isInfo = logger.isInfoEnabled(); private MethodDescriptor descriptor; private TraceContext traceContext; @@ -29,29 +30,34 @@ public class ExecuteMethodInterceptor implements StaticAroundInterceptor, ByteCo @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { if (isDebug) { - LoggingUtils.logBefore(logger, target, className, methodName, parameterDescription, args); + logger.beforeInterceptor(target, className, methodName, parameterDescription, args); } try { external.org.apache.coyote.Request request = (external.org.apache.coyote.Request) args[0]; + + boolean sampling = samplingEnable(request); + if (!sampling) { + // 샘플링 대상이 아닐 경우도 TraceObject를 생성하여, sampling 대상이 아니라는것을 명시해야 한다. + // sampling 대상이 아닐경우 rpc 호출에서 sampling 대상이 아닌 것에 rpc호출 파라미터에 sampling disable 파라미터를 박을수 있다. + traceContext.disableSampling(); + return; + } + String requestURL = request.requestURI().toString(); - String clientIP = request.remoteAddr().toString(); - String parameters = getRequestParameter(request); + String remoteAddr = request.remoteAddr().toString(); + TraceID traceId = populateTraceIdFromRequest(request); Trace trace; if (traceId != null) { - if (logger.isInfoEnabled()) { - logger.info("TraceID exist. continue trace. " + traceId); - logger.debug("requestUrl:" + requestURL + " clientIp" + clientIP + " parameter:" + parameters); + if (isInfo) { + logger.debug("TraceID exist. continue trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } - trace = traceContext.continueTraceObject(traceId); } else { - trace = new DefaultTrace(); - if (logger.isInfoEnabled()) { - logger.info("TraceID not exist. start new trace. " + trace.getTraceId()); - logger.debug("requestUrl:" + requestURL + " clientIp" + clientIP + " parameter:" + parameters); + if (isInfo) { + logger.debug("TraceID not exist. start new trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } trace = traceContext.newTraceObject(); } @@ -65,42 +71,51 @@ public class ExecuteMethodInterceptor implements StaticAroundInterceptor, ByteCo trace.recordEndPoint(request.protocol().toString() + ":" + request.serverName().toString() + ":" + request.getServerPort()); trace.recordDestinationId(request.serverName().toString() + ":" + request.getServerPort()); trace.recordAttribute(AnnotationKey.HTTP_URL, request.requestURI().toString()); - if (parameters != null && parameters.length() > 0) { - trace.recordAttribute(AnnotationKey.HTTP_PARAM, parameters); - } - } catch (Exception e) { + + } catch (Throwable e) { if (logger.isWarnEnabled()) { logger.warn( "Tomcat StandardHostValve trace start fail. Caused:" + e.getMessage(), e); } } } + + @Override public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { if (isDebug) { - LoggingUtils.logAfter(logger, target, className, methodName, parameterDescription, args, result); + logger.afterInterceptor(target, className, methodName, parameterDescription, args, result); } // traceContext.getActiveThreadCounter().end(); + Trace trace = traceContext.currentTraceObject(); if (trace == null) { return; } traceContext.detachTraceObject(); - if (trace.getStackFrameId() != 0) { - logger.warn("Corrupted CallStack found. StackId not Root(0)"); - // 문제 있는 callstack을 dump하면 도움이 될듯. + + external.org.apache.coyote.Request request = (external.org.apache.coyote.Request) args[0]; + String parameters = getRequestParameter(request); + if (parameters != null && parameters.length() > 0) { + trace.recordAttribute(AnnotationKey.HTTP_PARAM, parameters); } trace.recordApi(descriptor); -// trace.recordApi(this.apiId); + trace.recordException(result); trace.markAfterTime(); trace.traceRootBlockEnd(); } + private boolean samplingEnable(external.org.apache.coyote.Request request) { + // optional 값. + String samplingFlag = request.getHeader(Header.HTTP_SAMPLED.toString()); + return SamplingFlagUtils.isSamplingFlag(samplingFlag); + } + /** * Pupulate source trace from HTTP Header. * @@ -113,10 +128,9 @@ public class ExecuteMethodInterceptor implements StaticAroundInterceptor, ByteCo UUID uuid = UUID.fromString(strUUID); int parentSpanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString()), SpanID.NULL); int spanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_SPAN_ID.toString()), SpanID.NULL); - boolean sampled = Boolean.parseBoolean(request.getHeader(Header.HTTP_SAMPLED.toString())); short flags = NumberUtils.parseShort(request.getHeader(Header.HTTP_FLAGS.toString()), (short) 0); - TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, sampled, flags); + TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, true, flags); if (logger.isInfoEnabled()) { logger.info("TraceID exist. continue trace. " + id); } @@ -129,7 +143,7 @@ public class ExecuteMethodInterceptor implements StaticAroundInterceptor, ByteCo private String getRequestParameter(external.org.apache.coyote.Request request) { Enumeration attrs = request.getParameters().getParameterNames(); - StringBuilder params = new StringBuilder(); + final StringBuilder params = new StringBuilder(32); while (attrs.hasMoreElements()) { String keyString = attrs.nextElement().toString(); diff --git a/src/main/java/com/profiler/modifier/connector/httpclient4/interceptor/Execute2MethodInterceptor.java b/src/main/java/com/profiler/modifier/connector/httpclient4/interceptor/Execute2MethodInterceptor.java index 0c1c107ae..e3519898f 100644 --- a/src/main/java/com/profiler/modifier/connector/httpclient4/interceptor/Execute2MethodInterceptor.java +++ b/src/main/java/com/profiler/modifier/connector/httpclient4/interceptor/Execute2MethodInterceptor.java @@ -37,12 +37,13 @@ public class Execute2MethodInterceptor implements StaticAroundInterceptor, ByteC @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { if (isDebug) { - LoggingUtils.logBefore(logger, target, className, methodName, parameterDescription, args); + logger.beforeInterceptor(target, className, methodName, parameterDescription, args); } Trace trace = traceContext.currentTraceObject(); if (trace == null) { return; } + trace.traceBlockBegin(); trace.markBeforeTime(); @@ -52,6 +53,7 @@ public class Execute2MethodInterceptor implements StaticAroundInterceptor, ByteC final HttpUriRequest request = (HttpUriRequest) args[0]; // UUID format을 그대로. + request.addHeader(Header.HTTP_TRACE_ID.toString(), nextId.getId().toString()); request.addHeader(Header.HTTP_SPAN_ID.toString(), Integer.toString(nextId.getSpanId())); request.addHeader(Header.HTTP_PARENT_SPAN_ID.toString(), Integer.toString(nextId.getParentSpanId())); @@ -74,7 +76,7 @@ public class Execute2MethodInterceptor implements StaticAroundInterceptor, ByteC public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { if (isDebug) { // result는 로깅하지 않는다. - LoggingUtils.logAfter(logger, target, className, methodName, parameterDescription, args); + logger.afterInterceptor(target, className, methodName, parameterDescription, args); } Trace trace = traceContext.currentTraceObject(); diff --git a/src/main/java/com/profiler/modifier/method/interceptors/MethodInterceptor.java b/src/main/java/com/profiler/modifier/method/interceptors/MethodInterceptor.java index 49ba6ae85..6e602d32b 100644 --- a/src/main/java/com/profiler/modifier/method/interceptors/MethodInterceptor.java +++ b/src/main/java/com/profiler/modifier/method/interceptors/MethodInterceptor.java @@ -15,44 +15,46 @@ import com.profiler.logging.LoggingUtils; * */ public class MethodInterceptor implements StaticAroundInterceptor, ByteCodeMethodDescriptorSupport, ServiceTypeSupport, TraceContextSupport { - - private final Logger logger = LoggerFactory.getLogger(MethodInterceptor.class.getName()); - private final boolean isDebug = logger.isDebugEnabled(); + // method intereptor는 객체의 라이프 사이클을 알수 없이 자주 호출될수 있으므로 그냥 static으로 선언한다. + private static final Logger logger = LoggerFactory.getLogger(MethodInterceptor.class.getName()); + private static final boolean isDebug = logger.isDebugEnabled(); private MethodDescriptor descriptor; private TraceContext traceContext; private ServiceType serviceType = ServiceType.INTERNAL_METHOD; + @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { if (isDebug) { - LoggingUtils.logBefore(logger, target, className, methodName, parameterDescription, args); + logger.beforeInterceptor(target, className, methodName, parameterDescription, args); } Trace trace = traceContext.currentTraceObject(); - if (trace == null) { - return; - } + if (trace == null) { + return; + } + + trace.traceBlockBegin(); + trace.markBeforeTime(); - trace.traceBlockBegin(); trace.recordServiceType(serviceType); -// trace.recordRpcName(ServiceType.INTERNAL_METHOD, null, null); - trace.markBeforeTime(); } @Override public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { if (isDebug) { - LoggingUtils.logAfter(logger, target, className, methodName, parameterDescription, args); + logger.afterInterceptor(target, className, methodName, parameterDescription, args); } Trace trace = traceContext.currentTraceObject(); if (trace == null) { return; } - + trace.recordApi(descriptor); trace.recordException(result); + trace.markAfterTime(); trace.traceBlockEnd(); } diff --git a/src/main/java/com/profiler/modifier/servlet/interceptors/DoXXXInterceptor.java b/src/main/java/com/profiler/modifier/servlet/interceptors/HttpServletInterceptor.java similarity index 79% rename from src/main/java/com/profiler/modifier/servlet/interceptors/DoXXXInterceptor.java rename to src/main/java/com/profiler/modifier/servlet/interceptors/HttpServletInterceptor.java index 3a5e4a317..8f8ea2e64 100644 --- a/src/main/java/com/profiler/modifier/servlet/interceptors/DoXXXInterceptor.java +++ b/src/main/java/com/profiler/modifier/servlet/interceptors/HttpServletInterceptor.java @@ -14,12 +14,12 @@ import com.profiler.interceptor.ByteCodeMethodDescriptorSupport; import com.profiler.interceptor.MethodDescriptor; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.interceptor.TraceContextSupport; -import com.profiler.logging.LoggingUtils; +import com.profiler.sampler.util.SamplingFlagUtils; import com.profiler.util.NumberUtils; -public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethodDescriptorSupport, TraceContextSupport { +public class HttpServletInterceptor implements StaticAroundInterceptor, ByteCodeMethodDescriptorSupport, TraceContextSupport { - private final Logger logger = LoggerFactory.getLogger(DoXXXInterceptor.class); + private final Logger logger = LoggerFactory.getLogger(HttpServletInterceptor.class); private final boolean isDebug = logger.isDebugEnabled(); private MethodDescriptor descriptor; @@ -28,7 +28,7 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod /* java.lang.IllegalStateException: already Trace Object exist. at com.profiler.context.TraceContext.attachTraceObject(TraceContext.java:54) - at com.profiler.modifier.servlet.interceptors.DoXXXInterceptor.before(DoXXXInterceptor.java:62) + at com.profiler.modifier.servlet.interceptors.HttpServletInterceptor.before(HttpServletInterceptor.java:62) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java) // profile method ** at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) // profile method at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) @@ -52,33 +52,40 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { if (isDebug) { - LoggingUtils.logBefore(logger, target, className, methodName, parameterDescription, args); + logger.beforeInterceptor(target, className, methodName, parameterDescription, args); } try { // traceContext.getActiveThreadCounter().start(); HttpServletRequest request = (HttpServletRequest) args[0]; + boolean sampling = samplingEnable(request); + if (!sampling) { + // 샘플링 대상이 아닐 경우도 TraceObject를 생성하여, sampling 대상이 아니라는것을 명시해야 한다. + // sampling 대상이 아닐경우 rpc 호출에서 sampling 대상이 아닌 것에 rpc호출 파라미터에 sampling disable 파라미터를 박을수 있다. + traceContext.disableSampling(); + return; + } + String requestURL = request.getRequestURI(); - String clientIP = request.getRemoteAddr(); + String remoteAddr = request.getRemoteAddr(); TraceID traceId = populateTraceIdFromRequest(request); Trace trace; if (traceId != null) { if (logger.isInfoEnabled()) { - logger.info("TraceID exist. continue trace. " + traceId); - logger.debug("requestUrl:" + requestURL + " clientIp" + clientIP); + logger.debug("TraceID exist. continue trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } trace = traceContext.continueTraceObject(traceId); } else { trace = traceContext.newTraceObject(); if (logger.isInfoEnabled()) { - logger.info("TraceID not exist. start new trace. " + trace.getTraceId()); - logger.debug("requestUrl:" + requestURL + " clientIp" + clientIP); + logger.debug("TraceID not exist. start new trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } } trace.markBeforeTime(); + // TODO 잘못됬음 Servlet가 되어야함 trace.recordServiceType(ServiceType.TOMCAT); trace.recordRpcName(requestURL); @@ -86,7 +93,7 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod trace.recordEndPoint(request.getProtocol() + ":" + request.getServerName() + ((port > 0) ? ":" + port : "")); trace.recordDestinationId(request.getServerName() + ((port > 0) ? ":" + port : "")); trace.recordAttribute(AnnotationKey.HTTP_URL, request.getRequestURI()); - } catch (Exception e) { + } catch (Throwable e) { if (logger.isWarnEnabled()) { logger.warn("Tomcat StandardHostValve trace start fail. Caused:" + e.getMessage(), e); } @@ -96,7 +103,7 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod @Override public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { if (isDebug) { - LoggingUtils.logAfter(logger, target, className, methodName, parameterDescription, args, result); + logger.afterInterceptor(target, className, methodName, parameterDescription, args, result); } Trace trace = traceContext.currentTraceObject(); @@ -112,13 +119,7 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod } - if (trace.getStackFrameId() != 0) { - logger.warn("Corrupted CallStack found. StackId not Root(0)"); - // 문제 있는 callstack을 dump하면 도움이 될듯. - } - trace.recordApi(descriptor); -// trace.recordApi(this.apiId); trace.recordException(result); @@ -126,6 +127,12 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod trace.traceBlockEnd(); } + private boolean samplingEnable(HttpServletRequest request) { + // optional 값. + String samplingFlag = request.getHeader(Header.HTTP_SAMPLED.toString()); + return SamplingFlagUtils.isSamplingFlag(samplingFlag); + } + /** * Pupulate source trace from HTTP Header. * @@ -138,10 +145,9 @@ public class DoXXXInterceptor implements StaticAroundInterceptor, ByteCodeMethod UUID uuid = UUID.fromString(strUUID); int parentSpanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString()), SpanID.NULL); int spanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_SPAN_ID.toString()), SpanID.NULL); - boolean sampled = Boolean.parseBoolean(request.getHeader(Header.HTTP_SAMPLED.toString())); short flags = NumberUtils.parseShort(request.getHeader(Header.HTTP_FLAGS.toString()), (short) 0); - TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, sampled, flags); + TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, true, flags); if (logger.isInfoEnabled()) { logger.info("TraceID exist. continue trace. " + id); } diff --git a/src/main/java/com/profiler/modifier/tomcat/StandardHostValveInvokeModifier.java b/src/main/java/com/profiler/modifier/tomcat/StandardHostValveInvokeModifier.java index e23d13a3c..02fcd69b8 100644 --- a/src/main/java/com/profiler/modifier/tomcat/StandardHostValveInvokeModifier.java +++ b/src/main/java/com/profiler/modifier/tomcat/StandardHostValveInvokeModifier.java @@ -37,7 +37,6 @@ public class StandardHostValveInvokeModifier extends AbstractModifier { try { Interceptor interceptor = byteCodeInstrumentor.newInterceptor(classLoader, protectedDomain, "com.profiler.modifier.tomcat.interceptors.StandardHostValveInvokeInterceptor"); -// setTraceContext(interceptor); InstrumentClass standardHostValve = byteCodeInstrumentor.getClass(javassistClassName); standardHostValve.addInterceptor("invoke", new String[]{"org.apache.catalina.connector.Request", "org.apache.catalina.connector.Response"}, interceptor); 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 39a09b747..57f6857dc 100644 --- a/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java +++ b/src/main/java/com/profiler/modifier/tomcat/interceptors/StandardHostValveInvokeInterceptor.java @@ -14,7 +14,7 @@ import com.profiler.interceptor.ByteCodeMethodDescriptorSupport; import com.profiler.interceptor.MethodDescriptor; import com.profiler.interceptor.StaticAroundInterceptor; import com.profiler.interceptor.TraceContextSupport; -import com.profiler.logging.LoggingUtils; +import com.profiler.sampler.util.SamplingFlagUtils; import com.profiler.util.NetworkUtils; import com.profiler.util.NumberUtils; @@ -24,36 +24,42 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept private final boolean isDebug = logger.isInfoEnabled(); private MethodDescriptor descriptor; - // private int apiId; + private TraceContext traceContext; @Override public void before(Object target, String className, String methodName, String parameterDescription, Object[] args) { if (isDebug) { - LoggingUtils.logBefore(logger, target, className, methodName, parameterDescription, args); + logger.beforeInterceptor(target, className, methodName, parameterDescription, args); } try { // traceContext.getActiveThreadCounter().start(); HttpServletRequest request = (HttpServletRequest) args[0]; + + boolean sampling = samplingEnable(request); + if (!sampling) { + // 샘플링 대상이 아닐 경우도 TraceObject를 생성하여, sampling 대상이 아니라는것을 명시해야 한다. + // sampling 대상이 아닐경우 rpc 호출에서 sampling 대상이 아닌 것에 rpc호출 파라미터에 sampling disable 파라미터를 박을수 있다. + traceContext.disableSampling(); + return; + } + String requestURL = request.getRequestURI(); String remoteAddr = request.getRemoteAddr(); TraceID traceId = populateTraceIdFromRequest(request); Trace trace; if (traceId != null) { - if (logger.isInfoEnabled()) { - logger.info("TraceID exist. continue trace. " + traceId); - logger.debug("requestUrl:" + requestURL + ", remoteAddr:" + remoteAddr); + if (isDebug) { + logger.debug("TraceID exist. continue trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } - trace = traceContext.continueTraceObject(traceId); } else { trace = traceContext.newTraceObject(); - if (logger.isInfoEnabled()) { - logger.info("TraceID not exist. start new trace. " + trace.getTraceId()); - logger.debug("requestUrl:" + requestURL + ", remoteAddr:" + remoteAddr); + if (isDebug) { + logger.debug("TraceID not exist. start new trace. {} requestUrl:{}, remoteAddr:{}", new Object[] {traceId, requestURL, remoteAddr }); } } @@ -87,10 +93,11 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept @Override public void after(Object target, String className, String methodName, String parameterDescription, Object[] args, Object result) { if (isDebug) { - LoggingUtils.logAfter(logger, target, className, methodName, parameterDescription, args, result); + logger.afterInterceptor(target, className, methodName, parameterDescription, args, result); } // traceContext.getActiveThreadCounter().end(); + Trace trace = traceContext.currentTraceObject(); if (trace == null) { return; @@ -104,13 +111,7 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept } - if (trace.getStackFrameId() != 0) { - logger.warn("Corrupted CallStack found. StackId not Root(0)"); - // 문제 있는 callstack을 dump하면 도움이 될듯. - } - trace.recordApi(descriptor); - // trace.recordApi(this.apiId); trace.recordException(result); @@ -125,18 +126,18 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept * @return */ private TraceID populateTraceIdFromRequest(HttpServletRequest request) { + String strUUID = request.getHeader(Header.HTTP_TRACE_ID.toString()); if (strUUID != null) { + UUID uuid = UUID.fromString(strUUID); int parentSpanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_PARENT_SPAN_ID.toString()), SpanID.NULL); int spanID = NumberUtils.parseInteger(request.getHeader(Header.HTTP_SPAN_ID.toString()), SpanID.NULL); - boolean sampled = Boolean.parseBoolean(request.getHeader(Header.HTTP_SAMPLED.toString())); short flags = NumberUtils.parseShort(request.getHeader(Header.HTTP_FLAGS.toString()), (short) 0); - - TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, sampled, flags); + TraceID id = this.traceContext.createTraceId(uuid, parentSpanID, spanID, true, flags); if (logger.isInfoEnabled()) { - logger.info("TraceID exist. continue trace. " + id); + logger.info("TraceID exist. continue trace. {}", id); } return id; } else { @@ -144,7 +145,13 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept } } - private String populateParentApplicationNameFromRequest(HttpServletRequest request) { + private boolean samplingEnable(HttpServletRequest request) { + // optional 값. + String samplingFlag = request.getHeader(Header.HTTP_SAMPLED.toString()); + return SamplingFlagUtils.isSamplingFlag(samplingFlag); + } + + private String populateParentApplicationNameFromRequest(HttpServletRequest request) { return request.getHeader(Header.HTTP_PARENT_APPLICATION_NAME.toString()); } @@ -158,7 +165,7 @@ public class StandardHostValveInvokeInterceptor implements StaticAroundIntercept private String getRequestParameter(HttpServletRequest request) { Enumeration attrs = request.getParameterNames(); - StringBuilder params = new StringBuilder(); + final StringBuilder params = new StringBuilder(32); while (attrs.hasMoreElements()) { String keyString = attrs.nextElement().toString();