E2E `TestE2EWebhookExchange` failure finding 1 message rather than 2

[peterbroadhurst]

See https://github.com/hyperledger/firefly/runs/4260142246?check_suite_focus=true found in #317

    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"transactions","type":"updated","namespace":"default","id":"21a6d5d6-24f4-40a2-a1c3-600bd7d23fcc"}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"pins","type":"created","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"pins","type":"created","sequence":12}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"transactions","type":"created","namespace":"default","id":"21a6d5d6-24f4-40a2-a1c3-600bd7d23fcc"}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"pins","type":"created","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"pins","type":"created","sequence":12}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"groups","type":"updated","namespace":"default","hash":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c"}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"events","type":"created","namespace":"default","id":"cccdd7ee-930b-48dc-b545-f100edc47fe8","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"pins","type":"updated","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"events","type":"created","namespace":"default","id":"2475e376-0aed-4b22-bf82-b965d05cac80","sequence":12}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"type":"change_notification","change":{"collection":"pins","type":"updated","sequence":12}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"id":"cccdd7ee-930b-48dc-b545-f100edc47fe8","sequence":11,"type":"message_confirmed","namespace":"default","reference":"6c87e722-28e5-4da7-ac81-9280aa84c7ef","created":"2021-11-19T04:11:46.921909611Z","subscription":{"id":"0ac790da-6354-445c-9b45-a418a394d5de","namespace":"default","name":"0ac790da-6354-445c-9b45-a418a394d5de"},"message":{"header":{"id":"6c87e722-28e5-4da7-ac81-9280aa84c7ef","type":"groupinit","txtype":"batch_pin","author":"did:firefly:org/afa61404-9ae8-4dc6-bb8b-6cae530d8c96","key":"0xea19e8069b30bd8eb7ff781ed66fe6e6504a3253","created":"2021-11-19T04:11:37.017276477Z","namespace":"default","group":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c","topics":["150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c"],"tag":"ff_define_group","datahash":"9ce612a290af251b76e193a64890910e97b643275b57c6319c4a6954b4e836ab"},"hash":"b5df39a8719d5fd38035086af1cd11fc5756088b9d9d26148fc27e8388c9d3c6","batch":"99268f18-304d-4b21-8e14-7f805f124b5f","state":"confirmed","confirmed":"2021-11-19T04:11:46.921403018Z","data":[{"id":"11b7ade9-edf7-49f5-9208-58079379c735","hash":"7ebb155904a1e9bfd372fab17581ea5ffc25fd4a6ac806cbad1ece6f29895c84"}],"pins":["224dbc9801ec6aad1254bf48d67041ccd9378ae41c023c1c194cc300e62544fd"]}}
    e2e_test.go:246: Websocket 127.0.0.1:5000 receive: {"id":"2475e376-0aed-4b22-bf82-b965d05cac80","sequence":12,"type":"message_confirmed","namespace":"default","reference":"3d938ac4-b5fb-408c-8c7e-ce71c0887fcd","created":"2021-11-19T04:11:46.926976245Z","subscription":{"id":"0ac790da-6354-445c-9b45-a418a394d5de","namespace":"default","name":"0ac790da-6354-445c-9b45-a418a394d5de"},"message":{"header":{"id":"3d938ac4-b5fb-408c-8c7e-ce71c0887fcd","type":"private","txtype":"batch_pin","author":"did:firefly:org/afa61404-9ae8-4dc6-bb8b-6cae530d8c96","key":"0xea19e8069b30bd8eb7ff781ed66fe6e6504a3253","created":"2021-11-19T04:11:37.017994768Z","namespace":"default","group":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c","topics":["default"],"tag":"myrequest","datahash":"5009462dbbb41502ae942154b38e213764d2de29595641d5d738f29954d87457"},"hash":"6e62ef2f69968f45cecad39dd6939748e44dc4e39b5a07298ff93938062cfae7","batch":"99268f18-304d-4b21-8e14-7f805f124b5f","state":"confirmed","confirmed":"2021-11-19T04:11:46.926432952Z","data":[{"id":"bfba4dea-db4b-4feb-9a89-b9d3a394922d","hash":"44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a"}],"pins":["0e9c029ba39b71ab69ffa713a13d3683700c05d10cfc8ee55a47a4e0951e31b3"]}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"groups","type":"created","namespace":"default","hash":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c"}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"events","type":"created","namespace":"default","id":"60c5fa4e-519d-4b61-befe-97bb3763a1ce","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"id":"60c5fa4e-519d-4b61-befe-97bb3763a1ce","sequence":11,"type":"message_confirmed","namespace":"default","reference":"6c87e722-28e5-4da7-ac81-9280aa84c7ef","created":"2021-11-19T04:11:46.929043317Z","subscription":{"id":"30a95519-9b61-4da2-b93e-02a2e29588d8","namespace":"default","name":"30a95519-9b61-4da2-b93e-02a2e29588d8"},"message":{"header":{"id":"6c87e722-28e5-4da7-ac81-9280aa84c7ef","type":"groupinit","txtype":"batch_pin","author":"did:firefly:org/afa61404-9ae8-4dc6-bb8b-6cae530d8c96","key":"0xea19e8069b30bd8eb7ff781ed66fe6e6504a3253","created":"2021-11-19T04:11:37.017276477Z","namespace":"default","group":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c","topics":["150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c"],"tag":"ff_define_group","datahash":"9ce612a290af251b76e193a64890910e97b643275b57c6319c4a6954b4e836ab"},"hash":"b5df39a8719d5fd38035086af1cd11fc5756088b9d9d26148fc27e8388c9d3c6","batch":"99268f18-304d-4b21-8e14-7f805f124b5f","state":"confirmed","confirmed":"2021-11-19T04:11:46.928516724Z","data":[{"id":"11b7ade9-edf7-49f5-9208-58079379c735","hash":"7ebb155904a1e9bfd372fab17581ea5ffc25fd4a6ac806cbad1ece6f29895c84"}],"pins":["224dbc9801ec6aad1254bf48d67041ccd9378ae41c023c1c194cc300e62544fd"]}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"pins","type":"updated","sequence":11}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"events","type":"created","namespace":"default","id":"a9afdc7a-2cfd-4131-84f9-9d520be6edd3","sequence":12}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"id":"a9afdc7a-2cfd-4131-84f9-9d520be6edd3","sequence":12,"type":"message_confirmed","namespace":"default","reference":"3d938ac4-b5fb-408c-8c7e-ce71c0887fcd","created":"2021-11-19T04:11:46.932768468Z","subscription":{"id":"30a95519-9b61-4da2-b93e-02a2e29588d8","namespace":"default","name":"30a95519-9b61-4da2-b93e-02a2e29588d8"},"message":{"header":{"id":"3d938ac4-b5fb-408c-8c7e-ce71c0887fcd","type":"private","txtype":"batch_pin","author":"did:firefly:org/afa61404-9ae8-4dc6-bb8b-6cae530d8c96","key":"0xea19e8069b30bd8eb7ff781ed66fe6e6504a3253","created":"2021-11-19T04:11:37.017994768Z","namespace":"default","group":"150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c","topics":["default"],"tag":"myrequest","datahash":"5009462dbbb41502ae942154b38e213764d2de29595641d5d738f29954d87457"},"hash":"6e62ef2f69968f45cecad39dd6939748e44dc4e39b5a07298ff93938062cfae7","batch":"99268f18-304d-4b21-8e14-7f805f124b5f","state":"confirmed","confirmed":"2021-11-19T04:11:46.93262217Z","data":[{"id":"bfba4dea-db4b-4feb-9a89-b9d3a394922d","hash":"44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a"}],"pins":["0e9c029ba39b71ab69ffa713a13d3683700c05d10cfc8ee55a47a4e0951e31b3"]}}
    e2e_test.go:246: Websocket 127.0.0.1:5001 receive: {"type":"change_notification","change":{"collection":"pins","type":"updated","sequence":12}}
    restclient.go:58: ==> GET /namespaces/default/messages
    restclient.go:65: <== 200
    e2e_test.go:86: Message 0: {Header:{ID:3d938ac4-b5fb-408c-8c7e-ce71c0887fcd CID: Type:private TxType:batch_pin Identity:{Author:did:firefly:org/afa61404-9ae8-4dc6-bb8b-6cae530d8c96 Key:0xea19e8069b30bd8eb7ff781ed66fe6e6504a3253} Created:2021-11-19T04:11:37.017994768Z Namespace:default Group:150cf2607c363b170bf6d4c9ebef1868c25f0a38e3ab3c69f64d05d90763c60c Topics:default Tag:myrequest DataHash:5009462dbbb41502ae942154b38e213764d2de29595641d5d738f29954d87457} Hash:6e62ef2f69968f45cecad39dd6939748e44dc4e39b5a07298ff93938062cfae7 BatchID:99268f18-304d-4b21-8e14-7f805f124b5f State:confirmed Confirmed:2021-11-19T04:11:46.926432952Z Data:[0xc000036a70] Pins:0e9c029ba39b71ab69ffa713a13d3683700c05d10cfc8ee55a47a4e0951e31b3 Sequence:0}
    e2e_test.go:92: 
        	Error Trace:	e2e_test.go:92
        	            				onchain_offchain_test.go:298
        	Error:      	Not equal: 
        	            	expected: 2
        	            	actual  : 1
        	Test:       	TestEthereumE2ESuite/TestE2EWebhookExchange

[peterbroadhurst]

The failure is here:

firefly/test/e2e/onchain_offchain_test.go

Lines 294 to 298 in 24ce2e7

	<-received1 // request
	<-received2 // request
	<-received1 // reply
	val1 := validateReceivedMessages(suite.testState, suite.testState.client1, fftypes.MessageTypePrivate, fftypes.TransactionTypeBatchPin, 2, 0)

Above in the log output, you can see we have received 4 message_confirmed events, but they are:

• "type":"groupinit"
• "type":"private"
• "type":"groupinit"
• "type":"private"

So the check seems to have popped too early - we've not had the responses back.
Checking whether the logic to filter out the group init and database events is there.