Skywalking ContextManager.active

作者: 杨_同_学 | 来源:发表于2019-08-13 19:19 被阅读0次

触发bug的条件

当前TraceSegment创建的太多了span（超过参数agent.span_limit_per_segment的配置，默认300）之后，执行ContextManager.createExitSpan的时候会创建NoopExitSpan
grpc agent 对远程调用拦截的时候会有两个Interceptor生效，也就是说会执行两次ContextManager.CreateExitSpan和ContextManager.StopSpan

具体原因

对于正常的ExitSpan来说，第二次执行createExitSpan的时候，如果发现当前栈的头位置已经是ExitSpan就不再创建新的，而是对这个ExitSpan调用start操作（stackDepth++）。在调用stopSpan的时候，会检查ExitSpan的finish（stackDepth-- == 0），如果为true，才pop。所以只会pop一次，没有问题

如果因为Span太多，超过限制，创建的是NoopExitSpan的时候，第二次执行createExitSpan的时候，因为NoopExitSpan的isExit方法返回true，所以也只会创建一个Span，第二次的时候只会调用NoopExitSpan的start方法（实现为空）。但是在调用stopSpan的时候，不会对NoopExit，而是直接pop，所以就会pop出两个span，其中一个span是别的拦截器的span。

这样就会导致接下来当前线程的span都对应不上了，后面的拦截器调用stopSpan的时候就会因为找不到span而抛出空指针异常

ERROR io.grpc.internal.SerializingExecutor - Exception while executing runnable io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed@5de15ec
java.lang.NullPointerException: null
  at org.apache.skywalking.apm.agent.core.context.ContextManager.activeSpan(ContextManager.java:161)
  at org.apache.skywalking.apm.agent.core.context.ContextManager.stopSpan(ContextManager.java:165)
  at org.apache.skywalking.apm.plugin.babyfs.grpc.v1.CallServerInterceptor$ServerCallListener.onHalfClose(CallServerInterceptor.java:173)
  at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:283)
  at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:710)
  at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
  at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  at java.lang.Thread.run(Thread.java:745)

具体过程

首先是在测试环境中发现偶尔会有上面的空指针异常，一开始是怀疑某一个agent的拦截器会不会因为bug没有创建Span，就直接关闭了Span，导致对应不上的。因为agent 的插件有很多，很难定位是哪个插件的原因，幸好后来继续看日志的时候发现一个规律。在发生在这个异常之前，同一个线程中都会报如下warn：

WARN 2019-08-09 17:54:31:190 http-nio-10011-exec-1 TracingContext :  More than 300 spans required to create 
java.lang.RuntimeException: Shadow tracing context. Thread dump
    at org.apache.skywalking.apm.agent.core.context.TracingContext.isLimitMechanismWorking(TracingContext.java:554)
    at org.apache.skywalking.apm.agent.core.context.TracingContext.access$100(TracingContext.java:47)
    at org.apache.skywalking.apm.agent.core.context.TracingContext$5.doProcess(TracingContext.java:327)
    at org.apache.skywalking.apm.agent.core.dictionary.PossibleFound.doInCondition(PossibleFound.java:50)
    at org.apache.skywalking.apm.agent.core.context.TracingContext.createExitSpan(TracingContext.java:323)
    at org.apache.skywalking.apm.agent.core.context.ContextManager.createExitSpan(ContextManager.java:122)
    at org.apache.skywalking.apm.plugin.grpc.v1.BlockingCallInterceptor.beforeMethod(BlockingCallInterceptor.java:42)
    at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.StaticMethodsInter.intercept(StaticMethodsInter.java:76)
    at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java)

后来在开发环境直接做实现，发现只要创建的span数量超过300，就能稳定复现文章开头的异常，所以很可能跟这个是有关系的。继续看CreateExitSpan的代码，看到CreateExitSpan的时候会先判断当前已经在ExitSpan中的话就直接调用ExitSpan的start方法，start方法中会对stackDepth++，而在StopSpan的时候，对于ExitSpan会先执行finish判断（stackDepth-- == 0），如果为true，才执行pop，逻辑完全没问题

AbstractSpan exitSpan;
        AbstractSpan parentSpan = peek();
        if (parentSpan != null && parentSpan.isExit()) {
            exitSpan = parentSpan;
        } else {
            final int parentSpanId = parentSpan == null ? -1 : parentSpan.getSpanId();
            exitSpan = (AbstractSpan)DictionaryManager.findNetworkAddressSection()
                .find(remotePeer).doInCondition(
                    new PossibleFound.FoundAndObtain() {
                        @Override
                        public Object doProcess(final int peerId) {
                            if (isLimitMechanismWorking()) {
                                return new NoopExitSpan(peerId);
                            }

                            return DictionaryManager.findEndpointSection()
                                .findOnly(segment.getServiceId(), operationName)
                                .doInCondition(
                                    new PossibleFound.FoundAndObtain() {
                                        @Override
                                        public Object doProcess(int operationId) {
                                            return new ExitSpan(spanIdGenerator++, parentSpanId, operationId, peerId);
                                        }
                                    }, new PossibleFound.NotFoundAndObtain() {
                                        @Override
                                        public Object doProcess() {
                                            return new ExitSpan(spanIdGenerator++, parentSpanId, operationName, peerId);
                                        }
                                    });
                        }
                    },
                    new PossibleFound.NotFoundAndObtain() {
                        @Override
                        public Object doProcess() {
                            if (isLimitMechanismWorking()) {
                                return new NoopExitSpan(remotePeer);
                            }

                            return DictionaryManager.findEndpointSection()
                                .findOnly(segment.getServiceId(), operationName)
                                .doInCondition(
                                    new PossibleFound.FoundAndObtain() {
                                        @Override
                                        public Object doProcess(int operationId) {
                                            return new ExitSpan(spanIdGenerator++, parentSpanId, operationId, remotePeer);
                                        }
                                    }, new PossibleFound.NotFoundAndObtain() {
                                        @Override
                                        public Object doProcess() {
                                            return new ExitSpan(spanIdGenerator++, parentSpanId, operationName, remotePeer);
                                        }
                                    });
                        }
                    });
            push(exitSpan);
        }
        exitSpan.start();
        return exitSpan;

public ExitSpan start() {
        if (++stackDepth == 1) {
            super.start();
        }
        return this;
    }

 @Override
    public boolean finish(TraceSegment owner) {
        if (--stackDepth == 0) {
            if (this.operationId == DictionaryUtil.nullValue()) {
                this.operationId = (Integer)DictionaryManager.findEndpointSection()
                    .findOrPrepare4Register(owner.getServiceId(), operationName, this.isEntry(), this.isExit())
                    .doInCondition(
                        new PossibleFound.FoundAndObtain() {
                            @Override public Object doProcess(int value) {
                                return value;
                            }
                        },
                        new PossibleFound.NotFoundAndObtain() {
                            @Override public Object doProcess() {
                                return DictionaryUtil.nullValue();
                            }
                        }
                    );
            }
            return super.finish(owner);
        } else {
            return false;
        }
    }

同时在创建ExitSpan的时候，会检查isLimitMechanismWorking（如果已经span数量已经超过agent.span_limit_per_segment的配置就会返回true），如果为true就返回NoopExitSpan，问题就出在NoopExitSpan上面了。因为NoopExitSpan的isExit方法也返回true，也被认为是一个ExitSpan。所以如果在一个远程调用中如果被执行两次CreateSpan，只会有一个NoopExitSpan被创建出来，第二次的时候只会执行NoopExitSpan的start方法，而NoopExitSpan的start方法是空的。stopSpan也会被执行两次，两次都会执行pop操作，就导致pop出来了一个不属于当前远程调用的span，该tracesegment在后面的stopSpan方法就会因为找不到span而抛出异常。

解决办法

在createExitSpan之前先检查是否达到限制，如果达到限制，直接创建NoopExitSpan并push进stack进去，然后返回

@Override
    public AbstractSpan createExitSpan(final String operationName, final String remotePeer) {
        if (isLimitMechanismWorking()) {
            NoopExitSpan span = new NoopExitSpan(remotePeer);
            return push(span);
        }

        AbstractSpan exitSpan;
        AbstractSpan parentSpan = peek();
        if (parentSpan != null && parentSpan.isExit()) {
            exitSpan = parentSpan;
        }

Skywalking ContextManager.active

触发bug的条件

具体原因

具体过程

解决办法

相关文章

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读

APM监控