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` #### 1. 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] ``` #### 2. 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] ``` #### 3. 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. Note that in this case and previous case the rev is `01002266-0000-0000-0000-5b9b90630000` ``` [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] ``` [ Full content available at: https://github.com/apache/incubator-openwhisk/issues/4024 ] This message was relayed via gitbox.apache.org for [email protected]
