Closed Samyoul closed 7 months ago
Analysis from @andremedeiro shows that fail is here
https://github.com/status-im/status-go/blob/develop/peers/peerpool_test.go#L513
Error log
[2020-06-18T07:40:31.467Z] === RUN TestPeerPoolSimulationSuite
[2020-06-18T07:40:31.467Z] === RUN TestPeerPoolSimulationSuite/TestMailServerPeersDiscovery
[2020-06-18T07:40:31.467Z] --- FAIL: TestPeerPoolSimulationSuite (1.07s)
[2020-06-18T07:40:31.467Z] --- FAIL: TestPeerPoolSimulationSuite/TestMailServerPeersDiscovery (1.06s)
[2020-06-18T07:40:31.467Z] suite.go:63: test panicked: runtime error: index out of range [0] with length 0
[2020-06-18T07:40:31.467Z] goroutine 146 [running]:
[2020-06-18T07:40:31.467Z] runtime/debug.Stack(0xc004b715d8, 0x10078c0, 0xc00369ad20)
[2020-06-18T07:40:31.467Z] /usr/local/go/src/runtime/debug/stack.go:24 +0x9d
[2020-06-18T07:40:31.467Z] github.com/stretchr/testify/suite.failOnPanic(0xc00026e200)
[2020-06-18T07:40:31.467Z] /home/jenkins/workspace/status-go_prs_tests_PR-1992/pkg/mod/github.com/stretchr/testify@v1.5.1/suite/suite.go:63 +0x57
[2020-06-18T07:40:31.467Z] panic(0x10078c0, 0xc00369ad20)
[2020-06-18T07:40:31.467Z] /usr/local/go/src/runtime/panic.go:679 +0x1b2
[2020-06-18T07:40:31.467Z] github.com/status-im/status-go/peers.(*PeerPoolSimulationSuite).TestMailServerPeersDiscovery(0xc000383500)
[2020-06-18T07:40:31.467Z] /home/jenkins/workspace/status-go_prs_tests_PR-1992/src/github.com/status-im/status-go/peers/peerpool_test.go:513 +0x1459
[2020-06-18T07:40:31.467Z] reflect.Value.call(0xc0000bfb00, 0xc000010fe0, 0x13, 0x10a267f, 0x4, 0xc0000f3ef8, 0x1, 0x1, 0xc0000f3d08, 0x41afda, ...)
[2020-06-18T07:40:31.467Z] /usr/local/go/src/reflect/value.go:460 +0x5f6
[2020-06-18T07:40:31.467Z] reflect.Value.Call(0xc0000bfb00, 0xc000010fe0, 0x13, 0xc0000f3ef8, 0x1, 0x1, 0x349, 0x349014f7b08, 0xfa)
[2020-06-18T07:40:31.467Z] /usr/local/go/src/reflect/value.go:321 +0xb4
[2020-06-18T07:40:31.467Z] github.com/stretchr/testify/suite.Run.func2(0xc00026e200)
[2020-06-18T07:40:31.467Z] /home/jenkins/workspace/status-go_prs_tests_PR-1992/pkg/mod/github.com/stretchr/testify@v1.5.1/suite/suite.go:137 +0x36b
[2020-06-18T07:40:31.467Z] testing.tRunner(0xc00026e200, 0xc000100680)
[2020-06-18T07:40:31.467Z] /usr/local/go/src/testing/testing.go:909 +0xc9
[2020-06-18T07:40:31.467Z] created by testing.(*T).Run
[2020-06-18T07:40:31.467Z] /usr/local/go/src/testing/testing.go:960 +0x350
[2020-06-18T07:40:31.467Z] FAIL
[2020-06-18T07:40:31.467Z] FAIL github.com/status-im/status-go/peers 1.157s
This test should not be flaky anymore. Some of the tests that are still flaky:
One more test:
[2020-10-07T13:34:40.186Z] --- FAIL: TestShhExtSuite (1.36s)
[2020-10-07T13:34:40.186Z] --- PASS: TestShhExtSuite/TestFailedRequestWithUnknownMailServerPeer (0.49s)
[2020-10-07T13:34:40.186Z] --- FAIL: TestShhExtSuite/TestMultipleRequestMessagesWithoutForce (0.87s)
[2020-10-07T13:34:40.186Z] api_geth_test.go:344:
[2020-10-07T13:34:40.186Z] Error Trace: api_geth_test.go:344
[2020-10-07T13:34:40.186Z] Error: Received unexpected error:
[2020-10-07T13:34:40.186Z] Could not find peer with ID: c498cd582b950c6b265cb4ba58f84309333577bea2c8183138ab7840685aa805
[2020-10-07T13:34:40.186Z] Test: TestShhExtSuite/TestMultipleRequestMessagesWithoutForce
[2020-10-07T13:34:40.186Z] FAIL
[2020-10-07T13:34:40.186Z] FAIL github.com/status-im/status-go/services/shhext 2.197s
Another flaky test I have noticed is:
[2020-10-08T13:30:30.125Z] goroutine 25870 [syscall, 29 minutes]:
[2020-10-08T13:30:30.125Z] github.com/mutecomm/go-sqlcipher._Cfunc_sqlite3_prepare_v2(0x7f453802cfb8, 0x7f4538003540, 0xc0ffffffff, 0xc000010428, 0xc000010430, 0x0)
[2020-10-08T13:30:30.125Z] _cgo_gotypes.go:563 +0x4d
[2020-10-08T13:30:30.125Z] github.com/mutecomm/go-sqlcipher.(*SQLiteConn).prepare.func2(0xc0002e35e0, 0x7f4538003540, 0xc000010428, 0xc000010430, 0x466720)
[2020-10-08T13:30:30.125Z] /home/jenkins/workspace/status-go_prs_tests_PR-2056/pkg/mod/github.com/mutecomm/go-sqlcipher@v0.0.0-20190227152316-55dbde17881f/sqlite3.go:505 +0x168
[2020-10-08T13:30:30.125Z] github.com/mutecomm/go-sqlcipher.(*SQLiteConn).prepare(0xc0002e35e0, 0x1435cc0, 0xc0000b4010, 0xc00052c360, 0x17, 0x0, 0x0, 0x0, 0x0)
[2020-10-08T13:30:30.125Z] /home/jenkins/workspace/status-go_prs_tests_PR-2056/pkg/mod/github.com/mutecomm/go-sqlcipher@v0.0.0-20190227152316-55dbde17881f/sqlite3.go:505 +0x102
[2020-10-08T13:30:30.125Z] github.com/mutecomm/go-sqlcipher.(*SQLiteConn).exec(0xc0002e35e0, 0x1435cc0, 0xc0000b4010, 0xc00052c360, 0x17, 0x1d0b020, 0x0, 0x0, 0x1d0b020, 0xc0006249f0, ...)
[2020-10-08T13:30:30.125Z] /home/jenkins/workspace/status-go_prs_tests_PR-2056/pkg/mod/github.com/mutecomm/go-sqlcipher@v0.0.0-20190227152316-55dbde17881f/sqlite3.go:220 +0xd2
[2020-10-08T13:30:30.125Z] github.com/mutecomm/go-sqlcipher.(*SQLiteConn).Exec(0xc0002e35e0, 0xc00052c360, 0x17, 0x1d0b020, 0x0, 0x0, 0x0, 0x0, 0x0, 0x1)
[2020-10-08T13:30:30.125Z] /home/jenkins/workspace/status-go_prs_tests_PR-2056/pkg/mod/github.com/mutecomm/go-sqlcipher@v0.0.0-20190227152316-55dbde17881f/sqlite3.go:214 +0x131
[2020-10-08T13:30:30.125Z] database/sql.ctxDriverExec(0x1435cc0, 0xc0000b4010, 0x0, 0x0, 0x7f457c08c750, 0xc0002e35e0, 0xc00052c360, 0x17, 0x1d0b020, 0x0, ...)
[2020-10-08T13:30:30.125Z] /usr/local/go/src/database/sql/ctxutil.go:43 +0x157
Seems like sqlcipher hangs sometimes opening the database (that's something we never noticed on production, so might be related to tests only), but not exactly clear what it is. Is seems it might deadlock if multiple threads are re-using the same connection, but that should not be the case, for now I will use a inmemory database for those tests, while other will still use a file.
Another flaky test https://ci.status.im/blue/rest/organizations/jenkins/pipelines/status-go/pipelines/prs/pipelines/tests/branches/PR-2060/runs/2/nodes/73/log/?start=0
--- FAIL: TestERC20Transfers (17.65s)
[2020-10-21T07:59:57.674Z] --- PASS: TestERC20Transfers/TestInRange (8.95s)
[2020-10-21T07:59:57.674Z] --- PASS: TestERC20Transfers/TestInboundEvent (5.14s)
[2020-10-21T07:59:57.674Z] --- FAIL: TestERC20Transfers/TestNoEvents (3.55s)
[2020-10-21T07:59:57.674Z] downloader_test.go:204:
[2020-10-21T07:59:57.674Z] Error Trace: downloader_test.go:204
[2020-10-21T07:59:57.674Z] suite.go:123
[2020-10-21T07:59:57.674Z] Error: Received unexpected error:
[2020-10-21T07:59:57.674Z] failed to estimate gas needed: method handler crashed
[2020-10-21T07:59:57.674Z] Test: TestERC20Transfers/TestNoEvents
and another one:
[2020-10-22T10:42:01.549Z] --- FAIL: TestMessengerPushNotificationSuite (11.51s)
[2020-10-22T10:42:01.549Z] --- PASS: TestMessengerPushNotificationSuite/TestContactCode (0.69s)
[2020-10-22T10:42:01.549Z] --- FAIL: TestMessengerPushNotificationSuite/TestReceivePushNotification (10.82s)
[2020-10-22T10:42:01.549Z] push_notification_test.go:227:
[2020-10-22T10:42:01.549Z] Error Trace: push_notification_test.go:227
[2020-10-22T10:42:01.549Z] Error: Received unexpected error:
[2020-10-22T10:42:01.549Z] info not fetched
[2020-10-22T10:42:01.549Z] Test: TestMessengerPushNotificationSuite/TestReceivePushNotification
[2020-10-22T10:42:01.549Z] FAIL
another one reported:
--- FAIL: TestERC20Transfers (25.93s)
[2020-11-02T10:13:14.984Z] --- PASS: TestERC20Transfers/TestInRange (9.45s)
[2020-11-02T10:13:14.984Z] --- PASS: TestERC20Transfers/TestInboundEvent (5.85s)
[2020-11-02T10:13:14.984Z] --- PASS: TestERC20Transfers/TestNoEvents (5.79s)
[2020-11-02T10:13:14.984Z] --- FAIL: TestERC20Transfers/TestOutboundEvent (4.84s)
[2020-11-02T10:13:14.984Z] downloader_test.go:204:
[2020-11-02T10:13:14.984Z] Error Trace: downloader_test.go:204
[2020-11-02T10:13:14.984Z] suite.go:123
[2020-11-02T10:13:14.984Z] Error: Received unexpected error:
[2020-11-02T10:13:14.984Z] failed to estimate gas needed: method handler crashed
[2020-11-02T10:13:14.984Z] Test: TestERC20Transfers/TestOutboundEvent
And another:
[2020-11-03T19:02:52.017Z] --- SKIP: TestPeerPoolSimulationSuite/TestSingleTopicDiscoveryWithFailoverRendezvous (0.00s)
[2020-11-03T19:02:52.017Z] peerpool_test.go:180: Skipping due to being flaky
[2020-11-03T19:02:52.017Z] --- FAIL: TestPeerPoolSimulationSuite/TestUpdateTopicLimits (0.01s)
[2020-11-03T19:02:52.017Z] peerpool_test.go:91:
[2020-11-03T19:02:52.017Z] Error Trace: peerpool_test.go:91
[2020-11-03T19:02:52.017Z] peerpool_test.go:408
[2020-11-03T19:02:52.017Z] Error: Received unexpected error:
[2020-11-03T19:02:52.017Z] listen udp [::]:36995: bind: address already in use
[2020-11-03T19:02:52.017Z] Test: TestPeerPoolSimulationSuite/TestUpdateTopicLimits
another one:
[2020-12-08T15:25:36.178Z] === RUN TestPeerPoolSimulationSuite/TestPeerPoolCacheEthV5
[2020-12-08T15:25:36.178Z] panic: runtime error: invalid memory address or nil pointer dereference
[2020-12-08T15:25:36.178Z] [signal SIGSEGV: segmentation violation code=0x1 addr=0x20 pc=0x8642ea]
[2020-12-08T15:25:36.178Z]
[2020-12-08T15:25:36.178Z] goroutine 364 [running]:
[2020-12-08T15:25:36.178Z] github.com/ethereum/go-ethereum/p2p/discv5.(*Network).SearchTopic(0x0, 0x10bf368, 0x8, 0xc004e00150, 0xc006fe2720, 0xc004e001c0)
[2020-12-08T15:25:36.178Z] /home/jenkins/workspace/status-go_prs_tests_PR-2093/pkg/mod/github.com/status-im/go-ethereum@v1.9.5-status.9/p2p/discv5/net.go:303 +0x3a
[2020-12-08T15:25:36.178Z] github.com/status-im/status-go/discovery.(*DiscV5).Discover(0xc004deaa00, 0x10bf368, 0x8, 0xc004e00150, 0xc006fe2720, 0xc004e001c0, 0x0, 0x0)
[2020-12-08T15:25:36.178Z] /home/jenkins/workspace/status-go_prs_tests_PR-2093/src/github.com/status-im/status-go/discovery/discv5.go:85 +0x61
[2020-12-08T15:25:36.178Z] github.com/status-im/status-go/peers.(*TopicPool).StartSearch.func1(0xc00674e200, 0xc006fe2720, 0xc004e001c0)
[2020-12-08T15:25:36.178Z] /home/jenkins/workspace/status-go_prs_tests_PR-2093/src/github.com/status-im/status-go/peers/topicpool.go:444 +0x80
[2020-12-08T15:25:36.178Z] created by github.com/status-im/status-go/peers.(*TopicPool).StartSearch
[2020-12-08T15:25:36.178Z] /home/jenkins/workspace/status-go_prs_tests_PR-2093/src/github.com/status-im/status-go/peers/topicpool.go:443 +0x35b
[2020-12-08T15:25:36.178Z] FAIL github.com/status-im/status-go/peers 2.948s
[2020-12-08T15:25:36.178Z] === RUN TestLocalVerifierForNodeIDTypes
[2020-12-08T15:25:36.178Z] --- PASS: TestLocalVerifierForNodeIDTypes (0.00s)
One fix for push notification tests https://github.com/status-im/status-go/pull/2118
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.
Problem
Jenkins unit tests will consistently fail
even if all the tests pass(there was a failing test, I just didn't notice them in the full test log). The tests can be passed mostly by retesting and making no changes to the code.Sample log data
Implementation
Future Steps
be aware if this type of consistent failing is reintroduced.