search

openzipkin / zipkin-gcp

Reporters and collectors for use in Google Cloud Platform
https://cloud.google.com/trace/docs/zipkin
Apache License 2.0
91 stars 54 forks source link

widen logging scope to zipkin2 #147

Closed codefromthecrypt closed 5 years ago

codefromthecrypt commented 5 years ago

We had a troubleshooting session on https://gitter.im/openzipkin/zipkin with @z-oo

basically unless you put the log level wider, you can't see any errors caused by translation bugs. Ex.

this:

curl -X POST -s localhost:9411/api/v2/spans -H'Content-Type: application/json' -d '[{"traceId":"fe1583ed5be1b96cf40538f958ca97a6","id":"96169d26c53f25ab","name":"loader::unload","timestamp":1568360755828060,"duration":124,"localEndpoint":{"ipv6":"::1"}}]'

causes an exception, but you'd not see the exception if you only looked at the translation logger.

2019-09-13 08:05:45.086 DEBUG 1 --- [cking-tasks-1-1] z.t.s.SpanTranslator                     : >> translating zipkin span: {"traceId":"fe1583ed5be1b96cf40538f958ca97a6","id":"96169d26c53f25ab","name":"loader::unload","timestamp":1568360755828060,"duration":124,"localEndpoint":{"ipv6":"::1"}}
2019-09-13 08:05:45.095 DEBUG 1 --- [cking-tasks-1-1] z.s.i.ZipkinHttpCollector                : Cannot store spans [fe1583ed5be1b96cf40538f958ca97a6/96169d26c53f25ab] due to NullPointerException()

java.lang.NullPointerException: null
    at zipkin2.translation.stackdriver.AttributesExtractor.extract(AttributesExtractor.java:83) ~[zipkin-translation-stackdriver-0.14.1-SNAPSHOT.jar!/:?]
    at zipkin2.translation.stackdriver.SpanTranslator.translate(SpanTranslator.java:112) ~[zipkin-translation-stackdriver-0.14.1-SNAPSHOT.jar!/:?]
    at zipkin2.translation.stackdriver.SpanTranslator.translate(SpanTranslator.java:60) ~[zipkin-translation-stackdriver-0.14.1-SNAPSHOT.jar!/:?]
    at zipkin2.storage.stackdriver.StackdriverSpanConsumer.accept(StackdriverSpanConsumer.java:51) ~[zipkin-storage-stackdriver-0.14.1-SNAPSHOT.jar!/:?]
    at zipkin2.collector.Collector.store(Collector.java:200) ~[zipkin-collector-2.16.3-SNAPSHOT.jar!/:?]
    at zipkin2.collector.Collector$StoreSpans.run(Collector.java:229) ~[zipkin-collector-2.16.3-SNAPSHOT.jar!/:?]
    at com.linecorp.armeria.common.AbstractRequestContext.lambda$makeContextAware$1(AbstractRequestContext.java:69) ~[armeria-0.91.0.jar!/:?]
    at com.linecorp.armeria.common.AbstractRequestContext.lambda$makeContextAware$1(AbstractRequestContext.java:69) ~[armeria-0.91.0.jar!/:?]
    at io.micrometer.core.instrument.AbstractTimer.record(AbstractTimer.java:160) ~[micrometer-core-1.2.1.jar!/:1.2.1]
    at io.micrometer.core.instrument.Timer.lambda$wrap$0(Timer.java:144) ~[micrometer-core-1.2.1.jar!/:1.2.1]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.39.Final.jar!/:4.1.39.Final]
    at java.lang.Thread.run(Thread.java:834) [?:?]