2021-09-02 SpringOne - Tracing Issues in Your Application

Transcript

1. Marcin Grzejszczak, Jonatán Ivanov Spring One 2021 Tracing Issues in Your Application Copyright © 2021 VMware, Inc. or its affiliates.
2. About Us Marcin Grzejszczak 󰐤 Spring Cloud @ VMware Twitter: @mgrzejszczak Blog: toomuchcoding.com Observability Spring Cloud Sleuth (Distributed Tracing) Spring Observability 😉 Contract Testing Spring Cloud Contract Jonatán Ivanov 󰏘 Spring Cloud @ VMware Twitter: @jonatan_ivanov Blog: develotters.com Observability Spring Cloud Sleuth (Distributed Tracing) Spring Observability 😉 Micrometer (Metrics)
3. Disclaimer This presentation may contain product features or functionality that are currently under development. This overview of new technology represents no commitment from VMware to deliver these features in any generally available product. Features are subject to change, and must not be included in contracts, purchase orders, or sales agreements of any kind. Technical feasibility and market demand will affect final delivery. Pricing and packaging for any new features/functionality/technology discussed or presented, have not been determined. The information in this presentation is for informational purposes only and may not be incorporated into any contract. There is no commitment or obligation to deliver any items presented herein.
4. Meet Joe Joe is a demanding internet user Joe wanted to search for memes
5. Meet Jane Jane is a programmer She’s been developing the meme generation system
6. Joe wanted to search for interesting memes. At first, things went smoothly...
7. Great result Joe was happy to be able to find an interesting meme https://www.rd.com/list/dog-memes/
8. Did you just say that you ssh’ed to a production machine?
9. His happiness didn’t last long. Eventually Joe saw this...
10. 500 response code Memes failed to generate due to server error
11. Joe was unhappy Joe decided to file a ticket to the meme generation system
12. Jane’s investigating She’s looking at the stack trace. Jane wants to know the truth about what happened
13. 2021-02-10 13:57:55.239 ERROR 274441 --- [nio-8082-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.IllegalStateException: Meme overflow occurred] with root cause java.lang.IllegalStateException: Meme overflow occurred at io.memegenerator.MemeController.generateMeme(Application.java:93) at io.memegenerator.MemeController$$FastClassBySpringCGLIB$$d54a9db6.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) at io.memegenerator.MemeController$$EnhancerBySpringCGLIB$$e33f7fa1.memeOverflow(<generated>) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1061) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:961) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
14. That wasn’t too helpful. Jane wanted to know what Joe did that lead to the error...
19. Death Star Architecture / Big Ball of Mud
20. Production observability Jane sees that there is no proper feedback from production Logs are missing critical information We’re lacking production observability!
21. What if the apps collect and publish metrics? Is there a way to correlate logs?
22. Jane wants to address the metrics problem
23. Metrics Store
24. What are metrics good for?
25. What about the log correlation?
26. TraceId: 123 2021-02-10 13:57:55.239 … HELLO FROM SERVICE1 123 123 2021-02-10 13:58:10.239 … HELLO FROM SERVICE2 123 123 123 2021-02-10 13:58:20.239 … HELLO FROM SERVICE4 123 2021-02-10 13:58:30.239 … HELLO FROM SERVICE3 123
28. Logs Store
30. Jane’s done! The problem was solved thanks to log correlation! Time to start the weekend...
31. Let’s get back to Joe. Joe wanted to generate a new meme...
32. Some meme about cats
34. Joe was sad again The system is slow Another ticket is filed
35. Another issue... Jane sees that Joe filed another issue The description could be better… Jane knows that the logs are correlated - for sure they will help!
36. [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:05.239 INFO 274441 --- [nio-8082-exec-1] This line shouldn’t be called [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:15.239 INFO 274441 --- [nio-8082-exec-1] Logging sth [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:25.239 INFO 274441 --- [nio-8082-exec-1] Logging moar [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:35.239 INFO 274441 --- [nio-8082-exec-1] This should work [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:45.239 INFO 274441 --- [nio-8082-exec-1] Sending a request [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:55.239 INFO 274441 --- [nio-8082-exec-1] Returning response Sending what request? Getting what response? Did it take 10 seconds?
37. [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:05.239 INFO 274441 --- [nio-8082-exec-1] This line shouldn’t be called [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:15.239 INFO 274441 --- [nio-8082-exec-1] Logging sth [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:25.239 INFO 274441 --- [nio-8082-exec-1] Logging moar [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:35.239 INFO 274441 --- [nio-8082-exec-1] This should work [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:45.239 INFO 274441 --- [nio-8082-exec-1] Sending a request - start [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:47.239 INFO 274441 --- [nio-8082-exec-1] Sending a request - stop [took 2 seconds] [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:55.239 INFO 274441 --- [nio-8082-exec-1] Returning response Change the logs? Add start? Add stop?
38. That’s a lot of work... Jane sees that modifying all logs will take a lot of time There must be a better way to solve this problem
39. Service 1 Service 3 Service 4 Application Controller Application Service Service 2
40. Service 1 Service 3 Service 4 Application Controller Application Service Service 2 Operation Operation? Operation Operation
41. Service 1 Service 3 Service 4 Application Controller Application Service Service 2 Span Span Span
42. [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:05.239 INFO 274441 --- [nio-8082-exec-1] This line shouldn’t be called [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:15.239 INFO 274441 --- [nio-8082-exec-1] Logging sth [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:25.239 INFO 274441 --- [nio-8082-exec-1] Logging moar [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:35.239 INFO 274441 --- [nio-8082-exec-1] This should work [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:45.239 INFO 274441 --- [nio-8082-exec-1] Sending a request [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:45.239 INFO 274441 --- [nio-8082-exec-1] [FRAMEWORK] SpanId [123] Start [xx] Stop [yy] [6dad9c7bd47f0e21c946a7a57d75e7c8] 2021-02-10 13:58:55.239 INFO 274441 --- [nio-8082-exec-1] Returning response
43. Span Store
44. Span Whole trace Production dependency graph
45. What are the options? Jane wants to know what distributed tracing options are out there? She has a polyglot environment - does it work for any language / framework? What are the latency visualization tools?
46. Standards OpenZipkin OpenTracing OpenCensus OpenTelemetry
47. Standards OpenZipkin OpenTelemetry
48. OpenZipkin Mature, production tested, multi language support Zipkin 14k stars on GitHub, first release 05.2016 Brave 2k stars on GitHub, first release 04.2013 Supported languages: C#, Go, Java, JavaScript, Ruby, Scala, PHP (many other are community driven)
49. OpenTelemetry (OTel) New, multi language, CNCF oriented OpenTelemetry Java ~900 stars on GitHub, first release 11.2019 OpenTelemetry Spec 1.9k stars on GitHub, first release 06.2019 First GA releases at the end of 2020 and beginning of 2021 OTel wants to address logs, tracing & metrics problems Supported languages: Java, C#, Go, JavaScript, Python, Rust, C++, Erlang/Elixir
50. Latency Visualization Tools VMware Tanzu Observability by Wavefront *Free Tanzu Observability for your Spring Boot applications - no sign-up needed
51. Latency Visualization Tools OpenZipkin Jaeger
52. Latency Visualization Tools APM vendors
53. What about Java & Spring? Jane wants to know if she can use distributed tracing with Java & Spring?
54. Spring Cloud Sleuth
55. Spring Cloud Sleuth Distributed tracing support for Spring Boot applications First release 10.2015 Version 2.x works directly with OpenZipkin Brave’s API Version 3.x bridges from Sleuth API to tracer APIs Plug in the library, configure it, you’re done!
56. Spring Cloud Sleuth - how does it work? Sleuth Instrumentation JAVA PROCESS Sleuth API HTTP Messaging Batch ... Span Store OpenZipkin Brave (out of the box support) OpenTelemetry (incubating) API BRIDGES OpenZipkin, Tanzu Observability (out of the box support) Custom (via OZ Brave / OTel bridges / configuration) REPORTER BRIDGES
57. What about Java & Spring? Jane wants to know if she can collect metrics with Java & Spring?
58. Micrometer
59. Micrometer Vendor-neutral application metrics facade First release 02.2018 Popular Metrics library on the JVM Like SLF4J, but for metrics - simple API (facade/abstraction) Supports the most popular metric backends (no vendor lock-in) Comes with Spring Boot Actuator Spring projects are instrumented using Micrometer Lots of third-party libraries use Micrometer to instrument their code
60. Supports the most popular metric backends AppOptics Atlas Azure Monitor CloudWatch (AWS) Datadog Dynatrace Elastic OpenTSDB Prometheus SignalFx Stackdriver (GCP) StatsD Wavefront* (VMware) (/actuator/metrics) Ganglia Graphite Humio InfluxDB JMX KairosDB New Relic *VMware Tanzu Observability by Wavefront
61. Jane wonders if there’s a Spring-native way of doing observability
62. Spring Observability
63. Spring Observability Spring-native approach to Observability Part of Spring Framework Core Recorder API Instrument once - get metrics and tracing Highly extensible - register additional listeners Tracing abstraction Like Spring Cloud Sleuth but without Spring Cloud Instrumentation happens in dedicated projects
64. Spring Observability - how does it work? JAVA PROCESS Span Store Tracing Listener Metrics Listener RECORDING LISTENERS HTTP Spring Web Instrumentation Tracing API Tracer Implementation Micrometer API MeterRegistry Metrics Store Spring Observability Recorder API
65. IntervalRecording recording = recorder .recordingFor((IntervalEvent) () -> "important-calculation") .tag(Tag.of("calculation-type", "tax", Cardinality.LOW)) .tag(Tag.of("user-id", userId, Cardinality.HIGH)) .start(); try { calculationService.calculate(); } catch (Exception exception) { recording.error(exception); throw exception; } finally { recording.stop(); }
66. IntervalRecording recording = recorder .recordingFor((IntervalEvent) () -> "important-calculation") .tag(Tag.of("calculation-type", "tax", Cardinality.LOW)) .tag(Tag.of("user-id", userId, Cardinality.HIGH)) .start(); try { calculationService.calculate(); } catch (Exception exception) { recording.error(exception); throw exception; } finally { recording.stop(); }
67. IntervalRecording recording = recorder .recordingFor((IntervalEvent) () -> "important-calculation") .tag(Tag.of("calculation-type", "tax", Cardinality.LOW)) .tag(Tag.of("user-id", userId, Cardinality.HIGH)) .start(); try { calculationService.calculate(); } catch (Exception exception) { recording.error(exception); throw exception; } finally { recording.stop(); }
68. IntervalRecording recording = recorder .recordingFor((IntervalEvent) () -> "important-calculation") .tag(Tag.of("calculation-type", "tax", Cardinality.LOW)) .tag(Tag.of("user-id", userId, Cardinality.HIGH)) .start(); try { calculationService.calculate(); } catch (Exception exception) { recording.error(exception); throw exception; } finally { recording.stop(); }
69. Jane wanted to see Spring Observability with Tanzu Observability & log correlation in action!
70. presentation-service
71. DEMO (Thanks to the Tanzu Observability Team for the help!)
72. Questions/Feedback? Contact us on Twitter @mgrzejszczak - toomuchcoding.com @jonatan_ivanov - develotters.com © 2020 Spring. A VMware-backed project.