You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@openwhisk.apache.org by GitBox <gi...@apache.org> on 2017/12/01 15:17:33 UTC
[GitHub] ransombriggs opened a new issue #105: invoker-0 stuck in CrashLoopBackOff loop probably due to issues creating a kafka topic
ransombriggs opened a new issue #105: invoker-0 stuck in CrashLoopBackOff loop probably due to issues creating a kafka topic
URL: https://github.com/apache/incubator-openwhisk-deploy-kube/issues/105
I have started all the openwhisk services, but the invoker appears to have issues creating a topic in kafka and then issues a JVM shutdown hook. The relevant errors from invoker logs appears to be the following, which originates from [invoker.scala](https://github.com/apache/incubator-openwhisk/blob/master/core/invoker/src/main/scala/whisk/core/invoker/Invoker.scala#L200)
```
[2017-12-01T15:01:42.512Z] [ERROR] [??] [KafkaMessagingProvider] exception during creation of topic invoker0
[2017-12-01T15:01:42.514Z] [ERROR] [#sid_100] [Invoker] failure during msgProvider.ensureTopic for topic invoker0
[INFO] [12/01/2017 15:01:42.604] [kamon-shutdown-hook-1] [CoordinatedShutdown(akka://kamon)] Starting coordinated shutdown from JVM shutdown hook
```
I have also included the relevant pods output as well as the full logs from invoker and relevant logs from kafka in case I missed some output that might help debug things.
```
-> % kubectl get pods -n openwhisk
NAME READY STATUS RESTARTS AGE
apigateway-75f6c5fdc-jrp8n 1/1 Running 0 15h
controller-0 0/1 CrashLoopBackOff 75 15h
controller-1 0/1 CrashLoopBackOff 75 15h
couchdb-5b6c59c7cc-hgf2z 1/1 Running 0 15h
invoker-0 0/1 CrashLoopBackOff 32 15h
kafka-797ff4c999-9tjb6 1/1 Running 0 15h
nginx-88b764487-9bvls 1/1 Running 0 15h
redis-7fb77bfc4-n5h8b 1/1 Running 0 15h
zookeeper-575965f666-4wgwj 1/1 Running 0 15
```
```
-> % kubectl -n openwhisk logs invoker-0
[2017-12-01T14:59:38.893Z] [INFO] Initializing Kamon...
[INFO] [12/01/2017 14:59:39.358] [main] [StatsDExtension(akka://kamon)] Starting the Kamon(StatsD) extension
[2017-12-01T14:59:39.506Z] [INFO] Slf4jLogger started
[2017-12-01T14:59:39.717Z] [INFO] [??] [Config] environment set value for db.whisk.actions
[2017-12-01T14:59:39.805Z] [INFO] [??] [Config] environment set value for db.protocol
[2017-12-01T14:59:39.817Z] [INFO] [??] [Config] environment set value for docker.image.prefix
[2017-12-01T14:59:39.839Z] [INFO] [??] [Config] environment set value for invoker.container.network
[2017-12-01T14:59:39.841Z] [INFO] [??] [Config] environment set value for whisk.api.host.name
[2017-12-01T14:59:39.843Z] [INFO] [??] [Config] environment set value for db.port
[2017-12-01T14:59:39.843Z] [INFO] [??] [Config] environment set value for db.whisk.activations.filter.ddoc
[2017-12-01T14:59:39.843Z] [INFO] [??] [Config] environment set value for db.username
[2017-12-01T14:59:39.843Z] [INFO] [??] [Config] environment set value for db.whisk.activations
[2017-12-01T14:59:39.844Z] [INFO] [??] [Config] environment set value for docker.registry
[2017-12-01T14:59:39.847Z] [INFO] [??] [Config] environment set value for db.whisk.actions.ddoc
[2017-12-01T14:59:39.872Z] [INFO] [??] [Config] environment set value for invoker.name
[2017-12-01T14:59:39.872Z] [INFO] [??] [Config] environment set value for docker.image.tag
[2017-12-01T14:59:39.873Z] [INFO] [??] [Config] environment set value for invoker.use.runc
[2017-12-01T14:59:39.873Z] [INFO] [??] [Config] environment set value for db.whisk.activations.ddoc
[2017-12-01T14:59:39.900Z] [INFO] [??] [Config] environment set value for zookeeper.hosts
[2017-12-01T14:59:39.900Z] [INFO] [??] [Config] environment set value for runtimes.manifest
[2017-12-01T14:59:39.953Z] [INFO] [??] [Config] environment set value for kafka.hosts
[2017-12-01T14:59:39.953Z] [INFO] [??] [Config] environment set value for db.host
[2017-12-01T14:59:39.953Z] [INFO] [??] [Config] environment set value for port
[2017-12-01T14:59:39.954Z] [INFO] [??] [Config] environment set value for db.provider
[2017-12-01T14:59:39.954Z] [INFO] [??] [Config] environment set value for db.password
[2017-12-01T14:59:41.038Z] [INFO] [??] [Invoker] Command line arguments parsed to yield CmdLineArgs(None,Some(0))
[2017-12-01T14:59:41.160Z] [INFO] [??] [Invoker] invokerReg: using proposedInvokerId 0
[2017-12-01T15:01:42.512Z] [ERROR] [??] [KafkaMessagingProvider] exception during creation of topic invoker0
[2017-12-01T15:01:42.514Z] [ERROR] [#sid_100] [Invoker] failure during msgProvider.ensureTopic for topic invoker0
[INFO] [12/01/2017 15:01:42.604] [kamon-shutdown-hook-1] [CoordinatedShutdown(akka://kamon)] Starting coordinated shutdown from JVM shutdown hook
```
```
kafka is up and running
+ echo 'Create health topic'
Create health topic
++ kafka-topics.sh --create --topic health --replication-factor 1 --partitions 1 --zookeeper zookeeper.openwhisk:2181 --config retention.bytes=536870912 --config retention.ms=1073741824 --config segment.bytes=3600000
[2017-11-30 23:08:26,065] INFO Creating /controller (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-11-30 23:08:26,113] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)
[2017-11-30 23:08:26,114] INFO 0 successfully elected as leader (kafka.server.ZookeeperLeaderElector)
[2017-11-30 23:08:26,498] INFO [ExpirationReaper-0], Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-11-30 23:08:26,504] INFO [ExpirationReaper-0], Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-11-30 23:08:26,508] INFO [ExpirationReaper-0], Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-11-30 23:08:26,571] INFO [GroupCoordinator 0]: Starting up. (kafka.coordinator.GroupCoordinator)
[2017-11-30 23:08:26,579] INFO [GroupCoordinator 0]: Startup complete. (kafka.coordinator.GroupCoordinator)
[2017-11-30 23:08:26,592] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 13 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-11-30 23:08:26,690] INFO Will not load MX4J, mx4j-tools.jar is not in the classpath (kafka.utils.Mx4jLoader$)
[2017-11-30 23:08:26,814] INFO Creating /brokers/ids/0 (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-11-30 23:08:26,830] INFO New leader is 0 (kafka.server.ZookeeperLeaderElector$LeaderChangeListener)
[2017-11-30 23:08:26,832] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)
[2017-11-30 23:08:26,834] INFO Registered broker 0 at path /brokers/ids/0 with addresses: EndPoint(kafka.openwhisk,9092,ListenerName(PLAINTEXT),PLAINTEXT) (kafka.utils.ZkUtils)
[2017-11-30 23:08:26,835] WARN No meta.properties file under dir /data/meta.properties (kafka.server.BrokerMetadataCheckpoint)
[2017-11-30 23:08:26,927] INFO Kafka version : 0.10.2.1 (org.apache.kafka.common.utils.AppInfoParser)
[2017-11-30 23:08:26,927] INFO Kafka commitId : e89bffd6b2eff799 (org.apache.kafka.common.utils.AppInfoParser)
[2017-11-30 23:08:26,931] INFO [Kafka Server 0], started (kafka.server.KafkaServer)
+ OUTPUT='Created topic "health".'
+ [[ Created topic "health". == *\a\l\r\e\a\d\y\ \e\x\i\s\t\s* ]]
+ [[ Created topic "health". == *\C\r\e\a\t\e\d\ \t\o\p\i\c* ]]
+ fg
/start.sh
[2017-11-30 23:18:26,585] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 3 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-11-30 23:28:26,581] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-11-30 23:38:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-11-30 23:48:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-11-30 23:58:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:08:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:18:26,580] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:28:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:38:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:48:26,579] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 1 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 00:58:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:08:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:18:26,579] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:28:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:38:26,577] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:48:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 01:58:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 02:08:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 02:18:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-12-01 02:28:26,578] INFO [Group Metadata Manager on Broker 0]: Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.GroupMetadataManager)
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on 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