Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Exit code of 0 after a failed test #2248

Open
cpswan opened this issue Jul 1, 2024 · 22 comments
Open

Exit code of 0 after a failed test #2248

cpswan opened this issue Jul 1, 2024 · 22 comments

Comments

@cpswan
Copy link

cpswan commented Jul 1, 2024

Describe the bug in detail.

A test (or tests) fail, but the exit code for the dart test process is 0.

@gkc first noticed this on a GitHub Action run. (Full logs at logs_24055523517.zip.)

test/enrollment_test.dart: A test to verify send enroll request, deny enrollment and auth by enrollmentId should fail (failed)

image

However the job still passed.

This was initially thought to be an issue with GitHub Actions, and @gkc opened atsign-foundation/at_libraries#586 but the behavior has since been replicated locally, so it looks like it's a dart test problem rather than a GitHub Actions problem.

Include the specific command you ran and any relevant details about the
environment, including operating system, Dart SDK version, and the version of
package:test you are using.

dart test --concurrency=1

Dart SDK version: 3.4.1 (stable) (Tue May 21 15:46:25 2024 +0000) on "linux_x64"

+ test 1.25.7
+ test_api 0.7.2
+ test_core 0.6.4

Whenever possible, include a full reproduction example that we can run to
observe the problem.

This will need Docker Compose.

 git clone https://github.com/atsign-foundation/at_libraries.git
 cd at_libraries/
 git checkout tests-testing
 cd tests/at_onboarding_cli_functional_tests/
 echo "127.0.0.1    vip.ve.atsign.zone" | sudo tee -a /etc/hosts
 dart pub get
 sudo docker compose up -d
 dart run check_docker_readiness.dart
 dart test --concurrency=1
 echo $?

@mit-mit this is the thing I mentioned to you last week at I/O Connect, so this is the GitHub issue you asked me to open.

@jakemac53
Copy link
Contributor

Can you create a reproduction case that doesn't require docker?

@jakemac53 jakemac53 added the needs-info Additional information needed from the issue author label Jul 2, 2024
@cpswan
Copy link
Author

cpswan commented Jul 3, 2024

@jakemac53 i don't think we can create a replication for this without docker in a reasonable time frame.

I also suspect that at the heart of this is a bunch of async stuff leading to a race condition, and the docker based services provide a substrate for that to happen.

@github-actions github-actions bot removed the needs-info Additional information needed from the issue author label Jul 3, 2024
@jakemac53
Copy link
Contributor

@cpswan can you provide more of the error logs?

@jakemac53
Copy link
Contributor

Fwiw, I have validated that late async errors in setUp, tearDown, and regular tests all do set the exit code appropriately.

@cpswan
Copy link
Author

cpswan commented Jul 4, 2024

@jacob314 I already attached the full log archive from the original GitHub Actions run where we first spotted this (and the specific log within that archive is 2_functional_tests_at_onboarding_cli (at_onboarding_cli_functional_tests).txt.

What other logs can I get for you?

@jakemac53
Copy link
Contributor

Sorry I missed the logs initially, checking over them now

@jakemac53
Copy link
Contributor

@cpswan I don't see anything obvious, I created a branch of test_core with some extra print statements just to get an idea of what state the runner thinks it is in. If you can run using that link the result that would help to get a start here, you should be able to use it by adding something like this to your pubspec:

dependency_overrides:
  test_api:
    git:
      url: https://github.com/dart-lang/test/
      ref: add-prints
      path: pkgs/test_api
  test_core:
    git:
      url: https://github.com/dart-lang/test/
      ref: add-prints
      path: pkgs/test_core
  test:
    git:
      url: https://github.com/dart-lang/test/
      ref: add-prints
      path: pkgs/test

@jakemac53
Copy link
Contributor

Another thing that might be worth testing, is that dart apps running under docker can in general set exit codes properly, so you could try running this app:

import 'dart:io';

void main() {
  exitCode = 1;
}

@cpswan
Copy link
Author

cpswan commented Jul 8, 2024

@jakemac53 the app in the container (and any exit codes it may set) should be entirely irrelevant, as it's just providing a set of APIs that the tests run against.

As it happens, the stuff in the container is a Dart AOT binary. But we don't expect the container itself to exit, or in any way communicate its exit code (should it have one) into the tests.

I'll have a go at running the extra prints tests.

@jakemac53
Copy link
Contributor

@jakemac53 the app in the container (and any exit codes it may set) should be entirely irrelevant, as it's just providing a set of APIs that the tests run against.

Oh right, you are not running dart test inside the docker environment, it is just talking to it.

@cpswan
Copy link
Author

cpswan commented Jul 8, 2024

@jakemac53

I set dependency overrides per #2248 (comment) and ran dart pub update to get those overrides in place:

! test 1.25.8-wip from git https://github.com/dart-lang/test/ at bd4d55 in pkgs/test (overridden)
! test_api 0.7.3-wip from git https://github.com/dart-lang/test/ at bd4d55 in pkgs/test_api (overridden)
! test_core 0.6.5-wip from git https://github.com/dart-lang/test/ at bd4d55 in pkgs/test_core (overridden)

Here's the output from dart test --concurrency=1

Building package executable...
Built test:test.
00:04 +0 -1: test/at_onboarding_cli_test.dart: Deliberately failing test [E]
  Expected: <true>
    Actual: <false>

  package:matcher                        expect
  test/at_onboarding_cli_test.dart 19:5  main.<fn>


To run this test again: /home/chris/flutter/bin/cache/dart-sdk/bin/dart test test/at_onboarding_cli_test.dart -p vm --plain-name 'Deliberately failing test'
00:10 +5 -1: test/at_onboarding_cli_test.dart: ... atSign is onboarded and .atKeys file is generated successfully      Connecting to secondary ...1/50
00:10 +5 -2: 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 [E]
  Exception: atsign @egcovidlab🛠 is already activated
  package:at_onboarding_cli/src/onboard/at_onboarding_service_impl.dart 106:7  AtOnboardingServiceImpl.onboard
  ===== asynchronous gap ===========================
  test/at_onboarding_cli_test.dart 152:21                                      main.<fn>.<fn>


To run this test again: /home/chris/flutter/bin/cache/dart-sdk/bin/dart test test/at_onboarding_cli_test.dart -p vm --plain-name 'A group of tests to verify onboard functionality A test to verify atSign is onboarded and .atKeys file is generated successfully'
00:10 +5 -2: 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:12 +5 -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
SEVERE|2024-07-08 17:39:20.163869|SyncService (@eve🛠)|Exception in sync 8b7f44f8-34da-41f3-8dbc-0bda91d85645. Reason: Failed to syncData caused by
local:lastreceivedservercommitid@eve🛠 is not a valid key

Connecting to secondary ...1/50
[Error] atsign @murali🛠 is already activated

I'm not noticing any extra prints there.

@jakemac53
Copy link
Contributor

I'm not noticing any extra prints there.

They should appear at the very end of the output of dart test

@cpswan
Copy link
Author

cpswan commented Jul 8, 2024

@jakemac53 whatever happened, those prints weren’t reached, which I guess tells its own story.

@jakemac53
Copy link
Contributor

@jakemac53 whatever happened, those prints weren’t reached, which I guess tells its own story.

That is indeed interesting... is it possible that dart test for you is actually not the real dart test but some other thing, or custom test runner?

The prints I added will only work if using the actual test runner executable, and running test files like dart some_test.dart will not print.

@cpswan
Copy link
Author

cpswan commented Jul 8, 2024

@jakemac53 I don’t think we’re doing anything to make dart test do anything abnormal. No aliases, no custom runners, nothing you don’t see in the repo.

Going back to when we first saw this, it was in a GitHub Actions runner, which guarantees a known clean environment.

@jakemac53
Copy link
Contributor

Is it possible that some of the code under test is calling exit(0)?

@cpswan
Copy link
Author

cpswan commented Jul 8, 2024

@jakemac53 yep, I think that's what's happening. I see a finally block that calls exit(0).

Does this now take us into a question of expected behaviour?

I wouldn't expect an exit(0) from a later test to override unrelated failures from earlier tests. But I'm also painfully aware that such things have been litigated in threads like these before (and not always found their way into more visible documentation).

@natebosch
Copy link
Member

Does this now take us into a question of expected behaviour?

Unfortunately it does.

When you call exit(0) anywhere, the VM will exit immediately. No further tests can run. The test runner cannot do any more work to check test statuses or change the exit code.

As far as I know, there is no way for us to change this, or to warn when it happens. We cannot intercept the exit() or change it's behavior within a zone.

cc @bkonyi - in case I'm overlooking some VM capability.

I wouldn't expect an exit(0) from a later test to override unrelated failures from earlier tests.

It's not so much a behavior of overriding other earlier test failures, as it is that the exit code is no longer in the control of the test runner because the test code is forcing it to 0 with that call.

@natebosch
Copy link
Member

@bkonyi - another idea I just had since we already do hardcode some test knowledge in the SDK and Dart CLI. Do you think it would be feasible (and sensible) to change the behavior of exit() when running dart test? If we know that the test runner won't use that API, we could maybe print a warning when it's used, or disallow exit(0) and force it to act like exit(1) since any exit() call should be considered a test failure.

@bkonyi
Copy link
Contributor

bkonyi commented Jul 19, 2024

Sorry, don't know how I missed this.

I'm not sure that we're going to be willing to change the behavior of exit() for the context of tests. The documentation for exit() is clear that using it will cause the VM to immediately exit and result in state not being cleaned up properly.

Is this something users are encountering frequently? If this is a common issue, it might be something worth investigating, but initial conversations with the VM team haven't been very positive.

@natebosch
Copy link
Member

This comes up infrequently enough that when it does it usually takes us a while to remember what to look for. The main motivation for wanting a change here is this is nasty to debug whenever it does come up. It may have come up again in dart-lang/sdk#56254 which could be a sign that we'll be seeing this more often.

One thing we can do at least is add extra logging like what Jake used behind a --verbose flag which exposes more of the test runner details, and ask users to use that flag when they see a crash.

@bkonyi
Copy link
Contributor

bkonyi commented Jul 24, 2024

This comes up infrequently enough that when it does it usually takes us a while to remember what to look for. The main motivation for wanting a change here is this is nasty to debug whenever it does come up. It may have come up again in dart-lang/sdk#56254 which could be a sign that we'll be seeing this more often.

I've got a CL up for review to add IOOverrides support for exit(...).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants