v0.29 Docker Error : unexpected error, closing socket connection and attempting reconnect

Question

v0.29 Docker Error : unexpected error, closing socket connection and attempting reconnect

ksingh7 opened this issue 5 years ago · 6 comments

Per our discussion on #1398 , I build the jars and packed that into docker container

Had a running Kafka/ZK containers

sudo docker-compose up
karan@beast:/mnt/hdd_space1/git/secor$ sudo docker ps
CONTAINER ID        IMAGE                             COMMAND                  CREATED             STATUS              PORTS                                        NAMES
36bfd8500cb4        confluentinc/cp-kafka:4.0.0       "/etc/confluent/dock…"   52 minutes ago      Up 52 minutes       0.0.0.0:9092->9092/tcp                       secor_kafka_1
547fb42d10e2        confluentinc/cp-zookeeper:4.0.0   "/etc/confluent/dock…"   52 minutes ago      Up 52 minutes       2888/tcp, 0.0.0.0:2181->2181/tcp, 3888/tcp   secor_zookeeper_1
karan@beast:/mnt/hdd_space1/git/secor$

After run, i tried to run sector container using this command

sudo docker run \
  -e DEBUG=true \
  -e ZOOKEEPER_PATH=/ \
  -e ZOOKEEPER_QUORUM=127.0.0.1:2181 \
  -e AWS_ACCESS_KEY=<KEY> \
  -e AWS_SECRET_KEY=<secret> \
  -e SECOR_S3_BUCKET=my-kafka-backups \
  -e SECOR_GROUP=raw_logs \
  -e KAFKA_SEED_BROKER_HOST=0.0.0.0:9092\
  karansingh/secor-0.29

i am getting error like this, i am not sure why does it connect to this host like 127.0.0.1/127.0.0.1:2181 this seems incorrect ??

2020-06-20 08:21:14,829 [Thread-5-SendThread(127.0.0.1:2181)] (org.apache.zookeeper.ClientCnxn) INFO  Opening socket connection to server 127.0.0.1/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
2020-06-20 08:21:14,829 [Thread-9-SendThread(127.0.0.1:2181)] (org.apache.zookeeper.ClientCnxn) INFO  Opening socket connection to server 127.0.0.1/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
2020-06-20 08:21:14,837 [Thread-5-SendThread(127.0.0.1:2181)] (org.apache.zookeeper.ClientCnxn) WARN  Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect
java.net.ConnectException: Connection refused
	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:714)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2020-06-20 08:21:14,837 [Thread-6-SendThread(127.0.0.1:2181)] (org.apache.zookeeper.ClientCnxn) WARN  Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect

Answer 1 · 2020-06-20T19:03:13.000Z

After some more testing, i found that some of the threads are not connecting to zookeeper :(

INFO: Starting LatchedStatsListener
Jun 20, 2020 6:27:54 PM com.twitter.logging.Logger log
INFO: Admin HTTP interface started on port 9999.
2020-06-20 18:27:54,994 [main] (com.pinterest.secor.common.OstrichAdminService:64) INFO  build.properties build_revision: ae9e639c6b318c40e381ffb5309cddd40034d93d
2020-06-20 18:27:55,243 [main] (com.pinterest.secor.main.ConsumerMain:69) INFO  starting 7 consumer threads
2020-06-20 18:27:55,383 [Thread-6] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-7] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-8] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-4] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-5] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-9] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,383 [Thread-3] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 18:27:55,409 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,410 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,410 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,410 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,411 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,410 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,411 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_16
2020-06-20 18:27:55,410 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,410 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property auto.commit.enable is overridden to false
2020-06-20 18:27:55,415 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,411 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,411 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,410 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,410 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,417 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_18
2020-06-20 18:27:55,416 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_14
2020-06-20 18:27:55,416 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,416 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,416 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property auto.offset.reset is overridden to smallest
2020-06-20 18:27:55,418 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,417 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,417 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,417 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_15
2020-06-20 18:27:55,417 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_17
2020-06-20 18:27:55,419 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,419 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,418 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,418 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_12
2020-06-20 18:27:55,420 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,418 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property consumer.id is overridden to 5a31c5cdd084_17_13
2020-06-20 18:27:55,420 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,420 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,419 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,419 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,419 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,421 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,421 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,421 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,420 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property consumer.timeout.ms is overridden to 10000
2020-06-20 18:27:55,420 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,422 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,422 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,422 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,422 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,421 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,421 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property dual.commit.enabled is overridden to false
2020-06-20 18:27:55,424 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,423 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,423 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,423 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,423 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,423 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,425 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,425 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,425 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,426 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,424 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,424 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,424 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property group.id is overridden to secor_backup
2020-06-20 18:27:55,426 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,426 [Thread-9] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,426 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,426 [Thread-5] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,425 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,425 [Thread-7] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,428 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,427 [Thread-3] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,427 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,427 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property offsets.storage is overridden to kafka
2020-06-20 18:27:55,428 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,429 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,429 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property partition.assignment.strategy is overridden to range
2020-06-20 18:27:55,429 [Thread-4] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,429 [Thread-6] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,430 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property zookeeper.connect is overridden to secor_zookeeper_1:2181/
2020-06-20 18:27:55,430 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property zookeeper.session.timeout.ms is overridden to 3000
2020-06-20 18:27:55,431 [Thread-8] (kafka.utils.Logging$class:68) INFO  Property zookeeper.sync.time.ms is overridden to 200
2020-06-20 18:27:55,493 [Thread-9] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_18], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,493 [Thread-7] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_16], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,493 [Thread-8] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_17], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,493 [Thread-5] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_14], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,493 [Thread-3] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_12], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,494 [Thread-4] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_13], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,496 [Thread-6] (kafka.utils.Logging$class:68) INFO  [secor_backup_5a31c5cdd084_17_15], Connecting to zookeeper instance at secor_zookeeper_1:2181/
2020-06-20 18:27:55,515 [ZkClient-EventThread-23-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,515 [ZkClient-EventThread-26-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,516 [ZkClient-EventThread-28-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,516 [ZkClient-EventThread-25-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,516 [ZkClient-EventThread-24-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,516 [ZkClient-EventThread-27-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,516 [ZkClient-EventThread-22-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:64) INFO  Starting ZkClient event thread.
2020-06-20 18:27:55,527 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:zookeeper.version=3.4.6-1569965, built on 02/20/2014 09:09 GMT
2020-06-20 18:27:55,527 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:host.name=5a31c5cdd084
2020-06-20 18:27:55,527 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.version=1.7.0_111
2020-06-20 18:27:55,527 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.vendor=Oracle Corporation
2020-06-20 18:27:55,528 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre
2020-06-20 18:27:55,528 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.class.path=/opt/secor/secor.jar
2020-06-20 18:27:55,528 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.library.path=:/usr/local/hadoop/lib/native:/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
2020-06-20 18:27:55,528 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.io.tmpdir=/tmp
2020-06-20 18:27:55,528 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:java.compiler=<NA>
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:os.name=Linux
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:os.arch=amd64
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:os.version=5.4.0-37-generic
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:user.name=root
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:user.home=/root
2020-06-20 18:27:55,529 [Thread-5] (org.apache.zookeeper.Environment:100) INFO  Client environment:user.dir=/
2020-06-20 18:27:55,531 [Thread-5] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@54d677c3
2020-06-20 18:27:55,531 [Thread-3] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@1eaf139a
2020-06-20 18:27:55,531 [Thread-6] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@4c50ceb8
2020-06-20 18:27:55,531 [Thread-8] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@4a0b1960
2020-06-20 18:27:55,531 [Thread-9] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@7ec21f4c
2020-06-20 18:27:55,531 [Thread-4] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@7a94f797
2020-06-20 18:27:55,531 [Thread-7] (org.apache.zookeeper.ZooKeeper:438) INFO  Initiating client connection, connectString=secor_zookeeper_1:2181/ sessionTimeout=3000 watcher=org.I0Itec.zkclient.ZkClient@4d33b92c
2020-06-20 18:27:55,552 [ZkClient-EventThread-23-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-28-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-27-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-22-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-26-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-24-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,552 [ZkClient-EventThread-25-secor_zookeeper_1:2181/] (org.I0Itec.zkclient.ZkEventThread:82) INFO  Terminate ZkClient event thread.
2020-06-20 18:27:55,553 [Thread-4] (com.pinterest.secor.main.ConsumerMain$1:65) ERROR Thread Thread[Thread-4,5,main] failed
java.lang.RuntimeException: Failed to initialize the consumer
	at com.pinterest.secor.consumer.Consumer.run(Consumer.java:89)
Caused by: org.I0Itec.zkclient.exception.ZkException: Unable to connect to secor_zookeeper_1:2181/
	at org.I0Itec.zkclient.ZkConnection.connect(ZkConnection.java:71)
	at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1227)
	at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:156)
	at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:130)
	at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:75)
	at kafka.utils.ZkUtils$.apply(ZkUtils.scala:57)
	at kafka.consumer.ZookeeperConsumerConnector.connectZk(ZookeeperConsumerConnector.scala:191)
	at kafka.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:139)
	at kafka.javaapi.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:66)
	at kafka.javaapi.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:69)
	at kafka.consumer.Consumer$.createJavaConsumerConnector(ConsumerConnector.scala:120)
	at kafka.consumer.Consumer.createJavaConsumerConnector(ConsumerConnector.scala)
	at com.pinterest.secor.reader.MessageReader.<init>(MessageReader.java:67)
	at com.pinterest.secor.consumer.Consumer.init(Consumer.java:70)
	at com.pinterest.secor.consumer.Consumer.run(Consumer.java:87)
Caused by: java.net.UnknownHostException: secor_zookeeper_1
	at java.net.InetAddress.getAllByName0(InetAddress.java:1273)
	at java.net.InetAddress.getAllByName(InetAddress.java:1185)
	at java.net.InetAddress.getAllByName(InetAddress.java:1119)
	at org.apache.zookeeper.client.StaticHostProvider.<init>(StaticHostProvider.java:61)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:445)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.I0Itec.zkclient.ZkConnection.connect(ZkConnection.java:69)
	... 14 more
2020-06-20 18:27:55,553 [Thread-6] (com.pinterest.secor.main.ConsumerMain$1:65) ERROR Thread Thread[Thread-6,5,main] failed
java.lang.RuntimeException: Failed to initialize the consumer
	at com.pinterest.secor.consumer.Consumer.run(Consumer.java:89)
Caused by: org.I0Itec.zkclient.exception.ZkException: Unable to connect to secor_zookeeper_1:2181/
	at org.I0Itec.zkclient.ZkConnection.connect(ZkConnection.java:71)
	at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1227)
	at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:156)
	at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:130)
	at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:75)
	at kafka.utils.ZkUtils$.apply(ZkUtils.scala:57)
	at kafka.consumer.ZookeeperConsumerConnector.connectZk(ZookeeperConsumerConnector.scala:191)
	at kafka.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:139)
	at kafka.javaapi.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:66)
	at kafka.javaapi.consumer.ZookeeperConsumerConnector.<init>(ZookeeperConsumerConnector.scala:69)
	at kafka.consumer.Consumer$.createJavaConsumerConnector(ConsumerConnector.scala:120)
	at kafka.consumer.Consumer.createJavaConsumerConnector(ConsumerConnector.scala)
	at com.pinterest.secor.reader.MessageReader.<init>(MessageReader.java:67)
	at com.pinterest.secor.consumer.Consumer.init(Consumer.java:70)
	at com.pinterest.secor.consumer.Consumer.run(Consumer.java:87)
Caused by: java.net.UnknownHostException: secor_zookeeper_1
	at java.net.InetAddress.getAllByName0(InetAddress.java:1273)
	at java.net.InetAddress.getAllByName(InetAddress.java:1185)
	at java.net.InetAddress.getAllByName(InetAddress.java:1119)
	at org.apache.zookeeper.client.StaticHostProvider.<init>(StaticHostProvider.java:61)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:445)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.I0Itec.zkclient.ZkConnection.connect(ZkConnection.java:69)
	... 14 more

Answer 2 · 2020-06-20T19:56:25.000Z

Now this has moved little more further, but still not there yet

I am getting a ton of these messages.

2020-06-20 19:49:26,913 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 19:49:26,913 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property client.id is overridden to secor_backup
2020-06-20 19:49:26,914 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property metadata.broker.list is overridden to localhost:9092
2020-06-20 19:49:26,914 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property request.timeout.ms is overridden to 30000
2020-06-20 19:49:26,914 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Fetching metadata from broker BrokerEndPoint(1001,localhost,9092) with correlation id 801 for 1 topic(s) Set(new_topic)
2020-06-20 19:49:26,915 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Connected to localhost:9092 for producing
2020-06-20 19:49:26,915 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Disconnecting from localhost:9092
2020-06-20 19:49:26,915 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:89) WARN  Fetching topic metadata with correlation id 801 for topics [Set(new_topic)] from broker [BrokerEndPoint(1001,localhost,9092)] failed
java.nio.channels.ClosedChannelException
	at kafka.network.BlockingChannel.send(BlockingChannel.scala:110)
	at kafka.producer.SyncProducer.liftedTree1$1(SyncProducer.scala:80)
	at kafka.producer.SyncProducer.kafka$producer$SyncProducer$$doSend(SyncProducer.scala:79)
	at kafka.producer.SyncProducer.send(SyncProducer.scala:124)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:59)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:94)
	at kafka.consumer.ConsumerFetcherManager$LeaderFinderThread.doWork(ConsumerFetcherManager.scala:66)
	at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)

2020-06-20 19:49:26,915 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Disconnecting from localhost:9092
2020-06-20 19:49:26,916 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:89) WARN  [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread], Failed to find leader for Set([new_topic,0])
kafka.common.KafkaException: fetching topic metadata for topics [Set(new_topic)] from broker [ArrayBuffer(BrokerEndPoint(1001,localhost,9092))] failed
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:73)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:94)
	at kafka.consumer.ConsumerFetcherManager$LeaderFinderThread.doWork(ConsumerFetcherManager.scala:66)
	at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
Caused by: java.nio.channels.ClosedChannelException
	at kafka.network.BlockingChannel.send(BlockingChannel.scala:110)
	at kafka.producer.SyncProducer.liftedTree1$1(SyncProducer.scala:80)
	at kafka.producer.SyncProducer.kafka$producer$SyncProducer$$doSend(SyncProducer.scala:79)
	at kafka.producer.SyncProducer.send(SyncProducer.scala:124)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:59)
	... 3 more
2020-06-20 19:49:26,916 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  [ConsumerFetcherManager-1592682398034] Added fetcher for partitions ArrayBuffer()

2020-06-20 19:49:27,123 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Verifying properties
2020-06-20 19:49:27,123 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property client.id is overridden to secor_backup
2020-06-20 19:49:27,123 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property metadata.broker.list is overridden to localhost:9092
2020-06-20 19:49:27,124 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Property request.timeout.ms is overridden to 30000
2020-06-20 19:49:27,124 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Fetching metadata from broker BrokerEndPoint(1001,localhost,9092) with correlation id 802 for 1 topic(s) Set(new_topic)
2020-06-20 19:49:27,125 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Connected to localhost:9092 for producing
2020-06-20 19:49:27,125 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Disconnecting from localhost:9092
2020-06-20 19:49:27,125 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:89) WARN  Fetching topic metadata with correlation id 802 for topics [Set(new_topic)] from broker [BrokerEndPoint(1001,localhost,9092)] failed
java.nio.channels.ClosedChannelException
	at kafka.network.BlockingChannel.send(BlockingChannel.scala:110)
	at kafka.producer.SyncProducer.liftedTree1$1(SyncProducer.scala:80)
	at kafka.producer.SyncProducer.kafka$producer$SyncProducer$$doSend(SyncProducer.scala:79)
	at kafka.producer.SyncProducer.send(SyncProducer.scala:124)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:59)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:94)
	at kafka.consumer.ConsumerFetcherManager$LeaderFinderThread.doWork(ConsumerFetcherManager.scala:66)
	at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
2020-06-20 19:49:27,125 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  Disconnecting from localhost:9092
2020-06-20 19:49:27,125 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:89) WARN  [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread], Failed to find leader for Set([new_topic,0])
kafka.common.KafkaException: fetching topic metadata for topics [Set(new_topic)] from broker [ArrayBuffer(BrokerEndPoint(1001,localhost,9092))] failed
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:73)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:94)
	at kafka.consumer.ConsumerFetcherManager$LeaderFinderThread.doWork(ConsumerFetcherManager.scala:66)
	at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
Caused by: java.nio.channels.ClosedChannelException
	at kafka.network.BlockingChannel.send(BlockingChannel.scala:110)
	at kafka.producer.SyncProducer.liftedTree1$1(SyncProducer.scala:80)
	at kafka.producer.SyncProducer.kafka$producer$SyncProducer$$doSend(SyncProducer.scala:79)
	at kafka.producer.SyncProducer.send(SyncProducer.scala:124)
	at kafka.client.ClientUtils$.fetchTopicMetadata(ClientUtils.scala:59)
	... 3 more
2020-06-20 19:49:27,126 [secor_backup_9e93ccaebe3f_20_12-leader-finder-thread] (kafka.utils.Logging$class:68) INFO  [ConsumerFetcherManager-1592682398034] Added fetcher for partitions ArrayBuffer()

This is how you can reproduce

Use docker-compose file provided in this repository
docker-compose up
This should give use Kafka and ZK pods
Run sector in docker container (same host)

sudo docker run \
  -e DEBUG=true \
  -e ZOOKEEPER_QUORUM=secor_zookeeper_1:2181 \
  -e KAFKA_SEED_BROKER_HOST=secor_kafka_1 \
  -e AWS_ACCESS_KEY=<ACCESS_KEY> \
  -e AWS_SECRET_KEY=<SECRET_KEY> \
  -e SECOR_S3_BUCKET=<S3_BUCKET_NAME> \
  -e SECOR_GROUP=raw_logs \
  -e SECOR_S3_PATH=my-path \
  -e KAFKA_OFFSETS_STORAGE=zookeeper \
  -e AWS_DEFAULT_REGION=ap-south-1 \
  -e SECOR_MAX_FILE_SECONDS=10 \
  --network secor_beast \
  --link secor_zookeeper_1 \
  --link secor_kafka_1 \
  ovotech/secor

ps : you need to create the S3 bucket in advance, also if you are running secor container on the same node as kafka/zk then you need to link then and use same docker network between all 3 containers.

Answer 3 · 2020-06-20T19:58:19.000Z

@HenryCaiHaiying can you give a try with the above commands and see if this works for you / you can reproduce the same issue ? Looking forward to hearing from you soon.

Answer 4 · 2020-06-21T07:38:10.000Z

127.0.0.1:2181 is to connect to zookeeper running on localhost at port 2181 (the default port for ZK)

Answer 5 · 2020-06-22T10:38:46.000Z

@HenryCaiHaiying That was useful , i can now connect to Kafka cluster using sector container , cool

But sector is able to read the messages but throwing NullPointerException, (see below)

I have produced some messages using Kafka cat and i can verify the message as shown below

Can you guide me if there has to be a specific format that needs to be used while messages are generated into Kafka topic, such that sector can move them to S3 ? I am doing a Proof of Concept , looks like i am very close but still missing certain detail.s

I definitely like to document my learnings in a step by step blog post so that others should not fumble to get secor working ;)

Need your help right now.

Answer 6 · 2020-06-22T16:08:15.000Z

Closing this issue and have opened #1404 to further troubleshoot