Functional test failing, but github job doesn't fail
Describe the bug
When tests are failing in the test step of the functional_tests_at_onboarding_cli job defined in at_libraries.yaml, the overall job does not fail and so the test failures are not flagged on the PR
Steps to reproduce
See https://github.com/atsign-foundation/at_libraries/actions/runs/9191223708/job/25277175158 for example. Noticed in the course of working on https://github.com/atsign-foundation/at_libraries/pull/582
Expected behavior
If the tests fail then the job should fail
@gkc were you able to get the tests to fail (in the same way locally)?
I'm trying to replicate, and it seems the tests are running OK against trunk.
I fixed the tests last week. I'll make a branch for you and add a deliberately failing test
@gkc I've gone back to #0805d1c which is where things were when that GitHub Actions job ran, and the tests pass locally for me, but there's no sign of any attempt to run enrollment_test.dart, which is where the failure happened.
Building package executable... (8.1s)
Built test:test.
00:06 +0: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:11:53.647253|AtLookup|Creating new connection
INFO|2024-05-29 11:11:53.726525|AtLookup|New connection created OK
INFO|2024-05-29 11:11:53.739781|AtLookup|from result:data:_eb29f18a-1bc8-4dbf-910c-aff5c8912ce6@aliceđź› :34f3ac6a-67f2-4831-afd1-034075768893
INFO|2024-05-29 11:11:53.763665|AtLookup|auth success
INFO|2024-05-29 11:11:53.791702|OutboundConnectionImpl|close(): calling socket.destroy() on connection to InternetAddress('127.0.0.1', IPv4):25000
INFO|2024-05-29 11:11:53.874004|AtLookup|Creating new connection
INFO|2024-05-29 11:11:53.889748|AtLookup|New connection created OK
INFO|2024-05-29 11:11:53.972647|AtLookup|auth success
INFO|2024-05-29 11:11:53.974994|AtClientManager|setCurrentAtSign called with atSign @aliceđź›
INFO|2024-05-29 11:11:53.975316|AtClientManager|Switching atSigns from null to @aliceđź›
INFO|2024-05-29 11:11:54.004378|HiveBase|commit_log_0a406b4891f14d0fa7a716c9d4baf6c8abc3a84833452ad054a837c2b21cea6a initialized successfully
INFO|2024-05-29 11:11:54.014814|HiveBase|0a406b4891f14d0fa7a716c9d4baf6c8abc3a84833452ad054a837c2b21cea6a initialized successfully
INFO|2024-05-29 11:11:54.019494|AtClientCommitLogCompaction (@aliceđź› )|Starting commit log compaction job running for every 11 minute(s)
INFO|2024-05-29 11:11:54.088317|AtClientManager|setCurrentAtSign complete
00:07 +1: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify update and llookup verbs with authenticated atLookup instance
INFO|2024-05-29 11:11:54.175536|AtLookup|Creating new connection
INFO|2024-05-29 11:11:54.199409|AtLookup|New connection created OK
INFO|2024-05-29 11:11:54.270673|AtLookup|auth success
00:07 +1: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:11:54.270919|AtClientManager|setCurrentAtSign called with atSign @aliceđź›
INFO|2024-05-29 11:11:54.271067|AtClientManager|previous currentAtSign @aliceđź› is same as new atSign @aliceđź› - doing nothing, returning
INFO|2024-05-29 11:11:54.297531|AtLookup|Creating new connection
INFO|2024-05-29 11:11:54.321209|AtLookup|New connection created OK
INFO|2024-05-29 11:11:54.355656|AtLookup|auth success
00:07 +2: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:11:54.381114|AtLookup|Creating new connection
INFO|2024-05-29 11:11:54.399061|AtLookup|New connection created OK
INFO|2024-05-29 11:11:54.409612|AtLookup|from result:data:_6eb1b6f8-6cb2-458e-966a-1a0923ee3386@eveđź› :f026b0c1-42f5-4f0f-845c-d7b477e1488a
INFO|2024-05-29 11:11:54.422706|AtLookup|auth success
INFO|2024-05-29 11:11:54.444686|OutboundConnectionImpl|close(): calling socket.destroy() on connection to InternetAddress('127.0.0.1', IPv4):25010
INFO|2024-05-29 11:11:54.456179|AtLookup|Creating new connection
INFO|2024-05-29 11:11:54.474913|AtLookup|New connection created OK
INFO|2024-05-29 11:11:54.513719|AtLookup|auth success
00:07 +2: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:11:54.513978|AtClientManager|setCurrentAtSign called with atSign @eveđź›
INFO|2024-05-29 11:11:54.514209|AtClientManager|Switching atSigns from @aliceđź› to @eveđź›
00:07 +2: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:11:54.520957|HiveBase|commit_log_52c6e136524062d6def95e9fc56c27438ede6afb6245c5ea76f1c56ccd0778fc initialized successfully
INFO|2024-05-29 11:11:54.533887|HiveBase|52c6e136524062d6def95e9fc56c27438ede6afb6245c5ea76f1c56ccd0778fc initialized successfully
INFO|2024-05-29 11:11:54.534804|AtClientCommitLogCompaction (@eveđź› )|Starting commit log compaction job running for every 11 minute(s)
00:07 +2: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:11:54.535608|AtClientCommitLogCompaction (@aliceđź› )|Stopping commit log compaction job
INFO|2024-05-29 11:11:54.540317|AtClientManager|setCurrentAtSign complete
00:07 +4: test/at_onboarding_cli_test.dart: A group of tests to assert encryption keys persist into local secondary A test to authenticate atSign and verify PKAM keys and encryption keys are updated to local secondary
INFO|2024-05-29 11:11:54.689817|AtLookup|Creating new connection
INFO|2024-05-29 11:11:54.717377|AtLookup|New connection created OK
INFO|2024-05-29 11:11:54.747690|AtLookup|auth success
00:07 +4: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:11:54.748011|AtClientManager|setCurrentAtSign called with atSign @eveđź›
INFO|2024-05-29 11:11:54.748142|AtClientManager|previous currentAtSign @eveđź› is same as new atSign @eveđź› - doing nothing, returning
00:11 +5: test/at_onboarding_cli_test.dart: ... verify atSign is onboarded and .atKeys file is generated successfully Connecting to secondary ...1/50
00:11 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:11:58.839157|AtLookup|Creating new connection
INFO|2024-05-29 11:11:58.854587|AtLookup|New connection created OK
INFO|2024-05-29 11:11:58.866398|OutboundConnectionImpl|close(): calling socket.destroy() on connection to InternetAddress('127.0.0.1', IPv4):25006
INFO|2024-05-29 11:11:58.869358|AtLookup|Creating new connection
INFO|2024-05-29 11:11:58.884224|AtLookup|New connection created OK
INFO|2024-05-29 11:11:58.895588|AtLookup|from result:data:_bc22d7eb-814c-4671-b37f-6795f39d2470@egcovidlabđź› :bc6ef473-dd36-4c55-aaaf-15a7d9dd329a
INFO|2024-05-29 11:11:58.907519|AtLookup|auth success
INFO|2024-05-29 11:11:58.908312|AtAuthServiceImpl|Generating encryption keypair
INFO|2024-05-29 11:11:59.446104|AtAuthServiceImpl|[Information] Generating your encryption keys and .atKeys file
INFO|2024-05-29 11:11:59.446255|AtAuthServiceImpl|Generating pkam keypair
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.308501|AtLookup|Creating new connection
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.317151|OutboundConnectionImpl|close(): calling socket.destroy() on connection to InternetAddress('127.0.0.1', IPv4):25006
INFO|2024-05-29 11:12:00.317557|AtLookup|Creating new connection
INFO|2024-05-29 11:12:00.322555|AtLookup|New connection created OK
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.324594|AtLookup|New connection created OK
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.349569|AtLookup|auth success
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.355601|AtLookup|auth success
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.360774|AtAuthServiceImpl|Encryption public key update result data:2
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.366832|SyncService (@eveđź› )|148192220|Returning serverCommitId 2
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.377571|AtAuthServiceImpl|Cram secret delete response : data:-1
[Success] Your .atKeys file saved at /home/chris/.atsign/keys/@egcovidlabđź› _key.atKeys
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:12:00.387351|AtClientManager|setCurrentAtSign called with atSign @egcovidlabđź›
INFO|2024-05-29 11:12:00.387541|AtClientManager|Switching atSigns from @eveđź› to @egcovidlabđź›
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.388470|SyncService (@eveđź› )|148192220|Returning serverCommitId 2
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.395961|HiveBase|commit_log_62d8a53cdc86e1329b338fc2868d51fc3a39bf99c3a89ccf7fd20b15e30ef9dc initialized successfully
INFO|2024-05-29 11:12:00.400047|HiveBase|62d8a53cdc86e1329b338fc2868d51fc3a39bf99c3a89ccf7fd20b15e30ef9dc initialized successfully
INFO|2024-05-29 11:12:00.400367|AtClientCommitLogCompaction (@egcovidlabđź› )|Starting commit log compaction job running for every 11 minute(s)
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
INFO|2024-05-29 11:12:00.400695|AtClientCommitLogCompaction (@eveđź› )|Stopping commit log compaction job
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to verify authentication is successful with .atKeys file
INFO|2024-05-29 11:12:00.401497|AtClientManager|setCurrentAtSign complete
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to assert on authenticate functionality A test to authenticate and atSign and invoke AtClient put and get methods
SEVERE|2024-05-29 11:12:00.446526|SyncService (@eveđź› )|Exception in sync f7b820b3-cb66-4a30-9813-5028131d4617. Reason: Failed to syncData caused by
local:lastreceivedservercommitid@eveđź› is not a valid key
00:13 +5: test/at_onboarding_cli_test.dart: A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully
INFO|2024-05-29 11:12:00.453845|AtLookup|Creating new connection
INFO|2024-05-29 11:12:00.469436|AtLookup|New connection created OK
INFO|2024-05-29 11:12:00.492617|OutboundConnectionImpl|close(): calling socket.destroy() on connection to InternetAddress('127.0.0.1', IPv4):25006
00:13 +6: test/at_onboarding_cli_test.dart: ... atSign is activated and .atKeys file is generated using activate_cli [Information] Root server is vip.ve.atsign.zone
[Information] Registrar url provided is my.atsign.com
[Information] Activating your atSign. This may take up to 2 minutes.
00:17 +6: test/at_onboarding_cli_test.dart: ... atSign is activated and .atKeys file is generated using activate_cli Connecting to secondary ...1/50
00:18 +6: test/at_onboarding_cli_test.dart: ... atSign is activated and .atKeys file is generated using activate_cli [Success] Your .atKeys file saved at /home/chris/.atsign/keys/@muraliđź› _key.atKeys
@gkc running these locally I get a 0 exit code despite tests failing
So this is a dart test thing rather than a GitHub Actions thing
Carrying 2SP into PR89 as @gkc wants to do a little more testing before we open a ticket with the Dart team.
@gkc I think we have an answer at https://github.com/dart-lang/test/issues/2248#issuecomment-2216278541
Looks like this is happening when we hit an exit(0) during a test.
We now have some head scratching to do in order to figure out correct behaviour under test versus in production (whilst the VM team do the same for the more general case of exit handling).
Aha! Yes
Evidence here that our test pack as whole will now, correctly, fail if there is any individual test failure.