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 2019/09/13 07:24:16 UTC
[GitHub] [incubator-druid] gocho1 opened a new issue #8534: Ingest task
succeeded then failed but stays running forever
gocho1 opened a new issue #8534: Ingest task succeeded then failed but stays running forever
URL: https://github.com/apache/incubator-druid/issues/8534
### Affected Version
Encountered in Druid 0.15.0, no other version tested yet.
### Description
A task that succeeded switch to failed status for no visible reason.
Then some resources are stopped and an exception occured on a thread that need a resource ("ServiceEmitter") that has been stopped.
Here is the log of the task.
```
2019-09-08T18:43:42,477 INFO [task-runner-0-priority-0] org.apache.druid.indexing.worker.executor.ExecutorLifecycle - Task completed with status: {
"id" : "index_hadoop_datasource_2019-09-08T18:42:42.831Z",
"status" : "SUCCESS",
"duration" : 54326,
"errorMsg" : null
}
2019-09-08T18:43:42,482 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [ANNOUNCEMENTS]
2019-09-08T18:43:42,483 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.curator.announcement.Announcer.stop()] on object[org.apache.druid.curator.announcement.Announcer@75bf9e67].
2019-09-08T18:43:42,484 INFO [main] org.apache.druid.curator.announcement.Announcer - Stopping announcer
2019-09-08T18:43:42,484 INFO [main] org.apache.druid.curator.announcement.Announcer - unannouncing [/druid_iods/listeners/lookups/__default/http:ip-XXX.eu-west-1.compute.internal:8100]
2019-09-08T18:43:42,497 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [SERVER]
2019-09-08T18:43:42,497 INFO [main] org.apache.druid.server.initialization.jetty.JettyServerModule - Stopping Jetty Server...
2019-09-08T18:43:42,501 INFO [main] org.eclipse.jetty.server.AbstractConnector - Stopped ServerConnector@1d39a880{HTTP/1.1,[http/1.1]}{0.0.0.0:8100}
2019-09-08T18:43:42,501 INFO [main] org.eclipse.jetty.server.session - node0 Stopped scavenging
2019-09-08T18:43:42,503 INFO [main] org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.s.ServletContextHandler@751686aa{/,null,UNAVAILABLE}
2019-09-08T18:43:42,506 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [NORMAL]
2019-09-08T18:43:42,506 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.server.listener.announcer.ListenerResourceAnnouncer.stop()] on object[org.apache.druid.query.lookup.LookupResourceListenerAnnouncer@54bb1194].
2019-09-08T18:43:42,506 INFO [main] org.apache.druid.server.listener.announcer.ListenerResourceAnnouncer - Unannouncing start time on [/druid_iods/listeners/lookups/__default/http:ip-XXX.eu-west-1.compute.internal:8100]
2019-09-08T18:43:42,506 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.indexing.worker.executor.ExecutorLifecycle.stop() throws java.lang.Exception] on object[org.apache.druid.indexing.worker.executor.ExecutorLifecycle@46702c26].
2019-09-08T18:43:42,507 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner.stop()] on object[org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner@12c76d6e].
2019-09-08T18:43:42,507 INFO [main] org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner - Starting graceful shutdown of task[index_hadoop_datasource_2019-09-08T18:42:42.831Z].
2019-09-08T18:43:42,507 INFO [main] org.apache.druid.indexing.overlord.TaskRunnerUtils - Task [index_hadoop_datasource_2019-09-08T18:42:42.831Z] status changed to [FAILED].
2019-09-08T18:43:42,519 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.client.cache.CaffeineCache.close()] on object[org.apache.druid.client.cache.CaffeineCache@f08d676].
2019-09-08T18:43:42,520 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.discovery.DruidLeaderClient.stop()] on object[org.apache.druid.discovery.DruidLeaderClient@5d27b4c1].
2019-09-08T18:43:42,520 INFO [main] org.apache.druid.discovery.DruidLeaderClient - Stopped.
2019-09-08T18:43:42,520 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.curator.discovery.ServerDiscoverySelector.stop() throws java.io.IOException] on object[org.apache.druid.curator.discovery.ServerDiscoverySelector@23396fc0].
2019-09-08T18:43:42,521 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.stop()] on object[org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager@32b112a1].
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager - DefaultBasicAuthenticatorCacheManager is stopping.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager - DefaultBasicAuthenticatorCacheManager is stopped.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.java.util.metrics.MonitorScheduler.stop()] on object[org.apache.druid.java.util.metrics.MonitorScheduler@34549979].
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.security.basic.authorization.db.cache.CoordinatorPollingBasicAuthorizerCacheManager.stop()] on object[org.apache.druid.security.basic.authorization.db.cache.CoordinatorPollingBasicAuthorizerCacheManager@ce655b9].
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.security.basic.authorization.db.cache.CoordinatorPollingBasicAuthorizerCacheManager - CoordinatorPollingBasicAuthorizerCacheManager is stopping.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.security.basic.authorization.db.cache.CoordinatorPollingBasicAuthorizerCacheManager - CoordinatorPollingBasicAuthorizerCacheManager is stopped.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.query.lookup.LookupReferencesManager.stop()] on object[org.apache.druid.query.lookup.LookupReferencesManager@171aa66].
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - LookupExtractorFactoryContainerProvider is stopping.
2019-09-08T18:43:42,522 INFO [LookupExtractorFactoryContainerProvider-MainThread] org.apache.druid.query.lookup.LookupReferencesManager - Lookup Management loop exited, Lookup notices are not handled anymore.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - LookupExtractorFactoryContainerProvider is stopped.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.discovery.DruidLeaderClient.stop()] on object[org.apache.druid.discovery.DruidLeaderClient@faec277].
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.discovery.DruidLeaderClient - Stopped.
2019-09-08T18:43:42,522 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.curator.discovery.ServerDiscoverySelector.stop() throws java.io.IOException] on object[org.apache.druid.curator.discovery.ServerDiscoverySelector@1a536164].
2019-09-08T18:43:42,523 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider.stop()] on object[org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider@3df77dfa].
2019-09-08T18:43:42,523 INFO [main] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider - stopping
2019-09-08T18:43:42,523 INFO [main] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider - stopped
2019-09-08T18:43:42,523 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.java.util.http.client.NettyHttpClient.stop()] on object[org.apache.druid.java.util.http.client.NettyHttpClient@64f3ca6].
2019-09-08T18:43:42,538 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void org.apache.druid.java.util.emitter.service.ServiceEmitter.close() throws java.io.IOException] on object[ServiceEmitter{serviceDimensions={service=druid/middleManager, host=ip-XXX.eu-west-1.compute.internal:8100, version=0.15.0-incubating}, emitter=HttpPostEmitter{config=HttpEmitterConfig{flushMillis=10000, flushCount=500, flushTimeOut=9223372036854775807, basicAuthentication='null', batchingStrategy=ARRAY, maxBatchSize=5191680, contentEncoding=null, batchQueueSizeLimit=9, httpTimeoutAllowanceFactor=2.0, minHttpTimeoutMillis=0, recipientBaseUrl='https://fluentd.common.pps.io/druid_iods'}}}].
2019-09-08T18:43:49,802 WARN [BasicAuthenticatorCacheManager-Exec--0] org.apache.druid.java.util.common.RetryUtils - Retrying (1 of 9) in 783ms.
java.lang.IllegalStateException
at com.google.common.base.Preconditions.checkState(Preconditions.java:161) ~[guava-16.0.1.jar:?]
at org.apache.druid.discovery.DruidLeaderClient.makeRequest(DruidLeaderClient.java:130) ~[druid-server-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.discovery.DruidLeaderClient.makeRequest(DruidLeaderClient.java:139) ~[druid-server-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.tryFetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:250) ~[?:?]
at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$fetchUserMapFromCoordinator$1(CoordinatorPollingBasicAuthenticatorCacheManager.java:191) ~[?:?]
at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:86) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:114) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:104) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.fetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:189) ~[?:?]
at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$start$0(CoordinatorPollingBasicAuthenticatorCacheManager.java:121) ~[?:?]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:55) [druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:51) [druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$2.run(ScheduledExecutors.java:92) [druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222-ea]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222-ea]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222-ea]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_222-ea]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222-ea]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222-ea]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222-ea]
. . .
2019-09-08T18:47:45,004 ERROR [CoordinatorPollingBasicAuthorizerCacheManager-Exec--0] org.apache.druid.java.util.common.concurrent.ScheduledExecutors - Uncaught exception.
java.util.concurrent.RejectedExecutionException: Service is closed.
at org.apache.druid.java.util.emitter.core.HttpPostEmitter.awaitStarted(HttpPostEmitter.java:208) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.core.HttpPostEmitter.emitAndReturnBatch(HttpPostEmitter.java:233) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.core.HttpPostEmitter.emit(HttpPostEmitter.java:226) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.service.ServiceEmitter.emit(ServiceEmitter.java:67) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.service.ServiceEmitter.emit(ServiceEmitter.java:72) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.service.AlertBuilder.emit(AlertBuilder.java:88) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.emitter.EmittingLogger$EmittingAlertBuilder.emit(EmittingLogger.java:109) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.security.basic.authorization.db.cache.CoordinatorPollingBasicAuthorizerCacheManager.lambda$start$0(CoordinatorPollingBasicAuthorizerCacheManager.java:132) ~[?:?]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:55) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:51) ~[druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$2.run(ScheduledExecutors.java:92) [druid-core-0.15.0-incubating.jar:0.15.0-incubating]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222-ea]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222-ea]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222-ea]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_222-ea]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222-ea]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222-ea]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222-ea]
```
----------------------------------------------------------------
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