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 2019/08/30 06:58:12 UTC
[GitHub] [openwhisk] pankaj-dahiya commented on issue #4067: [Issue] 100%
reproducible ok: invoked /guest/example,
but the request has not yet finished, with id xxxx
pankaj-dahiya commented on issue #4067: [Issue] 100% reproducible ok: invoked /guest/example, but the request has not yet finished, with id xxxx
URL: https://github.com/apache/openwhisk/issues/4067#issuecomment-526483619
same thing happening with me at hello-world function!
I am just running : make quick-start and it ends at last with below error -- >
Installing apimgmt actions
ok: updated action apimgmt/getApi
ok: updated action apimgmt/createApi
ok: updated action apimgmt/deleteApi
waiting for the Whisk invoker to come up ...
... OK
creating the hello.js function ...
invoking the hello-world function ...
adding the function to whisk ...
ok: created action hello
invoking the function ...
ok: invoked /_/hello, but the request has not yet finished, with id 8cc8120fe13640ae88120fe13680ae39
ok: deleted action hello
==> /home/ubuntu/tmp/openwhisk/invoker/logs/invoker-local_logs.log <==
Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap
Listening for transport dt_socket at address: 9222
[2019-08-30T06:44:04.181Z] [INFO] Loaded metric reporter [kamon.statsd.StatsDReporter]
[2019-08-30T06:44:04.181Z] [INFO] Started the Kamon StatsD reporter
[2019-08-30T06:44:05.768Z] [INFO] Slf4jLogger started
[2019-08-30T06:44:09.420Z] [INFO] [#tid_sid_unknown] [Config] environment set value for whisk.api.host.name
[2019-08-30T06:44:09.425Z] [INFO] [#tid_sid_unknown] [Config] environment set value for zookeeper.hosts
[2019-08-30T06:44:09.431Z] [INFO] [#tid_sid_unknown] [Config] environment set value for runtimes.manifest
[2019-08-30T06:44:09.431Z] [INFO] [#tid_sid_unknown] [Config] environment set value for kafka.hosts
[2019-08-30T06:44:09.432Z] [INFO] [#tid_sid_unknown] [Config] environment set value for port
[2019-08-30T06:44:11.297Z] [INFO] [#tid_sid_unknown] [Invoker] Command line arguments parsed to yield CmdLineArgs(None,Some(0),None)
[2019-08-30T06:44:11.299Z] [INFO] [#tid_sid_unknown] [Invoker] invokerReg: using proposedInvokerId 0
[2019-08-30T06:44:11.327Z] [INFO] The configuration was reloaded successfully.
[2019-08-30T06:44:15.012Z] [INFO] [#tid_sid_unknown] [KafkaMessagingProvider] created topic invoker0
[2019-08-30T06:44:15.983Z] [INFO] [#tid_sid_unknown] [InvokerReactive] LogStoreProvider: class org.apache.openwhisk.core.containerpool.logging.DockerToActivationLogStore
[2019-08-30T06:44:18.538Z] [INFO] [#tid_sid_unknown] [DockerClientWithFileAccess] Detected docker client version 18.06.3-ce
[2019-08-30T06:44:18.791Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess] running /usr/bin/docker ps --quiet --no-trunc --all --filter name=wsk0_ (timeout: 1 minute) [marker:invoker_docker.ps_start:9410]
[2019-08-30T06:44:19.495Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess] [marker:invoker_docker.ps_finish:10097:447]
[2019-08-30T06:44:19.688Z] [INFO] [#tid_sid_invoker] [DockerContainerFactory] removing 0 action containers.
[2019-08-30T06:44:24.002Z] [INFO] [#tid_sid_invoker] [CouchDbRestStore] [QUERY] 'local_subjects' searching 'namespaceThrottlings/blockedNamespaces [marker:database_queryView_start:14621]
[2019-08-30T06:44:25.905Z] [ERROR] [#tid_sid_invoker] [CouchDbRestStore] Unexpected http response code: 404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
) [marker:database_queryView_error:16495:1871]
[2019-08-30T06:44:25.911Z] [ERROR] [#tid_sid_unknown] [InvokerReactive] error on updating the blacklist: Unexpected http response code: 404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)
[2019-08-30T06:44:26.037Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 8, pipeline fill at = 8, pipeline depth = 16
[2019-08-30T06:44:26.102Z] [INFO] [#tid_sid_invokerWarmup] [ContainerPool] pre-warming 2 nodejs:6 256 MB
[2019-08-30T06:44:27.257Z] [INFO] [#tid_sid_invokerWarmup] [DockerClientWithFileAccess] running /usr/bin/docker run -d --cpu-shares 256 --memory 256m --memory-swap 256m --network openwhisk_default -e __OW_API_HOST=https://192.168.1.168 --name wsk0_2_prewarm_nodejs6 --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --log-driver json-file openwhisk/nodejs6action:nightly (timeout: 1 minute) [marker:invoker_docker.run_start:17871]
[2019-08-30T06:44:27.324Z] [INFO] [#tid_sid_invokerWarmup] [DockerClientWithFileAccess] running /usr/bin/docker run -d --cpu-shares 256 --memory 256m --memory-swap 256m --network openwhisk_default -e __OW_API_HOST=https://192.168.1.168 --name wsk0_1_prewarm_nodejs6 --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --log-driver json-file openwhisk/nodejs6action:nightly (timeout: 1 minute) [marker:invoker_docker.run_start:17943]
[2019-08-30T06:44:32.543Z] [INFO] [#tid_sid_invokerHealth] [InvokerReactive] [marker:invoker_activation_start:19942]
[2019-08-30T06:44:32.580Z] [WARN] [#tid_sid_invokerHealth] [InvokerReactive] revision was not provided for whisk.system/invokerHealthTestAction0
[2019-08-30T06:44:33.069Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/invokerHealthTestAction0' [marker:database_getDocument_start:20472]
[2019-08-30T06:44:33.123Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [marker:database_getDocument_finish:20519:44]
[2019-08-30T06:44:33.640Z] [ERROR] [#tid_sid_invokerHealth] [InvokerReactive] activation event was not sent: java.lang.IllegalStateException: key 'kind' does not exist
[2019-08-30T06:44:33.751Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [PUT] 'local_activations' saving document: 'id: whisk.system/d6efd8219dfe44e8afd8219dfe14e8ff, rev: null' [marker:database_saveDocument_start:21157]
[2019-08-30T06:44:33.763Z] [INFO] [#tid_sid_dbBatcher] [CouchDbRestStore] 'local_activations' saving 1 documents [marker:database_saveDocumentBulk_start:24377]
[2019-08-30T06:44:33.890Z] [INFO] [#tid_sid_invokerHealth] [InvokerReactive] posted completion of activation d6efd8219dfe44e8afd8219dfe14e8ff
[2019-08-30T06:44:34.049Z] [INFO] [#tid_sid_invokerHealth] [InvokerReactive] [marker:invoker_activation_start:21452]
[2019-08-30T06:44:34.049Z] [WARN] [#tid_sid_invokerHealth] [InvokerReactive] revision was not provided for whisk.system/invokerHealthTestAction0
[2019-08-30T06:44:34.050Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/invokerHealthTestAction0' [marker:database_getDocument_start:21452]
[2019-08-30T06:44:34.127Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [marker:database_getDocument_finish:21525:70]
[2019-08-30T06:44:34.138Z] [ERROR] [#tid_sid_invokerHealth] [InvokerReactive] activation event was not sent: java.lang.IllegalStateException: key 'kind' does not exist
[2019-08-30T06:44:34.143Z] [INFO] [#tid_sid_invokerHealth] [CouchDbRestStore] [PUT] 'local_activations' saving document: 'id: whisk.system/57db832f1e9642f79b832f1e9682f726, rev: null' [marker:database_saveDocument_start:21548]
[2019-08-30T06:44:34.170Z] [INFO] [#tid_sid_invokerHealth] [InvokerReactive] posted completion of activation 57db832f1e9642f79b832f1e9682f726
[2019-08-30T06:44:34.275Z] [INFO] [#tid_sid_dbBatcher] [CouchDbRestStore] 'local_activations' saving 1 documents [marker:database_saveDocumentBulk_start:24892]
[2019-08-30T06:44:34.384Z] [ERROR] [#tid_sid_dbBatcher] [CouchDbRestStore] 'local_activations' failed to put documents, http status: '404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)' [marker:database_saveDocumentBulk_error:25000:618]
[2019-08-30T06:44:34.394Z] [ERROR] [#tid_sid_invokerHealth] [ArtifactActivationStore] failed to record activation d6efd8219dfe44e8afd8219dfe14e8ff with error Unexpected http response code: 404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)
[2019-08-30T06:44:34.606Z] [ERROR] [#tid_sid_dbBatcher] [CouchDbRestStore] 'local_activations' failed to put documents, http status: '404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)' [marker:database_saveDocumentBulk_error:25223:331]
[2019-08-30T06:44:34.607Z] [ERROR] [#tid_sid_invokerHealth] [ArtifactActivationStore] failed to record activation 57db832f1e9642f79b832f1e9682f726 with error Unexpected http response code: 404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)
[2019-08-30T06:45:13.642Z] [INFO] [#tid_sid_invokerWarmup] [DockerClientWithFileAccess] [marker:invoker_docker.run_finish:64258:46315]
[2019-08-30T06:45:14.690Z] [INFO] [#tid_sid_invokerWarmup] [DockerClientWithFileAccess] [marker:invoker_docker.run_finish:65309:47432]
[2019-08-30T06:46:58.006Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [InvokerReactive] [marker:invoker_activation_start:201]
[2019-08-30T06:46:58.083Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [WhiskAction] [GET] serving from datastore: CacheKey(guest/hello) [marker:database_cacheMiss_counter:278]
[2019-08-30T06:46:58.084Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: guest/hello, rev: 1-b3bd5509eceab6fa2cc7cb2caf2c2690' [marker:database_getDocument_start:278]
[2019-08-30T06:46:58.194Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [marker:database_getDocument_finish:390:111]
[2019-08-30T06:46:58.297Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [WhiskAction] write initiated on existing cache entry, invalidating CacheKey(guest/hello), tid hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ, state WriteInProgress
[2019-08-30T06:46:58.299Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [WhiskAction] write all done, caching CacheKey(guest/hello) Cached
[2019-08-30T06:46:58.322Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [DockerClientWithFileAccess] running /usr/bin/docker run -d --cpu-shares 256 --memory 256m --memory-swap 256m --network openwhisk_default -e __OW_API_HOST=https://192.168.1.168 --name wsk0_3_guest_hello --cap-drop NET_RAW --cap-drop NET_ADMIN --ulimit nofile=1024:1024 --pids-limit 1024 --log-driver json-file openwhisk/action-nodejs-v10:nightly (timeout: 1 minute) [marker:invoker_docker.run_start:518]
[2019-08-30T06:46:58.325Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ContainerPool] containerStart containerState: cold container: None activations: 1 of max 1 action: hello namespace: guest activationId: 8cc8120fe13640ae88120fe13680ae39 [marker:invoker_containerStart.cold_counter:520]
==> /home/ubuntu/tmp/openwhisk/controller/logs/controller-local_logs.log <==
Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap
Listening for transport dt_socket at address: 9222
[2019-08-30T06:44:06.302Z] [INFO] Slf4jLogger started
[2019-08-30T06:44:06.433Z] [INFO] Starting remoting
[2019-08-30T06:44:07.754Z] [INFO] Remoting started; listening on addresses :[akka.tcp://controller-actor-system@controller:2551]
[2019-08-30T06:44:07.782Z] [INFO] Remoting now listens on addresses: [akka.tcp://controller-actor-system@controller:2551]
[2019-08-30T06:44:07.947Z] [INFO] Cluster Node [akka.tcp://controller-actor-system@controller:2551] - Starting up, Akka version [2.5.22] ...
[2019-08-30T06:44:08.269Z] [INFO] Cluster Node [akka.tcp://controller-actor-system@controller:2551] - Registered cluster JMX MBean [akka:type=Cluster]
[2019-08-30T06:44:08.272Z] [INFO] Cluster Node [akka.tcp://controller-actor-system@controller:2551] - Started up successfully
[2019-08-30T06:44:10.478Z] [INFO] Loaded metric reporter [kamon.statsd.StatsDReporter]
[2019-08-30T06:44:10.477Z] [INFO] Started the Kamon StatsD reporter
[2019-08-30T06:44:12.608Z] [INFO] [#tid_sid_unknown] [Config] environment set value for limits.triggers.fires.perMinute
[2019-08-30T06:44:12.610Z] [INFO] [#tid_sid_unknown] [Config] environment set value for limits.actions.sequence.maxLength
[2019-08-30T06:44:12.613Z] [INFO] [#tid_sid_unknown] [Config] environment set value for limits.actions.invokes.concurrent
[2019-08-30T06:44:12.615Z] [INFO] [#tid_sid_unknown] [Config] environment set value for limits.actions.invokes.perMinute
[2019-08-30T06:44:12.618Z] [INFO] [#tid_sid_unknown] [Config] environment set value for runtimes.manifest
[2019-08-30T06:44:12.620Z] [INFO] [#tid_sid_unknown] [Config] environment set value for kafka.hosts
[2019-08-30T06:44:12.622Z] [INFO] [#tid_sid_unknown] [Config] environment set value for port
[2019-08-30T06:44:16.038Z] [INFO] [#tid_sid_unknown] [KafkaMessagingProvider] created topic completed0
[2019-08-30T06:44:17.385Z] [INFO] [#tid_sid_unknown] [KafkaMessagingProvider] created topic health
[2019-08-30T06:44:18.305Z] [INFO] [#tid_sid_unknown] [KafkaMessagingProvider] created topic cacheInvalidation
[2019-08-30T06:44:19.245Z] [INFO] [#tid_sid_unknown] [KafkaMessagingProvider] created topic events
[2019-08-30T06:44:20.763Z] [INFO] [#tid_sid_controller] [Controller] starting controller instance 0 [marker:controller_startup0_counter:8168]
[2019-08-30T06:44:24.490Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2019-08-30T06:44:25.915Z] [INFO] [#tid_sid_loadbalancer] [ShardingContainerPoolBalancerState] managedFraction = 0.9, blackboxFraction = 0.1
[2019-08-30T06:44:26.380Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2019-08-30T06:44:28.462Z] [INFO] [#tid_sid_loadbalancer] [WhiskAction] [GET] serving from datastore: CacheKey(whisk.system/invokerHealthTestAction0) [marker:database_cacheMiss_counter:15866]
[2019-08-30T06:44:28.719Z] [INFO] [#tid_sid_loadbalancer] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/invokerHealthTestAction0' [marker:database_getDocument_start:16110]
[2019-08-30T06:44:30.408Z] [INFO] [#tid_sid_loadbalancer] [CouchDbRestStore] [marker:database_getDocument_finish:17795:1676]
[2019-08-30T06:44:30.423Z] [INFO] [#tid_sid_loadbalancer] [WhiskAction] invalidating CacheKey(whisk.system/invokerHealthTestAction0)
[2019-08-30T06:44:30.456Z] [INFO] [#tid_sid_loadbalancer] [WhiskAction] write initiated on new cache entry
[2019-08-30T06:44:30.488Z] [INFO] [#tid_sid_loadbalancer] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: whisk.system/invokerHealthTestAction0, rev: null' [marker:database_saveDocument_start:17893]
[2019-08-30T06:44:30.678Z] [INFO] [#tid_sid_loadbalancer] [InvokerPool] test action for invoker health now exists
[2019-08-30T06:44:30.689Z] [ERROR] [#tid_sid_loadbalancer] [CouchDbRestStore] [PUT] 'local_whisks' failed to put document: 'id: whisk.system/invokerHealthTestAction0, rev: null'; http status: '404 Not Found (details: {"error":"not_found","reason":"Database does not exist."}
)' [marker:database_saveDocument_error:18090:193]
[2019-08-30T06:44:30.691Z] [INFO] [#tid_sid_loadbalancer] [WhiskAction] invalidating CacheKey(whisk.system/invokerHealthTestAction0)
[2019-08-30T06:44:31.065Z] [INFO] [#tid_sid_controller] [Controller] loadbalancer initialized: ShardingContainerPoolBalancer
[2019-08-30T06:44:31.082Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2019-08-30T06:44:31.610Z] [INFO] [#tid_sid_controller] [KindRestrictor] all kinds are allowed, the white-list is not specified
[2019-08-30T06:44:32.081Z] [INFO] [#tid_sid_invokerHealth] [InvokerPool] registered a new invoker: invoker0
[2019-08-30T06:44:32.159Z] [INFO] [#tid_sid_invokerHealth] [InvokerActor] invoker0 is unhealthy [marker:loadbalancer_invokerState.unhealthy_counter:19561]
[2019-08-30T06:44:32.177Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] posting topic 'invoker0' with activation id 'd6efd8219dfe44e8afd8219dfe14e8ff' [marker:controller_kafka_start:19581]
[2019-08-30T06:44:32.184Z] [INFO] [#tid_sid_invokerHealth] [InvokerPool] invoker status changed to 0 -> Unhealthy
[2019-08-30T06:44:32.190Z] [INFO] [#tid_sid_loadbalancer] [ShardingContainerPoolBalancerState] loadbalancer invoker status updated. managedInvokers = 1 blackboxInvokers = 1. number of known invokers increased: new = 1, old = 0. details: invoker0: Unhealthy / 1024 MB of 1024 MB.
[2019-08-30T06:44:32.254Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] posted to invoker0[0][0] [marker:controller_kafka_finish:19660:79]
[2019-08-30T06:44:34.010Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] received completion ack for health action on invoker0
[2019-08-30T06:44:34.013Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] posting topic 'invoker0' with activation id '57db832f1e9642f79b832f1e9682f726' [marker:controller_kafka_start:21417]
[2019-08-30T06:44:34.017Z] [INFO] [#tid_sid_invokerHealth] [InvokerActor] invoker0 is up
[2019-08-30T06:44:34.018Z] [INFO] [#tid_sid_invokerHealth] [InvokerPool] invoker status changed to 0 -> Healthy
[2019-08-30T06:44:34.018Z] [INFO] [#tid_sid_loadbalancer] [ShardingContainerPoolBalancerState] loadbalancer invoker status updated. managedInvokers = 1 blackboxInvokers = 1. no update required - number of known invokers unchanged: 1.
[2019-08-30T06:44:34.047Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] posted to invoker0[0][1] [marker:controller_kafka_finish:21453:36]
[2019-08-30T06:44:34.248Z] [INFO] [#tid_sid_invokerHealth] [ShardingContainerPoolBalancer] received completion ack for health action on invoker0
[2019-08-30T06:44:34.613Z] [INFO] [#tid_sid_controller] [ActionsApi] actionSequenceLimit '20'
[2019-08-30T06:45:55.787Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] PUT /api/v1/namespaces/whisk.system/packages/apimgmt overwrite=true
[2019-08-30T06:45:55.836Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:45:55.859Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [Identity] [GET] serving from datastore: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheMiss_counter:71]
[2019-08-30T06:45:55.859Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [QUERY] 'local_subjects' searching 'subjects/identities [marker:database_queryView_start:75]
[2019-08-30T06:45:56.467Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [marker:database_queryView_finish:684:608]
[2019-08-30T06:45:56.677Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [WhiskPackage] [GET] serving from datastore: CacheKey(whisk.system/apimgmt) [marker:database_cacheMiss_counter:893]
[2019-08-30T06:45:56.677Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt' [marker:database_getDocument_start:894]
[2019-08-30T06:45:56.697Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [marker:database_getDocument_finish:915:20]
[2019-08-30T06:45:56.698Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [WhiskPackage] invalidating CacheKey(whisk.system/apimgmt)
[2019-08-30T06:45:56.719Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [WhiskPackage] write initiated on new cache entry
[2019-08-30T06:45:56.722Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: whisk.system/apimgmt, rev: null' [marker:database_saveDocument_start:938]
[2019-08-30T06:45:56.769Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [CouchDbRestStore] [marker:database_saveDocument_finish:987:49]
[2019-08-30T06:45:56.785Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [WhiskPackage] write all done, caching CacheKey(whisk.system/apimgmt) Cached
[2019-08-30T06:45:56.851Z] [INFO] [#tid_OC8jNRQntgfXqHgw2fqhjR0eVepxUFe6] [BasicHttpService] [marker:http_put.200_counter:1069:1069]
[2019-08-30T06:46:22.401Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] GET /api/v1/namespaces/whisk.system/actions/apimgmt/getApi code=false
[2019-08-30T06:46:22.406Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:22.444Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:43]
[2019-08-30T06:46:22.477Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:78]
[2019-08-30T06:46:22.497Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:97]
[2019-08-30T06:46:22.516Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:116]
[2019-08-30T06:46:22.535Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [WhiskActionMetaData] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/getApi) [marker:database_cacheMiss_counter:135]
[2019-08-30T06:46:22.535Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/getApi' [marker:database_getDocument_start:136]
[2019-08-30T06:46:22.552Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [CouchDbRestStore] [marker:database_getDocument_finish:152:16]
[2019-08-30T06:46:22.560Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [WhiskActionMetaData] invalidating CacheKey(whisk.system/apimgmt/getApi)
[2019-08-30T06:46:22.601Z] [INFO] [#tid_i8T5CniPf9lmK2BoqnzVeltQN2N40OVp] [BasicHttpService] [marker:http_get.404_counter:201:201]
[2019-08-30T06:46:22.720Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] PUT /api/v1/namespaces/whisk.system/actions/apimgmt/getApi overwrite=true
[2019-08-30T06:46:22.746Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:22.746Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:26]
[2019-08-30T06:46:22.755Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:36]
[2019-08-30T06:46:23.651Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [WhiskAction] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/getApi) [marker:database_cacheMiss_counter:931]
[2019-08-30T06:46:23.651Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/getApi' [marker:database_getDocument_start:932]
[2019-08-30T06:46:23.658Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [marker:database_getDocument_finish:938:6]
[2019-08-30T06:46:23.658Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [WhiskAction] invalidating CacheKey(whisk.system/apimgmt/getApi)
[2019-08-30T06:46:23.776Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [WhiskAction] write initiated on new cache entry
[2019-08-30T06:46:23.810Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: whisk.system/apimgmt/getApi, rev: null' [marker:database_saveDocument_start:1089]
[2019-08-30T06:46:23.823Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [marker:database_saveDocument_finish:1104:15]
[2019-08-30T06:46:23.824Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [ATT_PUT] 'local_whisks' uploading attachment '243e292f-9508-44ac-be29-2f950894acdc' of document 'id: whisk.system/apimgmt/getApi, rev: 1-5ba92956473f7660d480937c1d1f1ae4' [marker:database_saveDocumentAttachment_start:1105]
[2019-08-30T06:46:24.175Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [CouchDbRestStore] [marker:database_saveDocumentAttachment_finish:1456:351]
[2019-08-30T06:46:24.191Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [WhiskAction] write all done, caching CacheKey(whisk.system/apimgmt/getApi) Cached
[2019-08-30T06:46:24.374Z] [INFO] [#tid_qFJX0E582efJkwnvyk5Qd1U80MTtxURo] [BasicHttpService] [marker:http_put.200_counter:1655:1655]
[2019-08-30T06:46:24.702Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] GET /api/v1/namespaces/whisk.system/actions/apimgmt/createApi code=false
[2019-08-30T06:46:24.708Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:24.710Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:7]
[2019-08-30T06:46:24.712Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:10]
[2019-08-30T06:46:24.713Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:12]
[2019-08-30T06:46:24.715Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:13]
[2019-08-30T06:46:24.717Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [WhiskActionMetaData] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/createApi) [marker:database_cacheMiss_counter:15]
[2019-08-30T06:46:24.717Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/createApi' [marker:database_getDocument_start:15]
[2019-08-30T06:46:24.726Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [CouchDbRestStore] [marker:database_getDocument_finish:25:10]
[2019-08-30T06:46:24.735Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [WhiskActionMetaData] invalidating CacheKey(whisk.system/apimgmt/createApi)
[2019-08-30T06:46:24.735Z] [INFO] [#tid_M6ArZXqnd9T3qx1Qv2Fx4E20ITjobiOT] [BasicHttpService] [marker:http_get.404_counter:29:29]
[2019-08-30T06:46:24.789Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] PUT /api/v1/namespaces/whisk.system/actions/apimgmt/createApi overwrite=true
[2019-08-30T06:46:24.809Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:24.810Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:22]
[2019-08-30T06:46:24.814Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:25]
[2019-08-30T06:46:25.515Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [WhiskAction] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/createApi) [marker:database_cacheMiss_counter:726]
[2019-08-30T06:46:25.515Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/createApi' [marker:database_getDocument_start:726]
[2019-08-30T06:46:25.529Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [marker:database_getDocument_finish:741:15]
[2019-08-30T06:46:25.530Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [WhiskAction] invalidating CacheKey(whisk.system/apimgmt/createApi)
[2019-08-30T06:46:25.595Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [WhiskAction] write initiated on new cache entry
[2019-08-30T06:46:25.606Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: whisk.system/apimgmt/createApi, rev: null' [marker:database_saveDocument_start:818]
[2019-08-30T06:46:25.629Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [marker:database_saveDocument_finish:840:21]
[2019-08-30T06:46:25.629Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [ATT_PUT] 'local_whisks' uploading attachment '921c82a9-452e-4c6d-9c82-a9452eec6ddc' of document 'id: whisk.system/apimgmt/createApi, rev: 1-d150f3049192a7e180a5c2cc5b9d98de' [marker:database_saveDocumentAttachment_start:841]
[2019-08-30T06:46:25.875Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [CouchDbRestStore] [marker:database_saveDocumentAttachment_finish:1086:245]
[2019-08-30T06:46:25.887Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [WhiskAction] write all done, caching CacheKey(whisk.system/apimgmt/createApi) Cached
[2019-08-30T06:46:25.928Z] [INFO] [#tid_DI4NlOlssRswVncXXwQEha0ctmLy5KM7] [BasicHttpService] [marker:http_put.200_counter:1140:1140]
[2019-08-30T06:46:26.113Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] GET /api/v1/namespaces/whisk.system/actions/apimgmt/deleteApi code=false
[2019-08-30T06:46:26.115Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:26.115Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:4]
[2019-08-30T06:46:26.117Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:6]
[2019-08-30T06:46:26.118Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:6]
[2019-08-30T06:46:26.119Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:7]
[2019-08-30T06:46:26.120Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [WhiskActionMetaData] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/deleteApi) [marker:database_cacheMiss_counter:8]
[2019-08-30T06:46:26.120Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/deleteApi' [marker:database_getDocument_start:8]
[2019-08-30T06:46:26.127Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [CouchDbRestStore] [marker:database_getDocument_finish:15:7]
[2019-08-30T06:46:26.127Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [WhiskActionMetaData] invalidating CacheKey(whisk.system/apimgmt/deleteApi)
[2019-08-30T06:46:26.128Z] [INFO] [#tid_GGnLy3m6SRxfXk7v7DlebLQ2ugVj43K0] [BasicHttpService] [marker:http_get.404_counter:17:17]
[2019-08-30T06:46:26.183Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] PUT /api/v1/namespaces/whisk.system/actions/apimgmt/deleteApi overwrite=true
[2019-08-30T06:46:26.196Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [BasicAuthenticationDirective] authenticate: 789c46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:26.197Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [Identity] [GET] serving from cache: CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:13]
[2019-08-30T06:46:26.198Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [WhiskPackage] [GET] serving from cache: CacheKey(whisk.system/apimgmt) [marker:database_cacheHit_counter:15]
[2019-08-30T06:46:26.563Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [WhiskAction] [GET] serving from datastore: CacheKey(whisk.system/apimgmt/deleteApi) [marker:database_cacheMiss_counter:379]
[2019-08-30T06:46:26.657Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: whisk.system/apimgmt/deleteApi' [marker:database_getDocument_start:379]
[2019-08-30T06:46:26.665Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [marker:database_getDocument_finish:481:101]
[2019-08-30T06:46:26.665Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [WhiskAction] invalidating CacheKey(whisk.system/apimgmt/deleteApi)
[2019-08-30T06:46:26.685Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [WhiskAction] write initiated on new cache entry
[2019-08-30T06:46:26.700Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: whisk.system/apimgmt/deleteApi, rev: null' [marker:database_saveDocument_start:509]
[2019-08-30T06:46:26.708Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [marker:database_saveDocument_finish:525:14]
[2019-08-30T06:46:26.708Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [ATT_PUT] 'local_whisks' uploading attachment 'c7a10472-d055-4b72-a104-72d0551b7221' of document 'id: whisk.system/apimgmt/deleteApi, rev: 1-8c4b99dd4b2a26e14da66c128a3c0e6a' [marker:database_saveDocumentAttachment_start:525]
[2019-08-30T06:46:26.857Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [CouchDbRestStore] [marker:database_saveDocumentAttachment_finish:674:149]
[2019-08-30T06:46:26.865Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [WhiskAction] write all done, caching CacheKey(whisk.system/apimgmt/deleteApi) Cached
[2019-08-30T06:46:26.888Z] [INFO] [#tid_ZkvDh69FSYG84cZfNBCQDz7F00WlLqNk] [BasicHttpService] [marker:http_put.200_counter:705:705]
[2019-08-30T06:46:57.524Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] PUT /api/v1/namespaces/_/actions/hello overwrite=false
[2019-08-30T06:46:57.527Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [BasicAuthenticationDirective] authenticate: 23bc46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:57.533Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [Identity] [GET] serving from datastore: CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheMiss_counter:9]
[2019-08-30T06:46:57.534Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [QUERY] 'local_subjects' searching 'subjects/identities [marker:database_queryView_start:10]
[2019-08-30T06:46:57.590Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [marker:database_queryView_finish:66:55]
[2019-08-30T06:46:57.599Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [WhiskAction] [GET] serving from datastore: CacheKey(guest/hello) [marker:database_cacheMiss_counter:75]
[2019-08-30T06:46:57.600Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: guest/hello' [marker:database_getDocument_start:76]
[2019-08-30T06:46:57.617Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [marker:database_getDocument_finish:93:16]
[2019-08-30T06:46:57.618Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [WhiskAction] invalidating CacheKey(guest/hello)
[2019-08-30T06:46:57.618Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [WhiskAction] write initiated on new cache entry
[2019-08-30T06:46:57.638Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [PUT] 'local_whisks' saving document: 'id: guest/hello, rev: null' [marker:database_saveDocument_start:115]
[2019-08-30T06:46:57.658Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [CouchDbRestStore] [marker:database_saveDocument_finish:135:20]
[2019-08-30T06:46:57.659Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [WhiskAction] write all done, caching CacheKey(guest/hello) Cached
[2019-08-30T06:46:57.669Z] [INFO] [#tid_YQCU7OSg0pRRMzIU56KzxpNav9NIqXLn] [BasicHttpService] [marker:http_put.200_counter:143:143]
[2019-08-30T06:46:57.805Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] POST /api/v1/namespaces/_/actions/hello blocking=true&result=true
[2019-08-30T06:46:57.808Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [BasicAuthenticationDirective] authenticate: 23bc46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:46:57.809Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [Identity] [GET] serving from cache: CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:5]
[2019-08-30T06:46:57.926Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [WhiskActionMetaData] [GET] serving from datastore: CacheKey(guest/hello) [marker:database_cacheMiss_counter:121]
[2019-08-30T06:46:57.926Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [GET] 'local_whisks' finding document: 'id: guest/hello' [marker:database_getDocument_start:121]
[2019-08-30T06:46:57.933Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [marker:database_getDocument_finish:129:8]
[2019-08-30T06:46:57.979Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ActionsApi] [marker:controller_blockingActivation_start:175]
[2019-08-30T06:46:57.980Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ActionsApi] action activation id: 8cc8120fe13640ae88120fe13680ae39 [marker:controller_loadbalancer_start:176]
[2019-08-30T06:46:57.984Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ShardingContainerPoolBalancer] scheduled activation 8cc8120fe13640ae88120fe13680ae39, action 'guest/hello@0.0.1' (managed), ns 'guest', mem limit 256 MB (std), time limit 60000 ms (std) to invoker0
[2019-08-30T06:46:57.995Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ShardingContainerPoolBalancer] posting topic 'invoker0' with activation id '8cc8120fe13640ae88120fe13680ae39' [marker:controller_kafka_start:190]
[2019-08-30T06:46:58.009Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ShardingContainerPoolBalancer] posted to invoker0[0][2] [marker:controller_kafka_finish:202:11]
[2019-08-30T06:46:58.009Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ActionsApi] [marker:controller_loadbalancer_finish:203:27]
[2019-08-30T06:47:13.028Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [GET] 'local_activations' finding document: 'id: guest/8cc8120fe13640ae88120fe13680ae39' [marker:database_getDocument_start:15223]
[2019-08-30T06:47:13.298Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [marker:database_getDocument_finish:15494:271]
[2019-08-30T06:47:28.318Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [GET] 'local_activations' finding document: 'id: guest/8cc8120fe13640ae88120fe13680ae39' [marker:database_getDocument_start:30513]
[2019-08-30T06:47:28.356Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [marker:database_getDocument_finish:30550:37]
[2019-08-30T06:47:43.369Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [GET] 'local_activations' finding document: 'id: guest/8cc8120fe13640ae88120fe13680ae39' [marker:database_getDocument_start:45564]
[2019-08-30T06:47:43.397Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [CouchDbRestStore] [marker:database_getDocument_finish:45593:29]
[2019-08-30T06:47:58.029Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [ActionsApi] [marker:controller_blockingActivation_finish:60225:60049]
[2019-08-30T06:47:58.032Z] [INFO] [#tid_hyHYTG0V5QV7yKaDH8YCKfzmIjjZ2rrZ] [BasicHttpService] [marker:http_post.202_counter:60228:60228]
[2019-08-30T06:47:58.154Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] DELETE /api/v1/namespaces/_/actions/hello
[2019-08-30T06:47:58.159Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [BasicAuthenticationDirective] authenticate: 23bc46b1-71f6-4ed5-8c54-816aa4f8c502
[2019-08-30T06:47:58.161Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [Identity] [GET] serving from cache: CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502) [marker:database_cacheHit_counter:7]
[2019-08-30T06:47:58.175Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [WhiskAction] [GET] serving from cache: CacheKey(guest/hello) [marker:database_cacheHit_counter:21]
[2019-08-30T06:47:58.182Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [WhiskAction] invalidating CacheKey(guest/hello) on delete
[2019-08-30T06:47:58.184Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [CouchDbRestStore] [DEL] 'local_whisks' deleting document: 'id: guest/hello, rev: 1-b3bd5509eceab6fa2cc7cb2caf2c2690' [marker:database_deleteDocument_start:31]
[2019-08-30T06:47:58.239Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [CouchDbRestStore] [marker:database_deleteDocument_finish:85:54]
[2019-08-30T06:47:58.240Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [WhiskAction] invalidating CacheKey(guest/hello)
[2019-08-30T06:47:58.261Z] [INFO] [#tid_rxPO2b8PbHqClq52Unb83YU3PJw7JZfZ] [BasicHttpService] [marker:http_delete.200_counter:107:107]
Makefile:379: recipe for target 'hello-world' failed
make: *** [hello-world] Error 1
----------------------------------------------------------------
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