Warm containers

[marcel-vieira-smartfit]

I need your help, I am running Openwhisk using a Raspberry Pi and I successfully executed the code following this doc: https://medium.com/openwhisk/apache-openwhisk-meets-raspberry-pi-e346e555b56a. But I'm facing a problem, the open whisk does not maintain a warm container and after every execution, the container is removed, and in the subsequent execution, the container is created again. So all execution is like a cold-start.

Have you faced this problem?

Here are the logs:

[2023-05-03T15:18:32.773Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] POST /api/v1/namespaces/guest/actions/hello blocking=true&result=true
[2023-05-03T15:18:32.775Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [BasicAuthenticationDirective] authenticate: 23bc46b1-71f6-4ed5-8c54-816aa4f8c502
[2023-05-03T15:18:32.790Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [Identity] [GET] serving from datastore: CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheMiss_count:18]
[2023-05-03T15:18:32.792Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore] [QUERY] 'whisk_local_subjects' searching 'subjects/identities [marker:database_queryView_start:19]
[2023-05-03T15:18:32.856Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore]  [marker:database_queryView_finish:84:65]
[2023-05-03T15:18:32.864Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [WhiskActionMetaData] [GET] serving from datastore: CacheKey(guest/hello) [marker:database_cacheMiss_count:92]
[2023-05-03T15:18:32.866Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore] [GET] 'whisk_local_whisks' finding document: 'id: guest/hello' [marker:database_getDocument_start:93]
[2023-05-03T15:18:32.886Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore]  [marker:database_getDocument_finish:114:21]
[2023-05-03T15:18:32.890Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ActionsApi]  [marker:controller_blockingActivation_start:118]
[2023-05-03T15:18:32.891Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ActionsApi] action activation id: c17cb8ff4ce545c3bcb8ff4ce595c333 [marker:controller_loadbalancer_start:118]
[2023-05-03T15:18:32.892Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [LeanBalancer] posting topic 'invoker0' with activation id 'c17cb8ff4ce545c3bcb8ff4ce595c333' [marker:controller_kafka_start:118]
[2023-05-03T15:18:32.895Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [LeanBalancer] posted to invoker0[0][-1] [marker:controller_kafka_finish:122:3]
[2023-05-03T15:18:32.897Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ActionsApi]  [marker:controller_loadbalancer_finish:123:5]
[2023-05-03T15:18:32.898Z] [INFO] [#tid_sid_unknown] [InvokerReactive] BBBBBB: maximumContainers: 8, maxPeek: 2000
[2023-05-03T15:18:32.899Z] [INFO] [#tid_sid_unknown] [InvokerReactive] CCCCCC: limitsConfig.max: 500, poolConfig.concurrentPeekFactor: 0.5
[2023-05-03T15:18:32.902Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [InvokerReactive]  [marker:invoker_activation_start:130]
[2023-05-03T15:18:32.905Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [WhiskAction] [GET] serving from datastore: CacheKey(guest/hello) [marker:database_cacheMiss_count:133]
[2023-05-03T15:18:32.907Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore] [GET] 'whisk_local_whisks' finding document: 'id: guest/hello, rev: 1-a6bef2efa78820860a3aabdc873db9cd' [marker:database_getDocument_start:135]
[2023-05-03T15:18:32.957Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [CouchDbRestStore]  [marker:database_getDocument_finish:184:48]
[2023-05-03T15:18:32.963Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [DockerContainer] sending initialization to ContainerId(8a875cd62bfa9fa03c9d389e35eacdbf3afd76d7d6632f28bb8daa811eb3c70b) ContainerAddress(172.17.0.6,8080) [marker:invoker_activationInit_start:190]
[2023-05-03T15:18:32.966Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ContainerPool] containerStart containerState: prewarmed (0 of max 1) action: hello namespace: guest activationId: c17cb8ff4ce545c3bcb8ff4ce595c333 [marker:invoker_containerStart.prewarmed_count:191]
[2023-05-03T15:18:32.968Z] [INFO] [#tid_sid_invokerWarmup] [DockerClientWithFileAccess] running /usr/bin/docker run -d --cpu-shares 256 --memory 256m --memory-swap 256m --network bridge -e __OW_API_HOST=https://172.17.0.1:443 --name wsk0_4_prewarm_nodejs6 --pids-limit 1024 --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --log-driver json-file --env __OW_ALLOW_CONCURRENT=True kpavel/nodejs6action:rpi (timeout: 1 minute) [marker:invoker_docker.run_start:2519738]
[2023-05-03T15:18:34.800Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [DockerContainer] initialization result: ok [marker:invoker_activationInit_finish:2028:1837]
[2023-05-03T15:18:34.803Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [DockerContainer] sending arguments to /guest/hello at ContainerId(8a875cd62bfa9fa03c9d389e35eacdbf3afd76d7d6632f28bb8daa811eb3c70b) ContainerAddress(172.17.0.6,8080) [marker:invoker_activationRun_start:2031]
[2023-05-03T15:18:34.838Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [DockerContainer] running result: ok [marker:invoker_activationRun_finish:2066:33]
[2023-05-03T15:18:34.840Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ContainerProxy]  [marker:invoker_collectLogs_start:2068]
[2023-05-03T15:18:34.845Z] [INFO] [#tid_sid_invokerNanny] [DockerClientWithFileAccess] running /usr/bin/docker rm -f 8a875cd62bfa9fa03c9d389e35eacdbf3afd76d7d6632f28bb8daa811eb3c70b (timeout: 1 minute) [marker:invoker_docker.rm_start:2521614]
[2023-05-03T15:18:34.846Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [InvokerReactive] posted completion of activation c17cb8ff4ce545c3bcb8ff4ce595c333
[2023-05-03T15:18:34.851Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [LeanBalancer] received result ack for 'c17cb8ff4ce545c3bcb8ff4ce595c333'
[2023-05-03T15:18:34.853Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ActionsApi]  [marker:controller_blockingActivation_finish:2080:1962]
[2023-05-03T15:18:34.862Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [BasicHttpService] [marker:http_post.200_count:2090:2090]

You can see after the execution, the docker container is removed. Do you know how to fix that?

[dgrove-oss]

I have seen this pattern before when extracting the logs from the container execution failed:

[2023-05-03T15:18:34.840Z] [INFO] [#tid_f72d562c0b21214b422689041a6d939b] [ContainerProxy]  [marker:invoker_collectLogs_start:2068]
[2023-05-03T15:18:34.845Z] [INFO] [#tid_sid_invokerNanny] [DockerClientWithFileAccess] running /usr/bin/docker rm -f 8a875cd62bfa9fa03c9d389e35eacdbf3afd76d7d6632f28bb8daa811eb3c70b (timeout: 1 minute) [marker:invoker_docker.rm_start:2521614]

[marcel-vieira-smartfit]

But the action returns the desired value. I'm running a simple nodejs action shown above

/**
 * Hello world as an OpenWhisk action.
 */
function main(params) {
    var name = params.name || 'World';
    return {payload:  'Hello, ' + name + '!'};
}

Do you know a way to verify what is going wrong?

[marcel-vieira-smartfit]

One more piece of information, I have configured two prewarm nodejs containers, so when I invoke an action the following steps occur:

1. create a new container of nodejs
2. use one of the existent containers to execute the action
3. delete the container used in Step 2

There is no need to delete the used container. Do you know how to avoid this?

[style95]

As David said above, when the extracting logs failed, the container will be removed as it considers an error happens.

[marcel-vieira-smartfit]

All the logs that I have seen, they do not show any error. Do you know if there is a way to verify why the extracting logs have failed?

[style95]

@marcelfvieira IIRC, the invoker directly accesses the container log in the host path. If the path is not accessible from the inside of the invoker container, I think the error would happen.

[marcel-vieira-smartfit]

Thanks! I will take a look, but for now, I have disabled the collect logs feature and everything started to work as expected