search

openzipkin-attic / docker-zipkin

Docker images for OpenZipkin
Apache License 2.0
687 stars 329 forks source link

Unable to process traces using kafka-zookeeper #190

Closed pranav-patil closed 6 years ago

pranav-patil commented 6 years ago

I am trying to configure Zipkin with Kafka and activate the Kafka 0.8 collector. I modified the KAFKA_ADVERTISED_HOST_NAME property in docker-compose-kafka08.yml to first kafka-zookeeper, then 127.0.0.1 and at last tried IP address of remote docker machine. I also updated the /etc/hosts file with 127.0.0.1 localhost kafka-zookeeper. But everytime I send Zipkin traces to Spring cloud application, I am getting below error KeeperExceptions from kafka-zookeeper. The spring cloud application which uses spring-cloud-starter-zipkin and spring-kafka to send trace messages resides on my local machine while zipkin instance is on remote machine. I use the below command from documentation to setup zipkin docker instances.

docker-compose -f docker-compose.yml -f docker-compose-kafka08.yml up

zipkin             | 2018-10-28 18:17:23.273  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], Cleared the data chunks in all the consumer message iterators
zipkin             | 2018-10-28 18:17:23.273  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], Committing all offsets after clearing the fetcher queues
zipkin             | 2018-10-28 18:17:23.273  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], Releasing partition ownership
zipkin             | 2018-10-28 18:17:23.324  INFO 1 --- [atcher_executor] k.c.RangeAssignor                        : Consumer zipkin_ad6c628d7445-1540750562130-185bd16d rebalancing the following partitions: ArrayBuffer(0) for topic zipkin with consumers: List(zipkin_ad6c628d7445-1540750562130-185bd16d-0)
zipkin             | 2018-10-28 18:17:23.330  INFO 1 --- [atcher_executor] k.c.RangeAssignor                        : zipkin_ad6c628d7445-1540750562130-185bd16d-0 attempting to claim partition 0
kafka-zookeeper    | 2018-10-28 18:17:23,470 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c1bfca380001 type:create cxid:0x20 zxid:0x2b txntype:-1 reqpath:n/a Error Path:/consumers/zipkin/owners/zipkin Error:KeeperErrorCode = NoNode for /consumers/zipkin/owners/zipkin
kafka-zookeeper    | 2018-10-28 18:17:23,495 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c1bfca380001 type:create cxid:0x21 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/consumers/zipkin/owners Error:KeeperErrorCode = NoNode for /consumers/zipkin/owners
zipkin             | 2018-10-28 18:17:23.588  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], zipkin_ad6c628d7445-1540750562130-185bd16d-0 successfully owned partition 0 for topic zipkin
zipkin             | 2018-10-28 18:17:23.643  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], Consumer zipkin_ad6c628d7445-1540750562130-185bd16d selected partitions : zipkin:0: fetched offset = -1: consumed offset = -1
zipkin             | 2018-10-28 18:17:23.647  INFO 1 --- [atcher_executor] k.c.ZookeeperConsumerConnector           : [zipkin_ad6c628d7445-1540750562130-185bd16d], end rebalancing consumer zipkin_ad6c628d7445-1540750562130-185bd16d try #0
zipkin             | 2018-10-28 18:17:23.659  INFO 1 --- [r-finder-thread] onsumerFetcherManager$LeaderFinderThread : [zipkin_ad6c628d7445-1540750562130-185bd16d-leader-finder-thread], Starting
zipkin             | 2018-10-28 18:17:23.773  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Verifying properties
zipkin             | 2018-10-28 18:17:23.773  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property client.id is overridden to zipkin
zipkin             | 2018-10-28 18:17:23.774  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property metadata.broker.list is overridden to 2a4c2fbb2406:9092
zipkin             | 2018-10-28 18:17:23.774  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property request.timeout.ms is overridden to 30000
zipkin             | 2018-10-28 18:17:23.852  INFO 1 --- [r-finder-thread] k.c.ClientUtils$                         : Fetching metadata from broker id:0,host:2a4c2fbb2406,port:9092 with correlation id 0 for 1 topic(s) Set(zipkin)
zipkin             | 2018-10-28 18:17:23.860  INFO 1 --- [r-finder-thread] k.p.SyncProducer                         : Connected to 2a4c2fbb2406:9092 for producing
zipkin             | 2018-10-28 18:17:23.926  INFO 1 --- [r-finder-thread] k.p.SyncProducer                         : Disconnecting from 2a4c2fbb2406:9092
zipkin             | 2018-10-28 18:17:23.941  INFO 1 --- [r-finder-thread] k.c.ConsumerFetcherManager               : [ConsumerFetcherManager-1540750562457] Added fetcher for partitions ArrayBuffer()
zipkin             | 2018-10-28 18:17:24.195  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Verifying properties
zipkin             | 2018-10-28 18:17:24.207  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property client.id is overridden to zipkin
zipkin             | 2018-10-28 18:17:24.207  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property metadata.broker.list is overridden to 2a4c2fbb2406:9092
zipkin             | 2018-10-28 18:17:24.207  INFO 1 --- [r-finder-thread] k.u.VerifiableProperties                 : Property request.timeout.ms is overridden to 30000
zipkin             | 2018-10-28 18:17:24.208  INFO 1 --- [r-finder-thread] k.c.ClientUtils$                         : Fetching metadata from broker id:0,host:2a4c2fbb2406,port:9092 with correlation id 1 for 1 topic(s) Set(zipkin)
zipkin             | 2018-10-28 18:17:24.210  INFO 1 --- [r-finder-thread] k.p.SyncProducer                         : Connected to 2a4c2fbb2406:9092 for producing
zipkin             | 2018-10-28 18:17:24.242  INFO 1 --- [r-finder-thread] k.p.SyncProducer                         : Disconnecting from 2a4c2fbb2406:9092
zipkin             | 2018-10-28 18:17:24.278  INFO 1 --- [30-185bd16d-0-0] k.c.ConsumerFetcherThread                : [ConsumerFetcherThread-zipkin_ad6c628d7445-1540750562130-185bd16d-0-0], Starting
zipkin             | 2018-10-28 18:17:24.359  INFO 1 --- [r-finder-thread] k.c.ConsumerFetcherManager               : [ConsumerFetcherManager-1540750562457] Added fetcher for partitions ArrayBuffer([[zipkin,0], initOffset -1 to broker id:0,host:2a4c2fbb2406,port:9092] )
zipkin             | 2018-10-28 18:17:57.091  INFO 1 --- [  XNIO-1 task-1] i.u.servlet                              : Initializing Spring FrameworkServlet 'dispatcherServlet'
zipkin             | 2018-10-28 18:17:57.091  INFO 1 --- [  XNIO-1 task-1] o.s.w.s.DispatcherServlet                : FrameworkServlet 'dispatcherServlet': initialization started
zipkin             | 2018-10-28 18:17:57.189  INFO 1 --- [  XNIO-1 task-1] o.s.w.s.DispatcherServlet                : FrameworkServlet 'dispatcherServlet': initialization completed in 97 ms
zipkin             | 2018-10-28 18:17:59.695  INFO 1 --- [  XNIO-1 task-4] c.z.h.HikariDataSource                   : HikariPool-1 - Starting...
zipkin             | 2018-10-28 18:18:00.316  INFO 1 --- [  XNIO-1 task-4] c.z.h.HikariDataSource                   : HikariPool-1 - Start completed.
kafka-zookeeper    | 2018-10-28 18:18:02,730 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c1bfca380001 type:setData cxid:0x29 zxid:0x30 txntype:-1 reqpath:n/a Error Path:/consumers/zipkin/offsets/zipkin/0 Error:KeeperErrorCode = NoNode for /consumers/zipkin/offsets/zipkin/0
kafka-zookeeper    | 2018-10-28 18:18:02,803 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c1bfca380001 type:create cxid:0x2a zxid:0x31 txntype:-1 reqpath:n/a Error Path:/consumers/zipkin/offsets Error:KeeperErrorCode = NoNode for /consumers/zipkin/offsets
codefromthecrypt commented 6 years ago

are you intentionally using an old kafka setup? did you try https://github.com/openzipkin/docker-zipkin/blob/master/docker-compose-kafka.yml

please use https://gitter.im/openzipkin/zipkin for troubleshooting, but before please look at this first: https://cwiki.apache.org/confluence/display/ZIPKIN/Kafka

codefromthecrypt commented 6 years ago

PS I just clarified the README to not suggest kafka 0.8. It simplifies the instructions and redundantly mentions most demo apps will be running alongside the docker container (not inside it), so should use bootstrap servers localhost:19092 (Ex spring.kafka.bootstrap-servers=localhost:19092 in sleuth)

pranav-patil commented 6 years ago

Thank you @adriancole for your quick response and updating the documentation. I am still facing issues as unable to see any traces in zipkin-ui and getting KeeperException in kafka-zookeeper logs. Below is my application.yml configuration for test application. As you recommended I tried changing the spring.kafka.bootstrap-servers property to remote-docker-machine-ip-address:19092 (localhost will not work for me as my docker machine with kafka is remote machine), but then I get 'Connection to node -1 could not be established. Broker may not be available' error in application log. Only below remote-docker-machine-ip-address with port 9092 seems to work with no connection errors.

spring:
  application:
    name: testzipkin
  zipkin:
    baseUrl: http://remote-docker-machine-ip-address:9411/
    sender:
      type: kafka
  sleuth:
    sampler:
      probability: 1.0
  kafka:
    bootstrap-servers: remote-docker-machine-ip-address:9092

Below is my docker-compose-kafka.yml configuration. As mentioned in the docker-compose-kafka.yml file comments starting with If using docker machine, I have uncommented the environment variable KAFKA_ADVERTISED_HOST_NAME and tried specifying it as 127.0.0.1, also tried kafka-zookeeper and at last IP address of the remote docker machine. I also tried commenting KAFKA_ADVERTISED_HOST_NAME still no traces are processed/consumed by kafka.

services:
  kafka-zookeeper:
    image: openzipkin/zipkin-kafka
    container_name: kafka-zookeeper
    # If using docker machine, uncomment the below and set your bootstrap
    # server list to 192.168.99.100:19092
    environment:
      - KAFKA_ADVERTISED_HOST_NAME=127.0.0.1
    ports:
      - 2181:2181
      - 9092:9092
      - 19092:19092

  zipkin:
    environment:
      - KAFKA_BOOTSTRAP_SERVERS=kafka-zookeeper:9092
    depends_on:
      - kafka-zookeeper

I am starting the zookeeper-kafka instance using below docker-compose command: docker-compose -f docker-compose.yml -f docker-compose-kafka.yml up

Below are the log errors in kafka-zookeeper:

2018-10-29T17:20:12.295398318Z 2018-10-29 17:20:12,294 [myid:] - INFO  [SyncThread:0:FileTxnLog@213] - Creating new log file: log.1
2018-10-29T17:20:12.378076047Z 2018-10-29 17:20:12,377 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@694] - Established session 0x100c6b35df90000 with negotiated timeout 6000 for client /127.0.0.1:35246
2018-10-29T17:20:12.781955229Z 2018-10-29 17:20:12,781 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x2 zxid:0x3 txntype:-1 reqpath:n/a Error Path:/brokers Error:KeeperErrorCode = NoNode for /brokers
2018-10-29T17:20:12.855424594Z 2018-10-29 17:20:12,854 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x6 zxid:0x7 txntype:-1 reqpath:n/a Error Path:/config Error:KeeperErrorCode = NoNode for /config
2018-10-29T17:20:12.890483253Z 2018-10-29 17:20:12,889 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x9 zxid:0xa txntype:-1 reqpath:n/a Error Path:/admin Error:KeeperErrorCode = NoNode for /admin
2018-10-29T17:20:13.887117516Z 2018-10-29 17:20:13,886 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x15 zxid:0x15 txntype:-1 reqpath:n/a Error Path:/cluster Error:KeeperErrorCode = NoNode for /cluster
2018-10-29T17:20:13.994780464Z [2018-10-29 17:20:13,992] WARN No meta.properties file under dir /kafka/logs/meta.properties (kafka.server.BrokerMetadataCheckpoint)
2018-10-29T17:20:17.717775563Z [2018-10-29 17:20:17,717] WARN No meta.properties file under dir /kafka/logs/meta.properties (kafka.server.BrokerMetadataCheckpoint)
2018-10-29T17:20:18.315922649Z 2018-10-29 17:20:18,315 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x21 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/controller_epoch Error:KeeperErrorCode = NoNode for /controller_epoch
2018-10-29T17:20:19.819232539Z 2018-10-29 17:20:19,818 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:delete cxid:0x34 zxid:0x1d txntype:-1 reqpath:n/a Error Path:/admin/reassign_partitions Error:KeeperErrorCode = NoNode for /admin/reassign_partitions
2018-10-29T17:20:19.886488141Z 2018-10-29 17:20:19,885 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:delete cxid:0x39 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/admin/preferred_replica_election Error:KeeperErrorCode = NoNode for /admin/preferred_replica_election
2018-10-29T17:20:33.391205454Z 2018-10-29 17:20:33,389 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x41 zxid:0x1f txntype:-1 reqpath:n/a Error Path:/config/topics/zipkin Error:KeeperErrorCode = NoNode for /config/topics/zipkin
2018-10-29T17:20:33.550588839Z 2018-10-29 17:20:33,550 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x4a zxid:0x22 txntype:-1 reqpath:n/a Error Path:/config/topics/__consumer_offsets Error:KeeperErrorCode = NoNode for /config/topics/__consumer_offsets

Please let me know if there are any corrections with my above configuration.

codefromthecrypt commented 6 years ago

you might have missed the request to use gitter for troubleshooting. we dont use issues for this purpose. please join and we can try to help there

On Tue, 30 Oct 2018, 03:19 Pranav Patil, notifications@github.com wrote:

Thank you @adriancole https://github.com/adriancole for your quick response and updating the documentation. I am still facing issues as unable to see any traces in zipkin-ui and getting KeeperException in kafka-zookeeper logs. Below is my application.yml configuration for test application. As you recommended I tried changing the spring.kafka.bootstrap-servers property to remote-docker-machine-ip-address:19092 (localhost will not work for me as my docker machine with kafka is remote machine), but then I get 'Connection to node -1 could not be established. Broker may not be available' error in application log. Only below remote-docker-machine-ip-address with port 9092 seems to work with no connection errors.

spring: application: name: testzipkin zipkin: baseUrl: http://remote-docker-machine-ip-address:9411/ sender: type: kafka sleuth: sampler: probability: 1.0 kafka: bootstrap-servers: remote-docker-machine-ip-address:9092

Below is my docker-compose-kafka.yml configuration. As mentioned in the docker-compose-kafka.yml https://github.com/openzipkin/docker-zipkin/blob/master/docker-compose-kafka.yml file comments starting with If using docker machine, I have uncommented the environment variable KAFKA_ADVERTISED_HOST_NAME and tried specifying it as 127.0.0.1, also tried kafka-zookeeper and at last IP address of the remote docker machine. I also tried commenting KAFKA_ADVERTISED_HOST_NAME still no traces are processed/consumed by kafka.

services: kafka-zookeeper: image: openzipkin/zipkin-kafka container_name: kafka-zookeeper

If using docker machine, uncomment the below and set your bootstrap

# server list to 192.168.99.100:19092
environment:
  - KAFKA_ADVERTISED_HOST_NAME=127.0.0.1
ports:
  - 2181:2181
  - 9092:9092
  - 19092:19092

zipkin: environment:

  • KAFKA_BOOTSTRAP_SERVERS=kafka-zookeeper:9092 depends_on:
  • kafka-zookeeper

I am starting the zookeeper-kafka instance using below docker-compose command: docker-compose -f docker-compose.yml -f docker-compose-kafka.yml up

Below are the log errors in kafka-zookeeper:

2018-10-29T17:20:12.295398318Z 2018-10-29 17:20:12,294 [myid:] - INFO [SyncThread:0:FileTxnLog@213] - Creating new log file: log.1 2018-10-29T17:20:12.378076047Z 2018-10-29 17:20:12,377 [myid:] - INFO [SyncThread:0:ZooKeeperServer@694] - Established session 0x100c6b35df90000 with negotiated timeout 6000 for client /127.0.0.1:35246 2018-10-29T17:20:12.781955229Z 2018-10-29 17:20:12,781 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x2 zxid:0x3 txntype:-1 reqpath:n/a Error Path:/brokers Error:KeeperErrorCode = NoNode for /brokers 2018-10-29T17:20:12.855424594Z 2018-10-29 17:20:12,854 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x6 zxid:0x7 txntype:-1 reqpath:n/a Error Path:/config Error:KeeperErrorCode = NoNode for /config 2018-10-29T17:20:12.890483253Z 2018-10-29 17:20:12,889 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x9 zxid:0xa txntype:-1 reqpath:n/a Error Path:/admin Error:KeeperErrorCode = NoNode for /admin 2018-10-29T17:20:13.887117516Z 2018-10-29 17:20:13,886 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:create cxid:0x15 zxid:0x15 txntype:-1 reqpath:n/a Error Path:/cluster Error:KeeperErrorCode = NoNode for /cluster 2018-10-29T17:20:13.994780464Z [2018-10-29 17:20:13,992] WARN No meta.properties file under dir /kafka/logs/meta.properties (kafka.server.BrokerMetadataCheckpoint) 2018-10-29T17:20:17.717775563Z [2018-10-29 17:20:17,717] WARN No meta.properties file under dir /kafka/logs/meta.properties (kafka.server.BrokerMetadataCheckpoint) 2018-10-29T17:20:18.315922649Z 2018-10-29 17:20:18,315 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x21 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/controller_epoch Error:KeeperErrorCode = NoNode for /controller_epoch 2018-10-29T17:20:19.819232539Z 2018-10-29 17:20:19,818 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:delete cxid:0x34 zxid:0x1d txntype:-1 reqpath:n/a Error Path:/admin/reassign_partitions Error:KeeperErrorCode = NoNode for /admin/reassign_partitions 2018-10-29T17:20:19.886488141Z 2018-10-29 17:20:19,885 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:delete cxid:0x39 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/admin/preferred_replica_election Error:KeeperErrorCode = NoNode for /admin/preferred_replica_election 2018-10-29T17:20:33.391205454Z 2018-10-29 17:20:33,389 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x41 zxid:0x1f txntype:-1 reqpath:n/a Error Path:/config/topics/zipkin Error:KeeperErrorCode = NoNode for /config/topics/zipkin 2018-10-29T17:20:33.550588839Z 2018-10-29 17:20:33,550 [myid:] - INFO [ProcessThread(sid:0 cport:2181)::PrepRequestProcessor@653] - Got user-level KeeperException when processing sessionid:0x100c6b35df90000 type:setData cxid:0x4a zxid:0x22 txntype:-1 reqpath:n/a Error Path:/config/topics/__consumer_offsets Error:KeeperErrorCode = NoNode for /config/topics/__consumer_offsets

Please let me know if there are any corrections with my above configuration.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/openzipkin/docker-zipkin/issues/190#issuecomment-434020981, or mute the thread https://github.com/notifications/unsubscribe-auth/AAD619CGFfzgSKQCm37gQC8i1ghOOxepks5up0aVgaJpZM4X-Hag .