Sitelet https://github.com/nodejs/node/issues/46478
Skip to content

Built-in test module only report ouput of the first top level describe #46478

Description

@piranna

Version

v19.4.0

Platform

Linux AVRAST1790 5.19.0-30-generic #31-Ubuntu SMP PREEMPT_DYNAMIC Fri Jan 6 15:40:20 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

test

What steps will reproduce the bug?

On a test file with multiple top level describe, report output only show the first one of them that got run. Any other describe gets no reported nor counted, both passing or failing. In fact, final report don't provide correct statistics at all:

TAP version 13
# Subtest: /home/piranna/Trabajo/Avrioc/EsDiPi/test/cli.js
    # longestStatic:  36
    # length:  85917
    # Subtest: clean-sdp
    ok 1 - clean-sdp # SKIP
      ---
      duration_ms: 2.336453
      ...
    # Subtest: compress
    ok 2 - compress # SKIP
      ---
      duration_ms: 0.057482
      ...
    # Subtest: empty esdipi
    ok 3 - empty esdipi
      ---
      duration_ms: 5.970628
      ...
    # Subtest: Offer esdipi
    ok 4 - Offer esdipi
      ---
      duration_ms: 21.166008
      ...
    # Subtest: Answer esdipi
    ok 5 - Answer esdipi
      ---
      duration_ms: 9.956793
      ...
    1..8
ok 1 - /home/piranna/Trabajo/Avrioc/EsDiPi/test/cli.js
  ---
  duration_ms: 104.264871
  ...
1..1
# tests 1
# pass 1
# fail 0
# cancelled 0
# skipped 0
# todo 0
# duration_ms 106.675893

It should be showing 11 total tests, passing 4 (3 from "empty esdipi" describe and another top level one not shown), 6 skipped ones from the "clean-sdp" and "compress" describes, and 1 failed top level one not shown.

If there are other skipped describes, they are shown as skipped, but there's no info of any other describe or test defined it. In fact, if I have tests after that describe, they get run (checked with c8 coverage, code being tested by that tests gets covered) but their status is not reported at all, both failed or sucessful. If I move one of that test that's passing to be executed before the describes, lefting one test that's failing to execute after the describes, then the first test and all the describes (including the skipped ones) fails with the next error and don't get executed at all:

   not ok 2 - clean-sdp # SKIP
       ---
      duration_ms: 0
      failureType: 'cancelledByParent'
      error: 'Promise resolution is still pending but the event loop has already resolved'
      code: 'ERR_TEST_FAILURE'
      stack: |-
        process.emit (node:events:512:28)
      ...

It seems like the test module has been tested or is more indented to have a single top level describe or test entry, not allowing to have several ones.

How often does it reproduce? Is there a required condition?

Always.

What is the expected behavior?

All describes and tests are being executed and reported, both passing and failing ones, no matter of their order of if they are inside describe / sub-tests.

What do you see instead?

Only first describe / sub-test is being reported, any other top level test or describe are excluded from reports.

Additional information

It seems there are several inter-related errors on this issue.

Activity

  1. MoLow commented on Feb 4, 2023

    @MoLow
    Member

    please include the file you are running and the cli command

  2. added
    test_runnerIssues and PRs related to the test runner subsystem.
    on Feb 4, 2023
  3. piranna commented on Feb 7, 2023

    @piranna
    ContributorAuthor

    please include the file you are running and the cli command

    I have uploaded my project to https://github.com/piranna/ESDiPi, and the actual file with the tests are at https://github.com/piranna/ESDiPi/blob/main/test/cli.js, you can play with them reordering or skipping them and will have the same behaviour I have. Module itself is working properly, so tests should not give you problems, just only the Node.js test tests runner module.

  4. MoLow commented on Feb 7, 2023

    @MoLow
    Member

    @piranna the issue is the usage of describe with test. describe is supposed to be used with it only - which I hope will be fixed/changed,
    but in the meanwhile you can change you code from test to it

  5. piranna commented on Feb 7, 2023

    @piranna
    ContributorAuthor

    @piranna the issue is the usage of describe with test. describe is supposed to be used with it only - which I hope will be fixed/changed,

    Aren't they aliases between them? At least it's the feel it gives on the docs (not that it says it, it's just a feeling) and the same for describe()...

  6. MoLow commented on Feb 7, 2023

    @MoLow
    Member

    Aren't they aliases between them? At least it's the feel it gives on the docs (not that it says it, it's just a feeling) and the same for describe()...

    they are not aliases, but I agree it is a fair expectation for test to work the same way it does, thus I opened a PR to change the behavior #46544

  7. piranna commented on Feb 7, 2023

    @piranna
    ContributorAuthor

    thus I opened a PR to change the behavior #46544

    Thank you :-)

  8. piranna commented on Feb 7, 2023

    @piranna
    ContributorAuthor

    thus I opened a PR to change the behavior #46544

    Thank you :-)

  9. piranna commented on Feb 10, 2023

    @piranna
    ContributorAuthor

    in the meanwhile you can change you code from test to it

    I confirm that with it instead of test, all tests and describes runned :-) Just only, the global metrics are still wrong:

    TAP version 13
    # Subtest: /home/piranna/Trabajo/Avrioc/ESDiPi/test/cli.js
        # Subtest: clean-sdp
            # Subtest: empty SDP
            ok 1 - empty SDP
              ---
              duration_ms: 6.303494
              ...
            # Subtest: Offer SDP
            ok 2 - Offer SDP
              ---
              duration_ms: 12.954568
              ...
            # Subtest: Answer SDP
            ok 3 - Answer SDP
              ---
              duration_ms: 5.798613
              ...
            1..3
        ok 1 - clean-sdp
          ---
          duration_ms: 26.163698
          ...
        # Subtest: compress
            # Subtest: empty SDP
            ok 1 - empty SDP
              ---
              duration_ms: 0.579423
              ...
            # Subtest: Offer SDP
            ok 2 - Offer SDP
              ---
              duration_ms: 74.314906
              ...
            # Subtest: Answer SDP
            ok 3 - Answer SDP
              ---
              duration_ms: 54.413326
              ...
            1..3
        ok 2 - compress
          ---
          duration_ms: 129.464455
          ...
        # Subtest: decompress
            # Subtest: empty esdipi
            ok 1 - empty esdipi
              ---
              duration_ms: 1.232121
              ...
            # Subtest: Offer esdipi
            ok 2 - Offer esdipi
              ---
              duration_ms: 8.018468
              ...
            # Subtest: Answer esdipi
            ok 3 - Answer esdipi
              ---
              duration_ms: 7.692408
              ...
            1..3
        ok 3 - decompress
          ---
          duration_ms: 17.10319
          ...
        # Subtest: prefix
        not ok 4 - prefix
          ---
          duration_ms: 0.843434
          failureType: 'cancelledByParent'
          error: 'Promise resolution is still pending but the event loop has already resolved'
          code: 'ERR_TEST_FAILURE'
          stack: |-
            process.emit (node:events:512:28)
          ...
        # Subtest: unknown command
        not ok 5 - unknown command
          ---
          duration_ms: 0
          failureType: 'cancelledByParent'
          error: 'Promise resolution is still pending but the event loop has already resolved'
          code: 'ERR_TEST_FAILURE'
          stack: |-
            process.emit (node:events:512:28)
          ...
        1..5
    not ok 1 - /home/piranna/Trabajo/Avrioc/ESDiPi/test/cli.js
      ---
      duration_ms: 238.9463
      failureType: 'subtestsFailed'
      exitCode: 1
      error: 'test failed'
      code: 'ERR_TEST_FAILURE'
      ...
    1..1
    # tests 1
    # pass 0
    # fail 1
    # cancelled 0
    # skipped 0
    # todo 0
    # duration_ms 243.316294
    

    I think with these tests output report they should be

    # tests 11
    # pass 9
    # fail 0
    # cancelled 2
    # skipped 0
    # todo 0
    

    Maybe that should be another issue?

  10. cjihrig commented on Feb 10, 2023

    @cjihrig
    Contributor

    Maybe that should be another issue?

    That's being handled in #46440.

  11. piranna commented on Feb 10, 2023

    @piranna
    ContributorAuthor

    That's being handled in #46440.

    Cool, thank you for the pointer :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    test_runnerIssues and PRs related to the test runner subsystem.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions