Shadow tracing context. Thread dump error when pressure test

[jinlongwang]

Please answer these questions before submitting your issue.

• Why do you submit this issue?
• Question or discussion
• Bug
• Requirement
• Feature or performance improvement

---

Question

• What do you want to know?

---

Bug

• Which version of SkyWalking, OS and JRE?
  SkyWalking: 5.0.0-beta2
  OS: CentOS release 6.6 (Final)
  JRE: jdk1.7.0_80

• Which company or project?
  autohome Inc

• What happen?
  My application provide a http interface and it will query redis. i added skywalking agent to my application. When qps under 2000 everything is fine but when the qps over 2000 i get some exceptions

WARN 2018-08-15 19:04:36 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:515)
	at org.apache.skywalking.apm.agent.core.context.TracingContext.access$100(TracingContext.java:56)
	at org.apache.skywalking.apm.agent.core.context.TracingContext$7.doProcess(TracingContext.java:334)
	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:330)
	at org.apache.skywalking.apm.agent.core.context.ContextManager.createExitSpan(ContextManager.java:125)
	at org.apache.skywalking.apm.plugin.jedis.v2.JedisMethodInterceptor.beforeMethod(JedisMethodInterceptor.java:37)
	at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:82)
	at redis.clients.jedis.Jedis.get(Jedis.java)

obviously， this http interface can not have to many spans. so what's wrong with it?

---

Requirement or improvement

• Please describe about your requirements or improvement suggestions.

[wu-sheng]

This is not related to qps. This is a warning, means too many spans in a single one request trace. The most likely reason is, there is trace leak.

What does your trace look like normally? How many spans?

[jinlongwang]

you'r right. we fixed this problem. there is something wrong with plugins. the quality of these plugins is uneven. we found there is bug in springmvc plugin. here the infos:

plugin: apm-springmvc-annotation-commons
package: org.apache.skywalking.apm.plugin.spring.mvc.commons.interceptor
class: AbstractMethodInterceptor
method: afterMethod
line: 104

    @Override
    public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
        Object ret) throws Throwable {
        Boolean forwardRequestFlag = (Boolean)ContextManager.getRuntimeContext().get(FORWARD_REQUEST_FLAG);
        /**
         * Spring MVC plugin do nothing if current request is forward request.
         * Ref: https://github.com/apache/incubator-skywalking/pull/1325
         */
        if (forwardRequestFlag != null && forwardRequestFlag) {
            return ret;
        }

        HttpServletResponse response = (HttpServletResponse)ContextManager.getRuntimeContext().get(RESPONSE_KEY_IN_RUNTIME_CONTEXT);
        try {
            if (response != null) {
                AbstractSpan span = ContextManager.activeSpan();
                if (response.getStatus() >= 400) {
                    span.errorOccurred();
                    Tags.STATUS_CODE.set(span, Integer.toString(response.getStatus()));
                }
                ContextManager.stopSpan();
            }
        } finally {
            ContextManager.getRuntimeContext().remove(REQUEST_KEY_IN_RUNTIME_CONTEXT);
            ContextManager.getRuntimeContext().remove(RESPONSE_KEY_IN_RUNTIME_CONTEXT);
        }

        return ret;
    }

this statement ContextManager.stopSpan(); may not execute, then this problem will be be triggered.

ContextManager.stopSpan(); is very important, We think the plugin‘s author did not understand the meaning of this sentence.

we will send pull request soon

[wu-sheng]

Yes. that is very important. Look forward to your PR. I hope to fix this in RC release, which I will try to do in next week.

[wu-sheng]

FYI @ascrutae Please notice this, and review the incoming PR. Make sure this serious bug fixed.

[ni-ze]

@wu-sheng Has this problem been solved? I found it in 5.0.0-ga. It occur NullPointException in org.apache.skywalking.apm.agent.core.context.ContextManager#activeSpan . I think get() null from ThreadLocal.