New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

@NewSpan annotation doesn't work #617

Closed
zavale opened this Issue Jun 17, 2017 · 14 comments

Comments

Projects
None yet
3 participants
@zavale

zavale commented Jun 17, 2017

I have a problem with @NewSpan doesn't generate new span and as a result is not reported to Zipkin server. Explicit spans, created not by annotation, are successfully generated and reported. For reproducing the problem, please run attached Maven project. The project is based on a Maven project generated by https://start.spring.io/, with just a few components - Web, Sleuth and Zipkin client.

For reproducing, hit the endpoint http://localhost:8080/test
The simple Controller should generate the implicit trace with a custom span, but custom span is not generated - observed in the logs, and also on the locally running Zipkin server.

Few suspicious log generated during the application start are:

objc[48907]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_101.jdk/Contents/Home/bin/java (0x1097344c0) and /Library/Java/JavaVirtualMachines/jdk1.8.0_101.jdk/Contents/Home/jre/lib/libinstrument.dylib (0x10b7b64e0). One of the two will be used. Which one is undefined.
2017-06-16 18:00:48.608  INFO [bootstrap,,,] 48907 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@36f0f1be: startup date [Fri Jun 16 18:00:48 PDT 2017]; root of context hierarchy
2017-06-16 18:00:48.785  INFO [bootstrap,,,] 48907 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'configurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$b19b06da] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
 :: Spring Boot ::        (v1.5.4.RELEASE)

2017-06-16 18:00:53.994  INFO [Demo,,,] 48907 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2017-06-16 18:00:54.005  INFO [Demo,,,] 48907 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@404bbcbd: startup date [Fri Jun 16 18:00:54 PDT 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@36f0f1be
2017-06-16 18:00:54.407  INFO [Demo,,,] 48907 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=3e015390-8e57-32f2-b31c-06909b5945fd
2017-06-16 18:00:54.498  INFO [Demo,,,] 48907 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.sleuth.annotation.SleuthAnnotationAutoConfiguration' of type [org.springframework.cloud.sleuth.annotation.SleuthAnnotationAutoConfiguration$$EnhancerBySpringCGLIB$$97e64a0f] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2017-06-16 18:00:54.671  INFO [Demo,,,] 48907 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'sleuthAdvisorConfig' of type [org.springframework.cloud.sleuth.annotation.SleuthAdvisorConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2017-06-16 18:00:54.673  INFO [Demo,,,] 48907 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$b19b06da] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)

Where beans related to sleuth reported as not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)

demo-no_annotations_working.zip

@marcingrzejszczak

This comment has been minimized.

Show comment
Hide comment
@marcingrzejszczak

marcingrzejszczak Jun 17, 2017

Contributor

Hi! Thanks for the issue. Could you please upload the sample to Github as a project? Thanks

Contributor

marcingrzejszczak commented Jun 17, 2017

Hi! Thanks for the issue. Could you please upload the sample to Github as a project? Thanks

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale Jun 18, 2017

@marcingrzejszczak You may import Maven project from https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect Please note, Zipkin server is supposed to run on http://localhost:9411/ but even if it doesn't run there, you will be able to see the @NewSpan annotation being ignored from Sleuth debug logs.

zavale commented Jun 18, 2017

@marcingrzejszczak You may import Maven project from https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect Please note, Zipkin server is supposed to run on http://localhost:9411/ but even if it doesn't run there, you will be able to see the @NewSpan annotation being ignored from Sleuth debug logs.

@marcingrzejszczak

This comment has been minimized.

Show comment
Hide comment
@marcingrzejszczak

marcingrzejszczak Jun 18, 2017

Contributor

It's not working cause you need to put the annotated method in a separate class. We're creating a proxy of the object so if you're calling a proxied method from the proxy itself then the method will be called directly without going through the proxy logic. I'll try to update the docs with that warning

Contributor

marcingrzejszczak commented Jun 18, 2017

It's not working cause you need to put the annotated method in a separate class. We're creating a proxy of the object so if you're calling a proxied method from the proxy itself then the method will be called directly without going through the proxy logic. I'll try to update the docs with that warning

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale Jun 18, 2017

@marcingrzejszczak I moved annotated method to the separate class, and it's still not working for me. I pushed the modification to https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect master. The span from the annotation is not created - I cannot observe it, neither in the Sleuth debug logs or Zipkin traces. Could you please take a look?

zavale commented Jun 18, 2017

@marcingrzejszczak I moved annotated method to the separate class, and it's still not working for me. I pushed the modification to https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect master. The span from the annotation is not created - I cannot observe it, neither in the Sleuth debug logs or Zipkin traces. Could you please take a look?

@marcingrzejszczak

This comment has been minimized.

Show comment
Hide comment
@marcingrzejszczak

marcingrzejszczak Jun 18, 2017

Contributor

Of course it's not working - you need to register it as a bean. That's how proxies work in Spring. Just annotate it with @Component

Contributor

marcingrzejszczak commented Jun 18, 2017

Of course it's not working - you need to register it as a bean. That's how proxies work in Spring. Just annotate it with @Component

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale Jun 18, 2017

@marcingrzejszczak Thanks for the response - I added @Component annotation to

@Component
public
class SpanTest {

    @NewSpan
    public void spanTest() {
        for (int i=0; i<100000000; i++);
    }
}

Pushed to master here: https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect

But span still doesn't appear in the trace - not in the logs, and not on the locally running Zipkin. Could you please refer me to the working code sample?

zavale commented Jun 18, 2017

@marcingrzejszczak Thanks for the response - I added @Component annotation to

@Component
public
class SpanTest {

    @NewSpan
    public void spanTest() {
        for (int i=0; i<100000000; i++);
    }
}

Pushed to master here: https://github.com/zavale/spring-cloud-sleuth-NewSpan-annotation-defect

But span still doesn't appear in the trace - not in the logs, and not on the locally running Zipkin. Could you please refer me to the working code sample?

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale Jun 19, 2017

@marcingrzejszczak Thanks for the reference, looking there, I managed to make my example working. Just wanted to summarize my understanding of how to make @NewSpan annotation working, and limitations that it imposes

  1. To create Span for a method foo, using @NewSpan annotation, a class ClassOfFoo that method foo belongs to, has to be declared as Bean.

  2. That means, that ClassOfFoo is a singleton - no dynamic instantiation, no multiple instances

  3. Spans a created, only when method foo is called outside of ClassOfFoo.

  4. That means that if method foo calls to method fooInternal, which also declared with @NewSpan annotation in a class ClassOfFoo*, no span will be created for fooInternal.

Could you please clarify that my understanding is correct.
I actually, tested that in a code, but want to make sure that I am not missing anything.

Thanks again!

zavale commented Jun 19, 2017

@marcingrzejszczak Thanks for the reference, looking there, I managed to make my example working. Just wanted to summarize my understanding of how to make @NewSpan annotation working, and limitations that it imposes

  1. To create Span for a method foo, using @NewSpan annotation, a class ClassOfFoo that method foo belongs to, has to be declared as Bean.

  2. That means, that ClassOfFoo is a singleton - no dynamic instantiation, no multiple instances

  3. Spans a created, only when method foo is called outside of ClassOfFoo.

  4. That means that if method foo calls to method fooInternal, which also declared with @NewSpan annotation in a class ClassOfFoo*, no span will be created for fooInternal.

Could you please clarify that my understanding is correct.
I actually, tested that in a code, but want to make sure that I am not missing anything.

Thanks again!

@Koizumi85

This comment has been minimized.

Show comment
Hide comment
@Koizumi85

Koizumi85 Jun 19, 2017

Hi @zavale.

your understanding is correct, with one single exception. Making a bean of ClassOfFoo not necessarily means, that there can't be multiple instances. There are ways to create beans for every Web-Request or for every Session for example using the scopes "request" or "session". Also with "prototype" scope, there can be any number of instances for a specific bean type. Please refer to the reference documentation of the spring framework (here).

Koizumi85 commented Jun 19, 2017

Hi @zavale.

your understanding is correct, with one single exception. Making a bean of ClassOfFoo not necessarily means, that there can't be multiple instances. There are ways to create beans for every Web-Request or for every Session for example using the scopes "request" or "session". Also with "prototype" scope, there can be any number of instances for a specific bean type. Please refer to the reference documentation of the spring framework (here).

@marcingrzejszczak

This comment has been minimized.

Show comment
Hide comment
@marcingrzejszczak

marcingrzejszczak Jun 19, 2017

Contributor

@Koizumi85 speaks the truth :) case closed :D

Contributor

marcingrzejszczak commented Jun 19, 2017

@Koizumi85 speaks the truth :) case closed :D

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale Jun 19, 2017

@marcingrzejszczak @Koizumi85 Thanks for the help.
Do you have any roadmap for making @NewSpan more generic?

I think that the limitation of "no spans generated" when methods of the same class call each other significantly reduces the usability.

zavale commented Jun 19, 2017

@marcingrzejszczak @Koizumi85 Thanks for the help.
Do you have any roadmap for making @NewSpan more generic?

I think that the limitation of "no spans generated" when methods of the same class call each other significantly reduces the usability.

@marcingrzejszczak

This comment has been minimized.

Show comment
Hide comment
@marcingrzejszczak

marcingrzejszczak Jun 19, 2017

Contributor

It's not the limitation of Sleuth - it's how proxies work in Spring. You can file an issue in Spring if you want to change this approach.

As for the usability, I completely don't agree but I guess it's a matter of preference discussion.

Contributor

marcingrzejszczak commented Jun 19, 2017

It's not the limitation of Sleuth - it's how proxies work in Spring. You can file an issue in Spring if you want to change this approach.

As for the usability, I completely don't agree but I guess it's a matter of preference discussion.

@Koizumi85

This comment has been minimized.

Show comment
Hide comment
@Koizumi85

Koizumi85 Jun 19, 2017

@zavale
I have to agree to everything @marcingrzejszczak said. This is the way EVERY annotation in spring works (@Cacheable, @Transactional, @Async, ...)

Also I have to say, that I am wondering how you are using Sleuth, if this behaviour is such a great limitation to you. Sleuth is about tracing distributed systems. So you would create spans if you leave/enter a specific system. For example if you call another microservice, a database or a third-party service. And usually for such calls, you would have a class only doing this specific stuff.
So if this limitation is making you trouble, you probably should rethink your architecture. Possibly your classes are doing to much stuff.

Koizumi85 commented Jun 19, 2017

@zavale
I have to agree to everything @marcingrzejszczak said. This is the way EVERY annotation in spring works (@Cacheable, @Transactional, @Async, ...)

Also I have to say, that I am wondering how you are using Sleuth, if this behaviour is such a great limitation to you. Sleuth is about tracing distributed systems. So you would create spans if you leave/enter a specific system. For example if you call another microservice, a database or a third-party service. And usually for such calls, you would have a class only doing this specific stuff.
So if this limitation is making you trouble, you probably should rethink your architecture. Possibly your classes are doing to much stuff.

@zavale

This comment has been minimized.

Show comment
Hide comment
@zavale

zavale commented Jun 19, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment