census-instrumentation / opencensus-service

OpenCensus service allows OpenCensus libraries to export to an exporter service rather than having to link vendor-specific exports.
Apache License 2.0
153 stars 63 forks source link

cmd/agent: opencensus receiver w/ jaeger|zipkin exporters no traces #603

Closed DazWilkin closed 2 years ago

DazWilkin commented 5 years ago

I tried routing traces through the Agent to Zipkin. When it didn't (appear) to work, I added Jaeger. Neither appear to work. I think I'm missing something obvious :-(

ocagent.yaml

receivers:
  opencensus:
    address: ":55678"

exporters:
  jaeger:
    collector_endpoint: "jaeger:14268/api/traces"
  prometheus:
    address: ":9100"
  zipkin:
    endpoint: "zipkin:9411/api/v2/spans"

zpages:
    port: 9999

and a subset of docker-compose.yaml:

  opencensus-agent:
    image: omnition/opencensus-agent:0.1.8
    command:
    - --config=/configs/ocagent.yaml
    volumes:
    - "${PWD}/ocagent.yaml:/configs/ocagent.yaml"
    expose:
    - "9100"
    - "9999"
    - "55678"
    ports:
    - 9100:9100
    - 9999:9999

  jaeger:
    image: jaegertracing/all-in-one:1.13
    expose:
    - "14268"
    - "16686"
    ports:
    - 14268:14268
    - 16686:16686

  zipkin:
    image: openzipkin/zipkin
    container_name: zipkin
    expose:
    - "9411"
    ports:
      - 9411:9411

Here's the /tracez for one of the service's exporting to the Agent: image

These traces don't appear to be reflected in the Agent's /tracez. So that's one problem. The Agent is generating its own gRPCs though so I would expect to at least see these:

image

Jaeger is reporting data but it appears to be reporting just traces of its own services: image

Zipkin shows nothing: image

The logs show nothing obvious: Jaeger:

jaeger_1                    | 2019/07/05 23:12:31 maxprocs: Leaving GOMAXPROCS=12: CPU quota undefined
jaeger_1                    | {"level":"info","ts":1562368352.023063,"caller":"flags/service.go:115","msg":"Mounting metrics handler on admin server","route":"/metrics"}
jaeger_1                    | {"level":"info","ts":1562368352.0235035,"caller":"flags/admin.go:108","msg":"Mounting health check on admin server","route":"/"}
jaeger_1                    | {"level":"info","ts":1562368352.0236897,"caller":"flags/admin.go:114","msg":"Starting admin HTTP server","http-port":14269}
jaeger_1                    | {"level":"info","ts":1562368352.0237954,"caller":"flags/admin.go:100","msg":"Admin server started","http-port":14269,"health-status":"unavailable"}
jaeger_1                    | {"level":"info","ts":1562368352.0279665,"caller":"memory/factory.go:55","msg":"Memory storage initialized","configuration":{"MaxTraces":0}}
jaeger_1                    | {"level":"info","ts":1562368352.0336778,"caller":"grpc/builder.go:75","msg":"Agent requested insecure grpc connection to collector(s)"}
jaeger_1                    | {"level":"info","ts":1562368352.0337358,"caller":"grpc/clientconn.go:242","msg":"parsed scheme: \"\"","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.0337782,"caller":"grpc/clientconn.go:248","msg":"scheme \"\" not registered, fallback to default scheme","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.033804,"caller":"grpc/resolver_conn_wrapper.go:113","msg":"ccResolverWrapper: sending update to cc: {[{127.0.0.1:14250 0  <nil>}] }","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.0344827,"caller":"base/balancer.go:76","msg":"base.baseBalancer: got new resolver state: {[{127.0.0.1:14250 0  <nil>}] }","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.034555,"caller":"base/balancer.go:130","msg":"base.baseBalancer: handle SubConn state change: 0xc0003fa1a0, CONNECTING","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.0349255,"caller":"grpc/clientconn.go:1139","msg":"grpc: addrConn.createTransport failed to connect to {127.0.0.1:14250 0  <nil>}. Err :connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:14250: connect: connection refused\". Reconnecting...","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.0349636,"caller":"base/balancer.go:130","msg":"base.baseBalancer: handle SubConn state change: 0xc0003fa1a0, TRANSIENT_FAILURE","system":"grpc","grpc_log":true}
jaeger_1                    | {"level":"info","ts":1562368352.035118,"caller":"all-in-one/main.go:198","msg":"Starting agent"}
jaeger_1                    | {"level":"info","ts":1562368352.03518,"caller":"app/agent.go:68","msg":"Starting jaeger-agent HTTP server","http-port":5778}
jaeger_1                    | {"level":"info","ts":1562368352.0372849,"caller":"all-in-one/main.go:241","msg":"Starting jaeger-collector TChannel server","port":14267}
jaeger_1                    | {"level":"info","ts":1562368352.0373552,"caller":"grpcserver/grpc_server.go:64","msg":"Starting jaeger-collector gRPC server","grpc-port":"14250"}
jaeger_1                    | {"level":"info","ts":1562368352.0374033,"caller":"all-in-one/main.go:259","msg":"Starting jaeger-collector HTTP server","http-port":14268}
jaeger_1                    | {"level":"info","ts":1562368352.0374215,"caller":"querysvc/query_service.go:130","msg":"Archive storage not created","reason":"archive storage not supported"}
jaeger_1                    | {"level":"info","ts":1562368352.0374308,"caller":"all-in-one/main.go:341","msg":"Archive storage not initialized"}
jaeger_1                    | {"level":"info","ts":1562368352.038343,"caller":"healthcheck/handler.go:129","msg":"Health Check state change","status":"ready"}
jaeger_1                    | {"level":"info","ts":1562368352.039242,"caller":"app/server.go:111","msg":"Starting HTTP server","port":16686}
jaeger_1                    | {"level":"info","ts":1562368352.0392437,"caller":"app/server.go:134","msg":"Starting CMUX server","port":16686}
jaeger_1                    | {"level":"info","ts":1562368352.0392504,"caller":"app/server.go:124","msg":"Starting GRPC server","port":16686}

Zipkin:

zipkin                      |                                     ********
zipkin                      |                                   **        **
zipkin                      |                                  *            *
zipkin                      |                                 **            **
zipkin                      |                                 **            **
zipkin                      |                                  **          **
zipkin                      |                                   **        **
zipkin                      |                                     ********
zipkin                      |                                       ****
zipkin                      |                                       ****
zipkin                      |         ****                          ****
zipkin                      |      ******                           ****                                 ***
zipkin                      |   ****************************************************************************
zipkin                      |     *******                           ****                                 ***
zipkin                      |         ****                          ****
zipkin                      |                                        **
zipkin                      |                                        **
zipkin                      | 
zipkin                      | 
zipkin                      |              *****      **     *****     ** **       **     **   **
zipkin                      |                **       **     **  *     ***         **     **** **
zipkin                      |               **        **     *****     ****        **     **  ***
zipkin                      |              ******     **     **        **  **      **     **   **
zipkin                      | 
zipkin                      | :: Powered by Spring Boot ::         (v2.1.6.RELEASE)
zipkin                      | 
zipkin                      | 2019-07-05 22:54:37.535  INFO 1 --- [           main] z.s.ZipkinServer                         : Starting ZipkinServer on a84f447617a0 with PID 1 (/zipkin/BOOT-INF/classes started by root in /zipkin)
zipkin                      | 2019-07-05 22:54:37.539  INFO 1 --- [           main] z.s.ZipkinServer                         : The following profiles are active: shared
zipkin                      | 2019-07-05 22:54:39.104  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.verboseExceptions: false (default)
zipkin                      | 2019-07-05 22:54:39.104  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.verboseSocketExceptions: false (default)
zipkin                      | 2019-07-05 22:54:39.104  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.verboseResponses: false (default)
zipkin                      | 2019-07-05 22:54:39.128  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.useEpoll: true (default)
zipkin                      | 2019-07-05 22:54:39.265  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.useOpenSsl: true (default)
zipkin                      | 2019-07-05 22:54:39.265  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.dumpOpenSslInfo: false (default)
zipkin                      | 2019-07-05 22:54:39.266  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.maxNumConnections: 2147483647 (default)
zipkin                      | 2019-07-05 22:54:39.266  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.numCommonWorkers: 24 (default)
zipkin                      | 2019-07-05 22:54:39.266  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.numCommonBlockingTaskThreads: 200 (default)
zipkin                      | 2019-07-05 22:54:39.267  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultMaxRequestLength: 10485760 (default)
zipkin                      | 2019-07-05 22:54:39.267  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultMaxResponseLength: 10485760 (default)
zipkin                      | 2019-07-05 22:54:39.268  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultRequestTimeoutMillis: 10000 (default)
zipkin                      | 2019-07-05 22:54:39.268  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultResponseTimeoutMillis: 15000 (default)
zipkin                      | 2019-07-05 22:54:39.268  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultConnectTimeoutMillis: 3200 (default)
zipkin                      | 2019-07-05 22:54:39.269  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultWriteTimeoutMillis: 1000 (default)
zipkin                      | 2019-07-05 22:54:39.269  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultServerIdleTimeoutMillis: 15000 (default)
zipkin                      | 2019-07-05 22:54:39.269  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultClientIdleTimeoutMillis: 10000 (default)
zipkin                      | 2019-07-05 22:54:39.269  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp2InitialConnectionWindowSize: 1048576 (default)
zipkin                      | 2019-07-05 22:54:39.270  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp2InitialStreamWindowSize: 1048576 (default)
zipkin                      | 2019-07-05 22:54:39.270  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp2MaxFrameSize: 16384 (default)
zipkin                      | 2019-07-05 22:54:39.270  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp2MaxStreamsPerConnection: 2147483647 (default)
zipkin                      | 2019-07-05 22:54:39.270  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp2MaxHeaderListSize: 8192 (default)
zipkin                      | 2019-07-05 22:54:39.271  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp1MaxInitialLineLength: 4096 (default)
zipkin                      | 2019-07-05 22:54:39.271  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp1MaxHeaderSize: 8192 (default)
zipkin                      | 2019-07-05 22:54:39.271  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultHttp1MaxChunkSize: 8192 (default)
zipkin                      | 2019-07-05 22:54:39.271  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultUseHttp2Preface: true (default)
zipkin                      | 2019-07-05 22:54:39.271  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultUseHttp1Pipelining: false (default)
zipkin                      | 2019-07-05 22:54:39.272  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultBackoffSpec: exponential=200:10000,jitter=0.2 (default)
zipkin                      | 2019-07-05 22:54:39.272  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.defaultMaxTotalAttempts: 10 (default)
zipkin                      | 2019-07-05 22:54:39.272  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.routeCache: maximumSize=4096 (default)
zipkin                      | 2019-07-05 22:54:39.273  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.compositeServiceCache: maximumSize=256 (default)
zipkin                      | 2019-07-05 22:54:39.273  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.parsedPathCache: maximumSize=4096 (default)
zipkin                      | 2019-07-05 22:54:39.273  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.headerValueCache: maximumSize=4096 (default)
zipkin                      | 2019-07-05 22:54:39.273  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.cachedHeaders: :authority,:scheme,:method,accept-encoding,content-type (default)
zipkin                      | 2019-07-05 22:54:39.274  INFO 1 --- [           main] c.l.a.c.Flags                            : com.linecorp.armeria.annotatedServiceExceptionVerbosity: unhandled (default)
zipkin                      | 2019-07-05 22:54:39.275  INFO 1 --- [           main] c.l.a.c.Flags                            : Using /dev/epoll
zipkin                      | 2019-07-05 22:54:39.275  INFO 1 --- [           main] c.l.a.c.Flags                            : Using OpenSSL: BoringSSL, 0x1010007f
zipkin                      | 2019-07-05 22:54:39.523  INFO 1 --- [           main] c.l.a.s.d.DocStringExtractor             : Using com.linecorp.armeria.thrift.jsonDir: META-INF/armeria/thrift
zipkin                      | 2019-07-05 22:54:39.543  INFO 1 --- [           main] c.l.a.c.u.SystemInfo                     : Hostname: a84f447617a0 (from /proc/sys/kernel/hostname)
zipkin                      | 2019-07-05 22:54:39.747  INFO 1 --- [oss-http-*:9411] c.l.a.s.Server                           : Serving HTTP at /0.0.0.0:9411 - http://127.0.0.1:9411/
zipkin                      | 2019-07-05 22:54:39.749  INFO 1 --- [           main] c.l.a.s.ArmeriaAutoConfiguration         : Armeria server started at ports: {/0.0.0.0:9411=ServerPort(/0.0.0.0:9411, [http])}
zipkin                      | 2019-07-05 22:54:39.802  INFO 1 --- [           main] c.d.d.core                               : DataStax Java driver 3.7.1 for Apache Cassandra
zipkin                      | 2019-07-05 22:54:39.808  INFO 1 --- [           main] c.d.d.c.GuavaCompatibility               : Detected Guava >= 19 in the classpath, using modern compatibility layer
zipkin                      | 2019-07-05 22:54:39.999  INFO 1 --- [           main] c.d.d.c.ClockFactory                     : Using native clock to generate timestamps.
zipkin                      | 2019-07-05 22:54:40.139  INFO 1 --- [           main] z.s.ZipkinServer                         : Started ZipkinServer in 3.183 seconds (JVM running for 4.529)
DazWilkin commented 5 years ago

I tried shipping traces to Jaeger directly and also did not appear to receive traces in Jaeger.

So, it's probably not the OpenCensus Agent but my code and|or the Jaeger Exporter.

I'm going to try another configuration.

DazWilkin commented 5 years ago

I was able to ship traces to Jaeger directly using a mash-up of OpenCensus documentation:

This E2E example for tracing with Zipking: https://opencensus.io/quickstart/go/tracing/

With this -- insuffiicient (!?) -- Jaeger example: https://opencensus.io/exporters/supported-exporters/go/jaeger/

I remain unable to export traces using ocgrpc. Evidently it's something I'm not doing but it remains unclear to me what I'm doing incorrectly and why this doesn't work.

Note 1

One additional "Aha!" is that the Jaeger configuration is inconsistent and must be configured as such. Evidently the protocol (http) is required for the collector but not the agent:

agentEndpointURI := "localhost:6831"
collectorEndpointURI := "http://localhost:14268/api/traces"

Note 2

Curiously, the Agent's configuration for Jaeger uses only the collectorEndpointURI so -- if the Jaeger Agent endpoint (6831) is required by the Jaeger Exporter it's unclear how this works when its used by the OpenCensus Agent:

https://github.com/census-instrumentation/opencensus-service#exporters

  jaeger:
    collector_endpoint: "http://127.0.0.1:14268/api/traces"
flands commented 5 years ago

@DazWilkin nice find -- yes the agent/collector configuration is known to be inconsistent. This will be addressed in the OpenTelemetry Service.

ChrisCoe commented 5 years ago

@DazWilkin I ran into the same problem when I tried using the agent to send to jaeger . @flands If this is not going to be addressed in OpenCensus Service, is there a work around?

I get a similar error here where my traces don't send, but instead some internal agent traces are generated. I am running the example/main.go

I am trying to incorporate an exporter I created for Azure Monitor to be used in the OpenCensus agent for my internship project. I don't think the error is comming from my exporter code.

Result on Azure Monitor: image

What my exporter is exporting on ExportSpan, but they don't all apear on Azure Monitor image

pjanotti commented 5 years ago

@ChrisCoe these spans that you see seem like the ones generated for z-pages by gRPC. The issue mentioned above is a inconsistency for the Jaeger exporter if it applies to your exporter is not clear. Perhaps if you can share your code we can take a look to see if that is the case or not.

ChrisCoe commented 5 years ago

@pjanotti Sorry for the late reply, and thank you for your offer. I was able to find my error to eliminate these extra spans. I accidentally registered my custom exporter right after creating it when the OC agent exporter already registered it. By having only the OC agent register, I eliminated this problem.

SergeyKanzhelev commented 5 years ago

@ChrisCoe I know it's a very old issue. Curious, did you manage to make Azure exporter work? Do you plan to merge it?

dashpole commented 2 years ago

This repository is now archived, and is succeeded by https://github.com/open-telemetry/opentelemetry-collector.