firefly icon indicating copy to clipboard operation
firefly copied to clipboard

Multitenancy E2E Test Intermittent Failure

Open nguyer opened this issue 2 years ago • 0 comments

While running E2E tests, I observed an intermittent failure of TestEthereumMultipartyE2ESuite/TestMultiTenancy

e2e-test (ethereum, evmconnect, TestEthereumMultipartyE2ESuite, postgres, erc20_erc721, true)

For archival purposes, I have attached full log output from the GitHub action run and the container archives as well.

=== RUN   TestEthereumMultipartyE2ESuite/TestMultiTenancy
    common.go:129: Blockchain provider: ethereum
    common.go:153: Client 1: http://127.0.0.1:5000/api/v1
    common.go:154: Client 2: http://127.0.0.1:5001/api/v1
    restclient.go:109: 2023-02-03T20:36:16.671347199Z: ==> GET /namespaces/default/status map[]: null
    restclient.go:116: 2023-02-03T20:36:16.673603331Z: <== 200
    restclient.go:109: 2023-02-03T20:36:16.673631631Z: ==> GET /namespaces/default/status map[]: null
    restclient.go:116: 2023-02-03T20:36:16.675271754Z: <== 200
    restclient.go:109: 2023-02-03T20:36:16.675301454Z: ==> GET /namespaces/default/network/organizations map[sort:[created]]: null
    restclient.go:116: 2023-02-03T20:36:16.676769475Z: <== 200
    restclient.go:109: 2023-02-03T20:36:16.676805275Z: ==> GET /namespaces/default/network/organizations map[sort:[created]]: null
    restclient.go:116: 2023-02-03T20:36:16.678333896Z: <== 200
    restclient.go:109: 2023-02-03T20:36:16.678374397Z: ==> GET /namespaces/default/identities/9ecd991d-7fae-4921-b75b-b10369f0a514/verifiers map[type:[!=dx_peer_id]]: null
    restclient.go:116: 2023-02-03T20:36:16.680325024Z: <== 200
    restclient.go:109: 2023-02-03T20:36:16.680525427Z: ==> GET /namespaces/default/identities/cf31e9e7-7476-44f9-832c-32e08f5e3760/verifiers map[type:[!=dx_peer_id]]: null
    restclient.go:116: 2023-02-03T20:36:16.682360052Z: <== 200
    common.go:181: Org1: ID=9ecd991d-7fae-4921-b75b-b10369f0a514 DID=did:firefly:org/org_707393 Key=0xb88a19f9b8320d7ca0614032a5ff5f63363e1f2e
    common.go:182: Org2: ID=cf31e9e7-7476-44f9-832c-32e08f5e3760 DID=did:firefly:org/org_53d464 Key=0x4430ed9571f37c2eff0229441984424bb1c635fa
    ethereum_contracts.go:106: Contract address: 0x79379a8a59f5e2ffa287bb0935661c624c633158
    multi_tenancy.go:73: Test namespace: e2e_9db0bbd287
    restclient.go:109: 2023-02-03T20:36:17.277131992Z: ==> POST /reset map[]: {}
Websocket 127.0.0.1:5000 closing, error: websocket: close 1006 (abnormal closure): unexpected EOF
    restclient.go:116: 2023-02-03T20:36:17.297993081Z: <== 204
    restclient.go:109: 2023-02-03T20:36:17.298055382Z: ==> POST /reset map[]: {}
    restclient.go:116: 2023-02-03T20:36:17.299925708Z: <== 204
    restclient.go:109: 2023-02-03T20:36:17.299983409Z: ==> GET /namespaces/e2e_9db0bbd287-A/status map[]: null
Websocket 127.0.0.1:5001 closing, error: websocket: close 1006 (abnormal closure): unexpected EOF
    restclient.go:109: 2023-02-03T20:36:22.30543512Z: ==> GET /namespaces/e2e_9db0bbd287-A/status map[]: null
    restclient.go:116: 2023-02-03T20:36:22.308218359Z: <== 200
    restclient.go:109: 2023-02-03T20:36:22.30826836Z: ==> GET /namespaces/e2e_9db0bbd287-B/status map[]: null
    restclient.go:116: 2023-02-03T20:36:22.309994584Z: <== 200
    restclient.go:109: 2023-02-03T20:36:22.310036185Z: ==> GET /namespaces/e2e_9db0bbd287-C/status map[]: null
    restclient.go:116: 2023-02-03T20:36:22.312368817Z: <== 200
    restclient.go:109: 2023-02-03T20:36:22.314957254Z: ==> POST /namespaces/e2e_9db0bbd287-A/network/organizations/self map[confirm:[true]]: {}
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-A/message_confirmed/7dfada18-5bc9-433e-98c2-0d9f0ef5078b -> 37bdbe19-f7c4-4782-8b0c-4f5f41832dd3 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:24.656851427Z: <== 200
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-B/message_confirmed/c42da160-cc8c-4f6a-9fb5-24b886ff7910 -> 37bdbe19-f7c4-4782-8b0c-4f5f41832dd3 (tx=%!s(*core.Transaction=<nil>))
    e2e.go:149: Detected 'message_confirmed' event for message '37bdbe19-f7c4-4782-8b0c-4f5f41832dd3' of type 'definition'
    restclient.go:109: 2023-02-03T20:36:24.96409964Z: ==> POST /namespaces/e2e_9db0bbd287-A/network/nodes/self map[confirm:[true]]: {}
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/2accaeab-ca8a-471b-b034-cdb59efd3e72 -> 37bdbe19-f7c4-4782-8b0c-4f5f41832dd3 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-A/message_confirmed/95c8878c-4fe0-4406-8652-803a88ac8b87 -> 27897f5d-e0d4-471b-b0ed-8447b99c7f88 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:26.651969174Z: <== 200
    restclient.go:109: 2023-02-03T20:36:26.652041075Z: ==> POST /namespaces/e2e_9db0bbd287-B/network/nodes/self map[confirm:[true]]: {}
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-B/message_confirmed/85f1bb29-3b9d-4eb2-a582-5b6501ce3051 -> 27897f5d-e0d4-471b-b0ed-8447b99c7f88 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/330c57cc-4c4d-47dd-b7eb-c71ed7c7e610 -> 27897f5d-e0d4-471b-b0ed-8447b99c7f88 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-B/message_confirmed/23fc2eac-01e8-4f7f-80bb-60913dc91049 -> 2dda0eec-1ddd-4964-a8e0-1639d7a48de7 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:28.653854634Z: <== 200
    restclient.go:109: 2023-02-03T20:36:28.653922935Z: ==> POST /namespaces/e2e_9db0bbd287-C/network/organizations/self map[confirm:[true]]: {}
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-A/message_confirmed/445551cb-ea06-4e74-97fd-8a8e537b07e8 -> 2dda0eec-1ddd-4964-a8e0-1639d7a48de7 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/b29d672d-30af-4531-8f2d-c6e346f16ecd -> 2dda0eec-1ddd-4964-a8e0-1639d7a48de7 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/ad8cffca-1c28-4854-a03d-e45373ea6980 -> f6775b35-f502-4b53-849e-672d7ab27130 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:30.702993161Z: <== 200
    restclient.go:109: 2023-02-03T20:36:30.703061862Z: ==> POST /namespaces/e2e_9db0bbd287-C/network/nodes/self map[confirm:[true]]: {}
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-A/message_confirmed/7aeab71a-87fb-47f6-b5ad-d379da66a76e -> f6775b35-f502-4b53-849e-672d7ab27130 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-B/message_confirmed/0a8e0a6b-3a0d-4d71-9564-8d9a6348aede -> f6775b35-f502-4b53-849e-672d7ab27130 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:32.708131567Z: <== 200
    restclient.go:109: 2023-02-03T20:36:32.708212068Z: ==> POST /namespaces/e2e_9db0bbd287-A/messages/broadcast map[confirm:[false]]: {"header":{"type":"","topics":["topic"]},"data":[{"value":"test"}]}
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/59a0f592-8ba8-43b1-bb80-e334774d40b8 -> 6030145b-b874-4558-b18c-7cedca1ad9a0 (tx=%!s(*core.Transaction=<nil>))
    restclient.go:116: 2023-02-03T20:36:32.713742046Z: <== 202
    restclient.go:331: Sent broadcast msg: f2e497d7-c60f-47e8-9f63-ef174d690888
    e2e.go:152: Ignored event '7dfada18-5bc9-433e-98c2-0d9f0ef5078b'
    e2e.go:152: Ignored event '95c8878c-4fe0-4406-8652-803a88ac8b87'
    e2e.go:152: Ignored event '445551cb-ea06-4e74-97fd-8a8e537b07e8'
    e2e.go:152: Ignored event '7aeab71a-87fb-47f6-b5ad-d379da66a76e'
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-A/message_confirmed/e174087d-1bed-4237-b8e1-d71fe08bf165 -> f2e497d7-c60f-47e8-9f63-ef174d690888 (tx=%!s(*core.Transaction=<nil>))
    e2e.go:149: Detected 'message_confirmed' event for message 'f2e497d7-c60f-47e8-9f63-ef174d690888' of type 'broadcast'
    e2e.go:152: Ignored event '85f1bb29-3b9d-4eb2-a582-5b6501ce3051'
    e2e.go:152: Ignored event '23fc2eac-01e8-4f7f-80bb-60913dc91049'
    e2e.go:152: Ignored event '0a8e0a6b-3a0d-4d71-9564-8d9a6348aede'
Websocket 127.0.0.1:5001 event: e2e_9db0bbd287-C/message_confirmed/3f23b03a-2502-450a-9199-ebe73f2eed32 -> f2e497d7-c60f-47e8-9f63-ef174d690888 (tx=%!s(*core.Transaction=<nil>))
Websocket 127.0.0.1:5000 event: e2e_9db0bbd287-B/message_confirmed/d9cfe16a-1187-4ea9-8841-a8ca955b0d45 -> f2e497d7-c60f-47e8-9f63-ef174d690888 (tx=%!s(*core.Transaction=<nil>))
    e2e.go:149: Detected 'message_confirmed' event for message 'f2e497d7-c60f-47e8-9f63-ef174d690888' of type 'broadcast'
    e2e.go:152: Ignored event '2accaeab-ca8a-471b-b034-cdb59efd3e72'
    e2e.go:152: Ignored event '330c57cc-4c4d-47dd-b7eb-c71ed7c7e610'
    e2e.go:152: Ignored event 'b29d672d-30af-4531-8f2d-c6e346f16ecd'
    e2e.go:152: Ignored event 'ad8cffca-1c28-4854-a03d-e45373ea6980'
    e2e.go:152: Ignored event '59a0f592-8ba8-43b1-bb80-e334774d40b8'
    e2e.go:149: Detected 'message_confirmed' event for message 'f2e497d7-c60f-47e8-9f63-ef174d690888' of type 'broadcast'
    restclient.go:109: 2023-02-03T20:36:37.281426707Z: ==> POST /namespaces/e2e_9db0bbd287-A/messages/private map[confirm:[false]]: {"header":{"type":"","txtype":"batch_pin","topics":["topic"],"tag":"tag1"},"data":[{"value":"test"}],"group":{"name":"test_1675456576671308099","members":[{"identity":"org_53d464","node":"did:firefly:node/charlie"}]}}
    restclient.go:116: 2023-02-03T20:36:37.[2853](https://github.com/hyperledger/firefly/actions/runs/4087653438/jobs/7048465897#step:6:2854)44463Z: <== 400
    restclient.go:118: <!! {"error":"FF10224: Node with name or identity 'did:firefly:node/charlie' not found"}
    restclient.go:119: Headers: map[Content-Length:[85] Content-Type:[application/json] Date:[Fri, 03 Feb 2023 20:36:37 GMT] Vary:[Origin]]
    restclient.go:499: Sent private message  to [{Identity:org_53d464 Node:did:firefly:node/charlie}]
    multi_tenancy.go:162: 
        	Error Trace:	/home/runner/work/firefly/firefly/test/e2e/runners/multi_tenancy.go:162
        	Error:      	Not equal: 
        	            	expected: 202
        	            	actual  : 400
        	Test:       	TestEthereumMultipartyE2ESuite/TestMultiTenancy

logs_6242.zip container-logs-TestEthereumMultipartyE2ESuite--evmconnect-postgres-erc20_erc721 (1).zip

nguyer avatar Feb 03 '23 21:02 nguyer