mhaack opened a new issue #39: docker-compose tooling fails on Mac using docker-machine URL: https://github.com/apache/incubator-openwhisk-devtools/issues/39 The docker-compose tooling does not work on Mac if docker-machine (with VirtualBox VM) is used as docker environment. `make quick-start` fails and waits forever after ``` waiting until the controller recognizes a healthy invoker ... Restarting openwhisk_controller_1 ........................................... ``` I think this is with the `restart-controller` step in the mail file. Looks like it is related to the invoker does not start and the controller does not find a working invoker. So the actual problem might have been occurred before. But the previous step `init-couchdb` did not log any error. Errors from the invoker log: ``` [2017-06-15T13:06:18.470Z] [INFO] Slf4jLogger started [2017-06-15T13:06:18.788Z] [INFO] [??] [Config] environment set value for db.whisk.actions [2017-06-15T13:06:18.841Z] [INFO] [??] [Config] environment set value for db.protocol [2017-06-15T13:06:18.842Z] [INFO] [??] [Config] environment set value for consulserver.host [2017-06-15T13:06:18.846Z] [INFO] [??] [Config] environment set value for docker.image.prefix [2017-06-15T13:06:18.850Z] [INFO] [??] [Config] environment set value for invoker.container.network [2017-06-15T13:06:18.868Z] [INFO] [??] [Config] environment set value for whisk.version.date [2017-06-15T13:06:18.869Z] [INFO] [??] [Config] environment set value for whisk.api.host.name [2017-06-15T13:06:18.870Z] [INFO] [??] [Config] environment set value for db.port [2017-06-15T13:06:18.876Z] [INFO] [??] [Config] environment set value for whisk.version.buildno [2017-06-15T13:06:18.877Z] [INFO] [??] [Config] environment set value for db.username [2017-06-15T13:06:18.888Z] [INFO] [??] [Config] environment set value for db.whisk.activations [2017-06-15T13:06:18.896Z] [INFO] [??] [Config] environment set value for docker.registry [2017-06-15T13:06:18.897Z] [INFO] [??] [Config] environment set value for db.whisk.auths [2017-06-15T13:06:18.902Z] [INFO] [??] [Config] environment set value for whisk.logs.dir [2017-06-15T13:06:18.911Z] [INFO] [??] [Config] environment set value for runtimes.manifest [2017-06-15T13:06:18.918Z] [INFO] [??] [Config] environment set value for kafka.host.port [2017-06-15T13:06:18.928Z] [INFO] [??] [Config] environment set value for consul.host.port4 [2017-06-15T13:06:18.931Z] [INFO] [??] [Config] environment set value for db.host [2017-06-15T13:06:18.935Z] [INFO] [??] [Config] environment set value for port [2017-06-15T13:06:18.950Z] [INFO] [??] [Config] environment set value for db.provider [2017-06-15T13:06:18.953Z] [INFO] [??] [Config] environment set value for db.password [2017-06-15T13:06:18.953Z] [INFO] [??] [Config] environment set value for kafka.host [2017-06-15T13:06:18.954Z] [INFO] [??] [WhiskConfig] reading properties from consul at consul.docker:8500 [2017-06-15T13:06:26.949Z] [WARN] [??] [WhiskConfig] failed to read properties from consul: null [2017-06-15T13:06:28.592Z] [INFO] [#sid_100] [Invoker] starting invoker instance 0 [marker:invoker_startup0_count:9831] [2017-06-15T13:06:30.904Z] [INFO] [??] [ContainerPool] Not using runc because of configuration flag [2017-06-15T13:06:30.913Z] [INFO] [??] [ContainerPool] dockerhost = localhost serializeDockerOp = true serializeDockerPull = true useRunC = false [2017-06-15T13:06:30.956Z] [INFO] [??] [ContainerPool] maxActive set to 8 [2017-06-15T13:06:30.969Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.ps_start:12240] [2017-06-15T13:06:30.992Z] [INFO] [#sid_101] [SimpleExec] Running command: /usr/bin/docker ps --no-trunc -a [2017-06-15T13:06:31.242Z] [INFO] [#sid_101] [SimpleExec] Done running command: /usr/bin/docker ps --no-trunc -a [2017-06-15T13:06:31.244Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.ps_finish:12516:248] [2017-06-15T13:06:31.255Z] [INFO] [??] [Invoker] using whisk.core.invoker.Invoker@76adb233 [2017-06-15T13:06:31.258Z] [INFO] [#sid_102] [ContainerPool] killStragglers now removing 2 leftover containers [2017-06-15T13:06:31.276Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.unpause_start:12534] [2017-06-15T13:06:31.289Z] [INFO] [#sid_102] [SimpleExec] Running command: /usr/bin/docker unpause wsk0_2_warmJsContainer_20170509T111848942Z [2017-06-15T13:06:31.505Z] [INFO] [#sid_102] [SimpleExec] Done running command: /usr/bin/docker unpause wsk0_2_warmJsContainer_20170509T111848942Z [2017-06-15T13:06:31.517Z] [ERROR] [#sid_102] [ContainerUtils] stdout: stderr: Error response from daemon: Container 9a9e0b935a4f121325a69bc208830b55d7ccf4716398af1ab22a9bac90835c51 is not paused [marker:invoker_docker.unpause_error:12779:238] [2017-06-15T13:06:31.526Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.rm_start:12781] [2017-06-15T13:06:31.527Z] [INFO] [#sid_102] [SimpleExec] Running command: /usr/bin/docker rm -f wsk0_2_warmJsContainer_20170509T111848942Z [2017-06-15T13:06:31.725Z] [INFO] [#sid_102] [SimpleExec] Done running command: /usr/bin/docker rm -f wsk0_2_warmJsContainer_20170509T111848942Z [2017-06-15T13:06:31.725Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.rm_finish:13007:226] [2017-06-15T13:06:31.732Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.unpause_start:13007] [2017-06-15T13:06:31.737Z] [INFO] [#sid_102] [SimpleExec] Running command: /usr/bin/docker unpause wsk0_1_warmJsContainer_20170509T111848174Z [2017-06-15T13:06:31.862Z] [INFO] [#sid_102] [SimpleExec] Done running command: /usr/bin/docker unpause wsk0_1_warmJsContainer_20170509T111848174Z [2017-06-15T13:06:31.866Z] [ERROR] [#sid_102] [ContainerUtils] stdout: stderr: Error response from daemon: Container cb9e2d5c2d95645f4efbd4cfd16c326f73d4a26fa18a4e4705bc39ce41534532 is not paused [marker:invoker_docker.unpause_error:13141:134] [2017-06-15T13:06:31.868Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.rm_start:13141] [2017-06-15T13:06:31.880Z] [INFO] [#sid_102] [SimpleExec] Running command: /usr/bin/docker rm -f wsk0_1_warmJsContainer_20170509T111848174Z [2017-06-15T13:06:32.065Z] [INFO] [#sid_102] [SimpleExec] Done running command: /usr/bin/docker rm -f wsk0_1_warmJsContainer_20170509T111848174Z [2017-06-15T13:06:32.090Z] [INFO] [#sid_102] [ContainerUtils] [marker:invoker_docker.rm_finish:13344:203] [2017-06-15T13:06:32.094Z] [INFO] [#sid_102] [ContainerPool] killStragglers completed [2017-06-15T13:06:32.887Z] [INFO] [#sid_101] [ContainerPool] Starting warm nodejs container [2017-06-15T13:06:32.937Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.run_start:14181] [2017-06-15T13:06:32.945Z] [INFO] [#sid_101] [SimpleExec] Running command: /usr/bin/docker run -e __OW_API_HOST=https://https://192.168.99.100:443 -e SERVICE_IGNORE=true --name wsk0_1_warmJsContainer_20170615T130632580Z -c 128 -m 256m --memory-swap 256m --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --net openwhisk_default -d openwhisk/nodejs6action:latest [2017-06-15T13:06:34.069Z] [INFO] [#sid_101] [SimpleExec] Done running command: /usr/bin/docker run -e __OW_API_HOST=https://https://192.168.99.100:443 -e SERVICE_IGNORE=true --name wsk0_1_warmJsContainer_20170615T130632580Z -c 128 -m 256m --memory-swap 256m --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --net openwhisk_default -d openwhisk/nodejs6action:latest [2017-06-15T13:06:34.070Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.run_finish:15348:1128] [2017-06-15T13:06:34.213Z] [WARN] [#sid_101] [ContainerPool] Docker operation took 1307 milliseconds [2017-06-15T13:06:34.228Z] [INFO] [#sid_101] [ContainerPool] Started warm nodejs container 1: 788ec76955f15c12d94231096c23ad3f7b23b393562b3f230a75e56fb7dca848 [2017-06-15T13:06:34.390Z] [INFO] [#sid_101] [ContainerPool] Starting warm nodejs container [2017-06-15T13:06:34.409Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.run_start:15672] [2017-06-15T13:06:34.410Z] [INFO] [#sid_101] [SimpleExec] Running command: /usr/bin/docker run -e __OW_API_HOST=https://https://192.168.99.100:443 -e SERVICE_IGNORE=true --name wsk0_2_warmJsContainer_20170615T130634389Z -c 128 -m 256m --memory-swap 256m --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --net openwhisk_default -d openwhisk/nodejs6action:latest [2017-06-15T13:06:35.562Z] [INFO] [#sid_101] [SimpleExec] Done running command: /usr/bin/docker run -e __OW_API_HOST=https://https://192.168.99.100:443 -e SERVICE_IGNORE=true --name wsk0_2_warmJsContainer_20170615T130634389Z -c 128 -m 256m --memory-swap 256m --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --net openwhisk_default -d openwhisk/nodejs6action:latest [2017-06-15T13:06:35.568Z] [INFO] [#sid_101] [ContainerUtils] [marker:invoker_docker.run_finish:16842:1170] [2017-06-15T13:06:35.569Z] [WARN] [#sid_101] [ContainerPool] Docker operation took 1172 milliseconds [2017-06-15T13:06:35.570Z] [INFO] [#sid_101] [ContainerPool] Started warm nodejs container 2: bf9821f61073011c2164366f60d73a067b5cd7cd68a38448faf980f1181dab32 [2017-06-15T13:06:36.764Z] [INFO] Bound to /0.0.0.0:8085 [2017-06-15T13:07:03.699Z] [ERROR] [??] [KafkaProducerConnector] sending message on topic 'health' failed: org.apache.kafka.common.errors.TimeoutException: Batch containing 1 record(s) expired due to timeout while requesting metadata from brokers for health-0 [2017-06-15T13:07:03.702Z] [ERROR] [??] [Invoker] failed to ping the controller: java.util.concurrent.ExecutionException: org.apache.kafka.common.errors.TimeoutException: Batch containing 1 record(s) expired due to timeout while requesting metadata from brokers for health-0 [2017-06-15T13:07:33.788Z] [ERROR] [??] [KafkaProducerConnector] sending message on topic 'health' failed: org.apache.kafka.common.errors.TimeoutException: Batch containing 1 record(s) expired due to timeout while requesting metadata from brokers for health-0 [2017-06-15T13:07:33.790Z] [ERROR] [??] [Invoker] failed to ping the controller: java.util.concurrent.ExecutionException: org.apache.kafka.common.errors.TimeoutException: Batch containing 1 record(s) expired due to timeout while requesting metadata from brokers for health-0 ``` I'm not sure how this can be related to the used docker environment. But on the same Mac using Docker for Mac everything works well. ---------------------------------------------------------------- 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: [email protected]
With regards, Apache Git Services
