Skywalking: Wrong display when there is pathvariable in path

[evanxuhe]

Please answer these questions before submitting your issue.

• Why do you submit this issue?
• [ ] Question or discussion

Wrong display when there is pathvariable in path

---

Question

• What do you want to know?

---

Bug

• Which version of SkyWalking, OS and JRE?
  Skywalking6.1.0
  SpringMVC

• Which company or project?

• What happen?
  If possible, provide a way for reproducing the error. e.g. demo application, component version.
  Normally, a normal request shows two span(Tomcat+ControllerMethod）
  

But，when there is pathvariable in path. It displays very odd.

What's more, it appears like normally but there are some features when displays wrongly

• Id always ends with 0001
• only one Spring MVC span
  which seems like that Tomcat Instrument doesn't work and request arrives at SpringMVC directly
  do you have any idea on why this happen?

Requirement or improvement

• Please describe about your requirements or improvement suggestions.

[wu-sheng]

which seems like that Tomcat Instrument doesn't work and request arrives at SpringMVC directly
do you have any idea on why this happen?

That is your codes doing in this way. Talk with your developer, they know what {path} means in Spring. Also, once SpringMVC active, should should happen.

[wu-sheng]

/apm/post/666 will break endpoint aggregation. And it is meanless. If you want to see this in trace, check url tag, it is there.

[evanxuhe]

which seems like that Tomcat Instrument doesn't work and request arrives at SpringMVC directly
do you have any idea on why this happen?

That is your codes doing in this way. Talk with your developer, they know what {path} means in Spring. Also, once SpringMVC active, should should happen.

Sorry. that's not what I mean.
I wanna it shows the same way. as /apm/post/666 or another one /apm/post/{path}. But it shows in some way randomly. Bad experience.

So, is it the problem in oap aggregator rather than agent?
_Can you point specific class name that can fix this problem?_
Thank you!

[wu-sheng]

I wanna it shows the same way. as /apm/post/666 or another one /apm/post/{path}. But it shows in some way randomly. Bad experience.

In the design and codes level, it always should show /apm/post/{path}, should not be random. Unless you build some async mechanism between Tomcat and SpringMVC, which could cause random things.

[wu-sheng]

So, is it the problem in oap aggregator rather than agent?
Can you point specific class name that can fix this problem?

It is inside agent core and automatically work w/o plugin codes, only depends on ThreadLocal only. So, I don't know the cause yet.

[qixiaobo]

I noticed that the http tag with SpringMVC may correct.
Because in springmvc framework , we may know the requestmapping value.
But in tomcat ,it can only be requestUrl.
The code below

 String operationName;
        if (Config.Plugin.SpringMVC.USE_QUALIFIED_NAME_AS_ENDPOINT_NAME) {
            operationName = MethodUtil.generateOperationName(method);
        } else {
            EnhanceRequireObjectCache pathMappingCache = (EnhanceRequireObjectCache)objInst.getSkyWalkingDynamicField();
            String requestURL = pathMappingCache.findPathMapping(method);
            if (requestURL == null) {
                requestURL = getRequestURL(method);
                pathMappingCache.addPathMapping(method, requestURL);
                requestURL = getAcceptedMethodTypes(method) + pathMappingCache.findPathMapping(method);
            }
            operationName = requestURL;
        }

 HttpServletRequest request = (HttpServletRequest)ContextManager.getRuntimeContext().get(REQUEST_KEY_IN_RUNTIME_CONTEXT);
        if (request != null) {
            StackDepth stackDepth = (StackDepth)ContextManager.getRuntimeContext().get(CONTROLLER_METHOD_STACK_DEPTH);

            if (stackDepth == null) {
                ContextCarrier contextCarrier = new ContextCarrier();
                CarrierItem next = contextCarrier.items();
                while (next.hasNext()) {
                    next = next.next();
                    next.setHeadValue(request.getHeader(next.getHeadKey()));
                }

                AbstractSpan span = ContextManager.createEntrySpan(operationName, contextCarrier);
                Tags.URL.set(span, request.getRequestURL().toString());
                Tags.HTTP.METHOD.set(span, request.getMethod());
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
                SpanLayer.asHttp(span);

                stackDepth = new StackDepth();
                ContextManager.getRuntimeContext().put(CONTROLLER_METHOD_STACK_DEPTH, stackDepth);
            } else {
                AbstractSpan span =
                    ContextManager.createLocalSpan(buildOperationName(objInst, method));
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
            }

            stackDepth.increment();
        }

but in tomcat

  @Override public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments,
        Class<?>[] argumentsTypes, MethodInterceptResult result) throws Throwable {
        HttpServletRequest request = (HttpServletRequest)allArguments[0];
        ContextCarrier contextCarrier = new ContextCarrier();

        CarrierItem next = contextCarrier.items();
        while (next.hasNext()) {
            next = next.next();
            next.setHeadValue(request.getHeader(next.getHeadKey()));
        }

        AbstractSpan span = ContextManager.createEntrySpan(request.getRequestURI(), contextCarrier);
        Tags.URL.set(span, request.getRequestURL().toString());
        Tags.HTTP.METHOD.set(span, request.getMethod());
        span.setComponent(ComponentsDefine.TOMCAT);
        SpanLayer.asHttp(span);

    }

As we can see , sw only set the requestUrl to url tag.
So it maybe tomcat plugin has a conflict with springMVC framework???

[qixiaobo]

So if springMVC is entry ,we can see aggregation happens.

[evanxuhe]

Yes I think the same way.
There may be
conflicts between web container interceptor(like Tomcat and Undertow) And SpringMVC Intercepeter.

Because.
It appears randomly as below at the same time. No obvious rule.
Debug shows that two intercpters(Tomcat+MVC) both work. Both of them create EntrySpan
And I didn't see any way that there are code that solves the conflicts when both interceptors create Entry Span

[evanxuhe]

So, is it the problem in oap aggregator rather than agent?
Can you point specific class name that can fix this problem?

It is inside agent core and automatically work w/o plugin codes, only depends on ThreadLocal only. So, I don't know the cause yet.

Yes I think the same way.
There may be
conflicts between web container interceptor(like Tomcat and Undertow) And SpringMVC Intercepeter.

Because.
It appears randomly as below at the same time. No obvious rule.
Debug shows that two intercpters(Tomcat+MVC) both work. Both of them create EntrySpan
And I didn't see any way that there are code that solves the conflicts when both interceptors create Entry Span

[evanxuhe]

So if springMVC is entry ,we can see aggregation happens.

I am confused that why this happens randomly. Since two interceptors works orderly.

[qixiaobo]

So if springMVC is entry ,we can see aggregation happens.

I am confused that why this happens randomly. Since two interceptors works orderly.

Me 2 😢

[qixiaobo]

You may notice if springmvc framework is not the entry , so it may has no type named unknown.
The code below

if (stackDepth == null) {
                ContextCarrier contextCarrier = new ContextCarrier();
                CarrierItem next = contextCarrier.items();
                while (next.hasNext()) {
                    next = next.next();
                    next.setHeadValue(request.getHeader(next.getHeadKey()));
                }

                AbstractSpan span = ContextManager.createEntrySpan(operationName, contextCarrier);
                Tags.URL.set(span, request.getRequestURL().toString());
                Tags.HTTP.METHOD.set(span, request.getMethod());
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
                SpanLayer.asHttp(span);

                stackDepth = new StackDepth();
                ContextManager.getRuntimeContext().put(CONTROLLER_METHOD_STACK_DEPTH, stackDepth);
            } else {
                AbstractSpan span =
                    ContextManager.createLocalSpan(buildOperationName(objInst, method));
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
            }

no asHttp invoked.

[evanxuhe]

Which is very wired. I think so
And which causes lots of endpoint data in ES, whichi is rather bad

Whats more , I have catch the params in AbstractMethodInterceptor .
We can see that when it AbstractMethodInterceptor normally , it displays {path}rightly

While, when it displays path1234XX wrongly. AbstractMethodInterceptor doesn't work

It shows randomly without rules

So is there possibility of tomcat entry cover the mvc entry

[qixiaobo]

Which is very wired. I think so
And which causes lots of endpoint data in ES, whichi is rather bad

Whats more , I have catch the params in AbstractMethodInterceptor .
We can see that when it AbstractMethodInterceptor normally , it displays {path}rightly

While, when it displays path1234XX wrongly. AbstractMethodInterceptor doesn't work

It shows randomly without rules

So is there possibility of tomcat entry cover the mvc entry

I think so. But why some requests can perform normally like that no tomcat plugin take effect.
It looks like that this request direct arrive to the springMVC framework.
That's strange.

[evanxuhe]

I found some rules!
The process id is related
All {path} trace ends with 0001, which means it is the first process
While
All {12345} trace ends with 0003 0005 and increases which means they have through some processes
Does it reminds you of some thing?

[evanxuhe]

[qixiaobo]

What's the trace id ending with 001 stands for?
It marks the first entry??? Thread?

[qixiaobo]

 if (request != null) {
            StackDepth stackDepth = (StackDepth)ContextManager.getRuntimeContext().get(CONTROLLER_METHOD_STACK_DEPTH);

            if (stackDepth == null) {
                ContextCarrier contextCarrier = new ContextCarrier();
                CarrierItem next = contextCarrier.items();
                while (next.hasNext()) {
                    next = next.next();
                    next.setHeadValue(request.getHeader(next.getHeadKey()));
                }

                AbstractSpan span = ContextManager.createEntrySpan(operationName, contextCarrier);
                Tags.URL.set(span, request.getRequestURL().toString());
                Tags.HTTP.METHOD.set(span, request.getMethod());
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
                SpanLayer.asHttp(span);

                stackDepth = new StackDepth();
                ContextManager.getRuntimeContext().put(CONTROLLER_METHOD_STACK_DEPTH, stackDepth);
            } else {
                AbstractSpan span =
                    ContextManager.createLocalSpan(buildOperationName(objInst, method));
                span.setComponent(ComponentsDefine.SPRING_MVC_ANNOTATION);
            }

            stackDepth.increment();
        }

So in this sence , the stackDepth must be null! If the springMvc framework appears first.

[qixiaobo]

 @Override
    public AbstractSpan createEntrySpan(final String operationName) {
        if (isLimitMechanismWorking()) {
            NoopSpan span = new NoopSpan();
            return push(span);
        }
        AbstractSpan entrySpan;
        final AbstractSpan parentSpan = peek();
        final int parentSpanId = parentSpan == null ? -1 : parentSpan.getSpanId();
        if (parentSpan != null && parentSpan.isEntry()) {
            entrySpan = (AbstractTracingSpan)DictionaryManager.findEndpointSection()
                .findOnly(segment.getServiceId(), operationName)
                .doInCondition(new PossibleFound.FoundAndObtain() {
                    @Override public Object doProcess(int operationId) {
                        return parentSpan.setOperationId(operationId);
                    }
                }, new PossibleFound.NotFoundAndObtain() {
                    @Override public Object doProcess() {
                        return parentSpan.setOperationName(operationName);
                    }
                });
            return entrySpan.start();
        } else {
            entrySpan = (AbstractTracingSpan)DictionaryManager.findEndpointSection()
                .findOnly(segment.getServiceId(), operationName)
                .doInCondition(new PossibleFound.FoundAndObtain() {
                    @Override public Object doProcess(int operationId) {
                        return new EntrySpan(spanIdGenerator++, parentSpanId, operationId);
                    }
                }, new PossibleFound.NotFoundAndObtain() {
                    @Override public Object doProcess() {
                        return new EntrySpan(spanIdGenerator++, parentSpanId, operationName);
                    }
                });
            entrySpan.start();
            return push(entrySpan);
        }
    }

I can see it depends on the spanIdGenerator field which default is 0.

[qixiaobo]

What's the trace id ending with 001 stands for?
It marks the first entry??? Thread?

Ah , I see.It can tell us some plugins or some spans may exists.

[qixiaobo]

Our services have a lot of endpoints. It causes huge of write operations to es ,so we have a poor performance.

[evanxuhe]

Our services have a lot of endpoints. It causes huge of write operations to es ,so we have a poor performance.

Yes I have experiences many problems. which finally leads to ES

[evanxuhe]

 @Override
    public AbstractSpan createEntrySpan(final String operationName) {
        if (isLimitMechanismWorking()) {
            NoopSpan span = new NoopSpan();
            return push(span);
        }
        AbstractSpan entrySpan;
        final AbstractSpan parentSpan = peek();
        final int parentSpanId = parentSpan == null ? -1 : parentSpan.getSpanId();
        if (parentSpan != null && parentSpan.isEntry()) {
            entrySpan = (AbstractTracingSpan)DictionaryManager.findEndpointSection()
                .findOnly(segment.getServiceId(), operationName)
                .doInCondition(new PossibleFound.FoundAndObtain() {
                    @Override public Object doProcess(int operationId) {
                        return parentSpan.setOperationId(operationId);
                    }
                }, new PossibleFound.NotFoundAndObtain() {
                    @Override public Object doProcess() {
                        return parentSpan.setOperationName(operationName);
                    }
                });
            return entrySpan.start();
        } else {
            entrySpan = (AbstractTracingSpan)DictionaryManager.findEndpointSection()
                .findOnly(segment.getServiceId(), operationName)
                .doInCondition(new PossibleFound.FoundAndObtain() {
                    @Override public Object doProcess(int operationId) {
                        return new EntrySpan(spanIdGenerator++, parentSpanId, operationId);
                    }
                }, new PossibleFound.NotFoundAndObtain() {
                    @Override public Object doProcess() {
                        return new EntrySpan(spanIdGenerator++, parentSpanId, operationName);
                    }
                });
            entrySpan.start();
            return push(entrySpan);
        }
    }

I can see it depends on the spanIdGenerator field which default is 0.

I will try to debug this part to find out problem

[evanxuhe]

Our services have a lot of endpoints. It causes huge of write operations to es ,so we have a poor performance.

I found that
Undertow interceptor works in XNIO-I/O -1 thread
SpringMVC interceptor works in XNIO-2 task1 thread

XNIO-I/O -1: Undertow
XNIO-2 task1 Undertow+SpringMVC
Does it explains the problem

[qixiaobo]

Our services have a lot of endpoints. It causes huge of write operations to es ,so we have a poor performance.

I found that
Undertow interceptor works in XNIO-I/O -1 thread
SpringMVC interceptor works in XNIO-2 task1 thread

XNIO-I/O -1: Undertow
XNIO-2 task1 Undertow+SpringMVC
Does it explains the problem

I should say our tomcat use nio model.
It absolutely makes the same result like Undertow.
But I should have a right result nor a random operation name

[evanxuhe]

Our services have a lot of endpoints. It causes huge of write operations to es ,so we have a poor performance.

I found that
Undertow interceptor works in XNIO-I/O -1 thread
SpringMVC interceptor works in XNIO-2 task1 thread
XNIO-I/O -1: Undertow
XNIO-2 task1 Undertow+SpringMVC
Does it explains the problem

I should say our tomcat use nio model.
It absolutely makes the same result like Undertow.
But I should have a right result nor a random operation name

Which is wired but very common in all of our environments. Nealy all of endpoints show number directly rather than ${path}.

[wu-sheng]

I should say our tomcat use nio model.
It absolutely makes the same result like Undertow.

NIO is just the transport level thing, nothing related to framework process model. Some middleware or some modes of middleware are different, which make async happens between the plugin of middleware and the plugin of SpringMVC. Easy way to solve this, remove the middleware plugin, simple.

[qixiaobo]

I should say our tomcat use nio model.
It absolutely makes the same result like Undertow.

NIO is just the transport level thing, nothing related to framework process model. Some middleware or some modes of middleware are different, which make async happens between the plugin of middleware and the plugin of SpringMVC. Easy way to solve this, remove the middleware plugin, simple.

As far as I can see , we should remove tomcat sdk and undertow sdk first to decrease the pressure of es.
But how to solve this problem ?I think we can find the requestUrl differs to springMvc annotation.
Then we may find the parent span to modify the operationName with HttpTag

[qixiaobo]

I should say our tomcat use nio model.
It absolutely makes the same result like Undertow.

NIO is just the transport level thing, nothing related to framework process model. Some middleware or some modes of middleware are different, which make async happens between the plugin of middleware and the plugin of SpringMVC. Easy way to solve this, remove the middleware plugin, simple.

As far as I can see , we should remove tomcat sdk and undertow sdk first to decrease the pressure of es.
But how to solve this problem ?I think we can find the requestUrl differs to springMvc annotation.
Then we may find the parent span to modify the operationName with HttpTag

The same with jetty ,resin and so on... if using pathVariable

[wu-sheng]

I think most likely, this is based on what you are doing, rather than skywalking did. How you make the process through multiple threads for a simple HTTP request. I am 100% sure, this should not happen in most applications. And it is not related to pathVariable at all. You are misreading the case.

[qixiaobo]

I think most likely, this is based on what you are doing, rather than skywalking did. How you make the process through multiple threads for a simple HTTP request. I am 100% sure, this should not happen in most applications. And it is not related to pathVariable at all. You are misreading the case.

I will consider about it……