You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@druid.apache.org by GitBox <gi...@apache.org> on 2020/03/17 17:07:54 UTC
[GitHub] [druid] DixxieFlatline commented on issue #9527: Second task hangs
while ingesting from Kafka in Dockerized environment
DixxieFlatline commented on issue #9527: Second task hangs while ingesting from Kafka in Dockerized environment
URL: https://github.com/apache/druid/issues/9527#issuecomment-600189381
I only had one instance of zookeeper so I've implemented a cluster of 3, leading to a new exception in the task log:
```
2020-03-17T16:59:08,392 INFO [main] org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=node0
2020-03-17T16:59:08,393 INFO [main] org.eclipse.jetty.server.session - No SessionScavenger set, using defaults
2020-03-17T16:59:08,394 INFO [main] org.eclipse.jetty.server.session - node0 Scavenging every 660000ms
2020-03-17T16:59:08,450 INFO [task-runner-0-priority-0] org.apache.kafka.common.utils.AppInfoParser - Kafka version: 2.2.1
2020-03-17T16:59:08,450 INFO [task-runner-0-priority-0] org.apache.kafka.common.utils.AppInfoParser - Kafka commitId: 55783d3133a5a49a
2020-03-17T16:59:08,452 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.CuratorDataSegmentServerAnnouncer - Announcing self[DruidServerMetadata{name='172.18.0.10:8101', hostAndPort='172.18.0.10:8101', hostAndTlsPort='null', maxSize=0, tier='_default_tier', type=indexer-executor, priority=0}] at [/druid/announcements/172.18.0.10:8101]
2020-03-17T16:59:08,457 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering org.apache.druid.server.http.SegmentListerResource as a root resource class
2020-03-17T16:59:08,458 INFO [task-runner-0-priority-0] org.apache.druid.curator.discovery.CuratorDruidNodeAnnouncer - Announced self [{"druidNode":{"service":"druid/middleManager","host":"172.18.0.10","bindOnHost":false,"plaintextPort":8101,"port":-1,"tlsPort":-1,"enablePlaintextPort":true,"enableTlsPort":false},"nodeType":"peon","services":{"dataNodeService":{"type":"dataNodeService","tier":"_default_tier","maxSize":0,"type":"indexer-executor","priority":0},"lookupNodeService":{"type":"lookupNodeService","lookupTier":"__default"}}}].
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering com.fasterxml.jackson.jaxrs.json.JacksonJsonProvider as a provider class
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering com.fasterxml.jackson.jaxrs.smile.JacksonSmileProvider as a provider class
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering org.apache.druid.server.initialization.jetty.CustomExceptionMapper as a provider class
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering org.apache.druid.server.initialization.jetty.ForbiddenExceptionMapper as a provider class
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering org.apache.druid.server.initialization.jetty.BadRequestExceptionMapper as a provider class
2020-03-17T16:59:08,459 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Registering org.apache.druid.server.StatusResource as a root resource class
2020-03-17T16:59:08,461 INFO [main] com.sun.jersey.server.impl.application.WebApplicationImpl - Initiating Jersey application, version 'Jersey: 1.19.3 10/24/2016 03:43 PM'
2020-03-17T16:59:08,500 INFO [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Initialized sequences: SequenceMetadata{sequenceId=0, sequenceName='index_kafka_analytics_d8c5f0c4519ee11_0', assignments=[0], startOffsets={0=8906}, exclusiveStartPartitions=[], endOffsets={0=9223372036854775807}, sentinel=false, checkpointed=false}
2020-03-17T16:59:08,501 INFO [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Adding partition[0], start[8906] -> end[9223372036854775807] to assignment.
2020-03-17T16:59:08,504 INFO [task-runner-0-priority-0] org.apache.kafka.clients.consumer.KafkaConsumer - [Consumer clientId=consumer-1, groupId=kafka-supervisor-lhgmjjpk] Subscribed to partition(s): analytics-0
2020-03-17T16:59:08,508 INFO [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Seeking partition[0] to[8906].
2020-03-17T16:59:08,522 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.initialization.jetty.CustomExceptionMapper to GuiceManagedComponentProvider with the scope "Singleton"
2020-03-17T16:59:08,523 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.initialization.jetty.ForbiddenExceptionMapper to GuiceManagedComponentProvider with the scope "Singleton"
2020-03-17T16:59:08,523 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.initialization.jetty.BadRequestExceptionMapper to GuiceManagedComponentProvider with the scope "Singleton"
2020-03-17T16:59:08,524 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding com.fasterxml.jackson.jaxrs.json.JacksonJsonProvider to GuiceManagedComponentProvider with the scope "Singleton"
2020-03-17T16:59:08,530 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding com.fasterxml.jackson.jaxrs.smile.JacksonSmileProvider to GuiceManagedComponentProvider with the scope "Singleton"
2020-03-17T16:59:08,652 INFO [task-runner-0-priority-0] org.apache.kafka.clients.Metadata - Cluster ID: -8JgS5vVQLeP_wB2EIOI9A
2020-03-17T16:59:08,932 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.http.security.StateResourceFilter to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,950 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - New segment[analytics_2020-03-17T16:00:00.000Z_2020-03-17T17:00:00.000Z_2020-03-17T16:58:03.837Z_1] for sequenceName[index_kafka_analytics_d8c5f0c4519ee11_0].
2020-03-17T16:59:08,951 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.http.SegmentListerResource to GuiceManagedComponentProvider with the scope "PerRequest"
2020-03-17T16:59:08,957 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.QueryResource to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,962 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.segment.realtime.firehose.ChatHandlerResource to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,965 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.http.security.ConfigResourceFilter to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,969 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.query.lookup.LookupListeningResource to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,971 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.query.lookup.LookupIntrospectionResource to GuiceInstantiatedComponentProvider
2020-03-17T16:59:08,972 INFO [main] com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory - Binding org.apache.druid.server.StatusResource to GuiceManagedComponentProvider with the scope "Undefined"
2020-03-17T16:59:09,002 INFO [main] org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5f0d8937{/,null,AVAILABLE}
2020-03-17T16:59:09,004 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Announcing segment[analytics_2020-03-17T16:00:00.000Z_2020-03-17T17:00:00.000Z_2020-03-17T16:58:03.837Z_1] at new path[/druid/segments/172.18.0.10:8101/172.18.0.10:8101_indexer-executor__default_tier_2020-03-17T16:59:09.000Z_cb6ca84f7c9b4469873c49965947c8320]
2020-03-17T16:59:09,017 INFO [main] org.eclipse.jetty.server.AbstractConnector - Started ServerConnector@10745a02{HTTP/1.1,[http/1.1]}{0.0.0.0:8101}
2020-03-17T16:59:09,017 INFO [main] org.eclipse.jetty.server.Server - Started @4764ms
2020-03-17T16:59:09,018 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Starting lifecycle [module] stage [ANNOUNCEMENTS]
2020-03-17T16:59:09,079 INFO [main] org.apache.druid.curator.announcement.Announcer - Problem creating parentPath[/druid/segments/172.18.0.10:8101], someone else created it first?
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /druid/segments/172.18.0.10:8101
at org.apache.zookeeper.KeeperException.create(KeeperException.java:122) ~[zookeeper-3.4.14.jar:3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf]
at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.4.14.jar:3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf]
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:792) ~[zookeeper-3.4.14.jar:3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf]
at org.apache.curator.framework.imps.CreateBuilderImpl$17.call(CreateBuilderImpl.java:1179) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl$17.call(CreateBuilderImpl.java:1160) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.connection.StandardConnectionHandlingPolicy.callWithRetry(StandardConnectionHandlingPolicy.java:64) ~[curator-client-4.1.0.jar:?]
at org.apache.curator.RetryLoop.callWithRetry(RetryLoop.java:100) ~[curator-client-4.1.0.jar:?]
at org.apache.curator.framework.imps.CreateBuilderImpl.pathInForeground(CreateBuilderImpl.java:1157) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl.protectedPathInForeground(CreateBuilderImpl.java:607) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl.forPath(CreateBuilderImpl.java:597) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl.forPath(CreateBuilderImpl.java:575) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl$4.forPath(CreateBuilderImpl.java:463) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.curator.framework.imps.CreateBuilderImpl$4.forPath(CreateBuilderImpl.java:393) ~[curator-framework-4.1.0.jar:4.1.0]
at org.apache.druid.curator.announcement.Announcer.createPath(Announcer.java:425) [druid-server-0.17.0.jar:0.17.0]
at org.apache.druid.curator.announcement.Announcer.announce(Announcer.java:298) [druid-server-0.17.0.jar:0.17.0]
at org.apache.druid.curator.announcement.Announcer.start(Announcer.java:116) [druid-server-0.17.0.jar:0.17.0]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_232]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_232]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
at org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler.start(Lifecycle.java:446) [druid-core-0.17.0.jar:0.17.0]
at org.apache.druid.java.util.common.lifecycle.Lifecycle.start(Lifecycle.java:341) [druid-core-0.17.0.jar:0.17.0]
at org.apache.druid.guice.LifecycleModule$2.start(LifecycleModule.java:143) [druid-core-0.17.0.jar:0.17.0]
at org.apache.druid.cli.GuiceRunnable.initLifecycle(GuiceRunnable.java:115) [druid-services-0.17.0.jar:0.17.0]
at org.apache.druid.cli.CliPeon.run(CliPeon.java:280) [druid-services-0.17.0.jar:0.17.0]
at org.apache.druid.cli.Main.main(Main.java:113) [druid-services-0.17.0.jar:0.17.0]
2020-03-17T16:59:09,084 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Successfully started lifecycle [module]
2020-03-17T17:00:00,046 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - New segment[analytics_2020-03-17T17:00:00.000Z_2020-03-17T18:00:00.000Z_2020-03-17T17:00:00.034Z] for sequenceName[index_kafka_analytics_d8c5f0c4519ee11_0].
2020-03-17T17:00:00,052 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Announcing segment[analytics_2020-03-17T17:00:00.000Z_2020-03-17T18:00:00.000Z_2020-03-17T17:00:00.034Z] at existing path[/druid/segments/172.18.0.10:8101/172.18.0.10:8101_indexer-executor__default_tier_2020-03-17T16:59:09.000Z_cb6ca84f7c9b4469873c49965947c8320]
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For additional commands, e-mail: commits-help@druid.apache.org