chetanmeh commented on issue #4024: Intermittent failure in WskRuleTests with multiple controllers URL: https://github.com/apache/incubator-openwhisk/issues/4024#issuecomment-422026359 What is happening here is that test creates 2 triggers and 2 actions first. Then it creates 4 rules r2to2a, r2to2b etc such that each trigger gets linked to 2 action. Then test asserts that upon trigger activation there are 2 linked activations for 2 actions. However in some cases it finds only 1 activation. Upon checking logs following sequence happens for trigger `t1to1b-1536921699040` #### Create trigger Trigger gets created on Controller at 10.66.20.28 ``` [2018-09-14T10:41:39.470Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] PUT /api/v1/namespaces/_/triggers/t1to1b-1536921699040 [2018-09-14T10:41:39.470Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [BasicAuthenticationDirective] authenticate: 2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433 [2018-09-14T10:41:39.470Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [Identity] [GET] serving from cache: CacheKey(2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433) [marker:database_cacheHit_count:0] [2018-09-14T10:41:39.471Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [WhiskTrigger] [GET] serving from datastore: CacheKey(guest/t1to1b-1536921699040) [marker:database_cacheMiss_count:1] [2018-09-14T10:41:39.471Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [CosmosDBArtifactStore] [GET] 'whisks' finding document: 'id: guest/t1to1b-1536921699040' [marker:database_getDocument_start:1] [2018-09-14T10:41:39.478Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [CosmosDBArtifactStore] [marker:database_getDocument_finish:8:7] [2018-09-14T10:41:39.478Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [WhiskTrigger] invalidating CacheKey(guest/t1to1b-1536921699040) [2018-09-14T10:41:39.478Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [WhiskTrigger] write initiated on new cache entry [2018-09-14T10:41:39.478Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [CosmosDBArtifactStore] [PUT] 'whisks' saving document: 'id: guest|t1to1b-1536921699040, rev: null' [marker:database_saveDocument_start:8] [2018-09-14T10:41:39.489Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [CosmosDBArtifactStore] [marker:database_saveDocument_finish:19:11] [2018-09-14T10:41:39.489Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [WhiskTrigger] write all done, caching CacheKey(guest/t1to1b-1536921699040) Cached [2018-09-14T10:41:39.490Z] [INFO] [#tid_cbyZDmV5qhHEld2shjmruoW3SAEcR54Q] [BasicHttpService] [marker:http_put.200_count:19:19] ``` #### Rule r2to2c updates the trigger r2to2c rule creation lead to trigger getting updated on Controller at ip 10.66.20.84 ``` [2018-09-14T10:41:40.809Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] PUT /api/v1/namespaces/_/rules/r2to2c [2018-09-14T10:41:40.810Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [BasicAuthenticationDirective] authenticate: 2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433 [2018-09-14T10:41:40.810Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [Identity] [GET] serving from cache: CacheKey(2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433) [marker:database_cacheHit_count:1] [2018-09-14T10:41:40.810Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [GET] 'whisks' finding document: 'id: guest/r2to2c' [marker:database_getDocument_start:1] [2018-09-14T10:41:40.817Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [marker:database_getDocument_finish:8:6] [2018-09-14T10:41:40.817Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [WhiskTrigger] [GET] serving from datastore: CacheKey(guest/t1to1b-1536921699040) [marker:database_cacheMiss_count:8] [2018-09-14T10:41:40.817Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [GET] 'whisks' finding document: 'id: guest/t1to1b-1536921699040' [marker:database_getDocument_start:8] [2018-09-14T10:41:40.821Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [marker:database_getDocument_finish:12:4] [2018-09-14T10:41:40.821Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [WhiskActionMetaData] [GET] serving from cache: CacheKey(guest/a1to1a-1536921699040) [marker:database_cacheHit_count:12] [2018-09-14T10:41:40.821Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [WhiskTrigger] write initiated on existing cache entry, invalidating CacheKey(guest/t1to1b-1536921699040), tid usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj, state WriteInProgress [2018-09-14T10:41:40.821Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [PUT] 'whisks' saving document: 'id: guest|t1to1b-1536921699040, rev: "01002266-0000-0000-0000-5b9b90630000"' [marker:database_saveDocument_start:12] [2018-09-14T10:41:40.833Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [marker:database_saveDocument_finish:24:12] [2018-09-14T10:41:40.833Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [WhiskTrigger] write all done, caching CacheKey(guest/t1to1b-1536921699040) Cached [2018-09-14T10:41:40.833Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [PUT] 'whisks' saving document: 'id: guest|r2to2c, rev: null' [marker:database_saveDocument_start:24] [2018-09-14T10:41:40.843Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [CosmosDBArtifactStore] [marker:database_saveDocument_finish:34:10] [2018-09-14T10:41:40.843Z] [INFO] [#tid_usZszyKeMJcEETfTuWOtKY8ItmvPo1Kj] [BasicHttpService] [marker:http_put.200_count:34:34] ``` #### r2to2d fails to update the trigger due to conflict When rule r2to2d tries to update the same trigger on Controller at ip 10.66.20.28 then it ends in a conflict ``` [2018-09-14T10:41:41.111Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] PUT /api/v1/namespaces/_/rules/r2to2d [2018-09-14T10:41:41.111Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [BasicAuthenticationDirective] authenticate: 2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433 [2018-09-14T10:41:41.111Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [Identity] [GET] serving from cache: CacheKey(2ed4ad48-9212-4ebc-a7fb-d7a9b61d4433) [marker:database_cacheHit_count:0] [2018-09-14T10:41:41.112Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [CosmosDBArtifactStore] [GET] 'whisks' finding document: 'id: guest/r2to2d' [marker:database_getDocument_start:1] [2018-09-14T10:41:41.119Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [CosmosDBArtifactStore] [marker:database_getDocument_finish:7:6] [2018-09-14T10:41:41.119Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [WhiskTrigger] [GET] serving from cache: CacheKey(guest/t1to1b-1536921699040) [marker:database_cacheHit_count:8] [2018-09-14T10:41:41.119Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [WhiskActionMetaData] [GET] serving from cache: CacheKey(guest/a1to1b-1536921699040) [marker:database_cacheHit_count:8] [2018-09-14T10:41:41.119Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [WhiskTrigger] write initiated on existing cache entry, invalidating CacheKey(guest/t1to1b-1536921699040), tid PCZdOzzF76jZmykwB58XlwRdmgcsmeZa, state WriteInProgress [2018-09-14T10:41:41.119Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [CosmosDBArtifactStore] [PUT] 'whisks' saving document: 'id: guest|t1to1b-1536921699040, rev: "01002266-0000-0000-0000-5b9b90630000"' [marker:database_saveDocument_start:8] [2018-09-14T10:41:41.128Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [CosmosDBArtifactStore] [marker:database_saveDocument_finish:17:9] [2018-09-14T10:41:41.128Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [WhiskTrigger] invalidating CacheKey(guest/t1to1b-1536921699040) [2018-09-14T10:41:41.129Z] [INFO] [#tid_PCZdOzzF76jZmykwB58XlwRdmgcsmeZa] [BasicHttpService] [marker:http_put.409_count:18:18] ```
---------------------------------------------------------------- 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
