Skip to content

test/debug.js is flaky :( #2600

Closed
Closed

Description

@KhafraDev
# Subtest: test/debug.js
    # Subtest: debug\#websocket
    ok 1 - debug\#websocket
      ---
      duration_ms: 692.207053
      ...
    # Subtest: debug\#fetch
    ok 2 - debug\#fetch
      ---
      duration_ms: 807.024345
      ...
    # Subtest: debug\#undici
    not ok 3 - debug\#undici
      ---
      duration_ms: 965.181717
      location: '/home/runner/work/undici/undici/test/debug.js:65:1'
      failureType: 'hookFailed'
      error: 'The plan was not completed'
      code: 'ERR_ASSERTION'
      name: 'AssertionError'
      expected: 10
      actual: 8
      operator: 'strictEqual'
      stack: |-
        TestContext.autoEnd (/home/runner/work/undici/undici/node_modules/@matteo.collina/tspl/tspl.js:25:14)
        TestHook.runInAsyncScope (node:async_hooks:203:9)
        TestHook.run (node:internal/test_runner/test:631:25)
        TestHook.run (node:internal/test_runner/test:856:18)
        TestHook.run (node:internal/util:530:12)
        node:internal/test_runner/test:565:20
        process.processTicksAndRejections (node:internal/process/task_queues:95:5)
        async node:internal/test_runner/test:564:9
        async Test.runHook (node:internal/test_runner/test:563:7)
        async after (node:internal/test_runner/test:591:9)
      ...
    1..3
    # tests 3
    # suites 0
    # pass 2
    # fail 1
    # cancelled 0
    # skipped 0
    # todo 0
    # duration_ms 2472.022223
    # failed 1 of 3 tests
not ok 27 - test/debug.js # time=2811.968ms
  ---
  env: {}
  file: test/debug.js
  timeout: 60000
  command: /opt/hostedtoolcache/node/18.19.0/x64/bin/node
  args:
    - --expose-gc
    - test/debug.js
  stdio:
    - 0
    - pipe
    - 2
  cwd: /home/runner/work/undici/undici
  exitCode: 1
  ...

cc @metcoder95

Activity

  1. metcoder95 commented on Jan 9, 2024

    @metcoder95
    Member

    Sorry, just saw it now; I'll check it out 👍

  2. KhafraDev commented on Jan 12, 2024

    @KhafraDev
    MemberAuthor

    Just saw this -

     # Subtest: debug\#websocket
    not ok 13 - debug\#websocket
      ---
      duration_ms: 1083.25216
      location: '/home/runner/work/undici/undici/test/node-test/debug.js:8:1'
      failureType: 'hookFailed'
      error: 'The plan was not completed'
      code: 'ERR_ASSERTION'
      name: 'AssertionError'
      expected: 5
      actual: 4
      operator: 'strictEqual'
      stack: |-
        TestContext.autoEnd (/home/runner/work/undici/undici/node_modules/@matteo.collina/tspl/tspl.js:25:14)
        TestHook.runInAsyncScope (node:async_hooks:203:9)
        TestHook.run (node:internal/test_runner/test:631:25)
        TestHook.run (node:internal/test_runner/test:856:18)
        TestHook.run (node:internal/util:530:12)
        node:internal/test_runner/test:565:20
        process.processTicksAndRejections (node:internal/process/task_queues:95:5)
        async node:internal/test_runner/test:564:9
        async Test.runHook (node:internal/test_runner/test:563:7)
        async after (node:internal/test_runner/test:591:9)
      ...
    
  3. metcoder95 commented on Jan 12, 2024

    @metcoder95
    Member

    This will be a nightmare...

  4. metcoder95 commented on Jan 12, 2024

    @metcoder95
    Member

    Do you have the job that failed like that?

  5. tsctx commented on Jan 12, 2024

    @tsctx
    Member
  6. KhafraDev commented on Jan 30, 2024

    @KhafraDev
    MemberAuthor

    @metcoder95

     # Subtest: debug\#websocket
    not ok 14 - debug\#websocket
      ---
      duration_ms: 1046.686059
      location: '/home/runner/work/undici/undici/test/node-test/debug.js:8:1'
      failureType: 'uncaughtException'
      error: |-
        The input did not match the regular expression /(WEBSOCKET [0-9]+:) (sending request)/. Input:
        
        'WEBSOCKET 6051: connection opened ::1:33002\n'
        
      code: 'ERR_ASSERTION'
      name: 'AssertionError'
      expected:
      actual: |-
        WEBSOCKET 6051: connection opened ::1:33002
        
      operator: 'match'
      stack: |-
        res.<computed> [as match] (/home/runner/work/undici/undici/node_modules/@matteo.collina/tspl/tspl.js:52:35)
        Socket.<anonymous> (/home/runner/work/undici/undici/test/node-test/debug.js:40:14)
        Socket.emit (node:events:530:35)
        endReadableNT (node:internal/streams/readable:1696:12)
        process.processTicksAndRejections (node:internal/process/task_queues:82:21)
      ...
    
  7. metcoder95 commented on Jan 30, 2024

    @metcoder95
    Member

    Ah, this is getting harder; now it seems it just receives a few lines instead of all of them. I'd see what I can do to make it less stricter

  8. KhafraDev commented on Feb 14, 2024

    @KhafraDev
    MemberAuthor

    @metcoder95 @Uzlopak

     test at test\node-test\debug.js:51:1
    ✖ debug#fetch (1374.7649ms)
      Error: kill EPERM
          at ChildProcess.kill (node:internal/child_process:512:26)
          at TestContext.<anonymous> (D:\a\undici\undici\test\node-test\debug.js:83:9)
          at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
          at async Test.run (node:internal/test_runner/test:632:9)
          at async Test.processPendingSubtests (node:internal/test_runner/test:374:7) {
        errno: -4048,
        code: 'EPERM',
        syscall: 'kill'
      }
    
    test at test\node-test\debug.js:86:1
    ✖ debug#undici (1148.761ms)
      Error: kill EPERM
          at ChildProcess.kill (node:internal/child_process:512:26)
          at TestContext.<anonymous> (D:\a\undici\undici\test\node-test\debug.js:121:9)
          at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
          at async Test.run (node:internal/test_runner/test:632:9)
          at async Test.processPendingSubtests (node:internal/test_runner/test:374:7) {
        errno: -4048,
        code: 'EPERM',
        syscall: 'kill'
      }
    

    https://github.com/nodejs/undici/actions/runs/7905870944/job/21579434771?pr=2761

  9. KhafraDev commented on Feb 14, 2024

    @KhafraDev
    MemberAuthor

    it's consistently failing on windows with node v21

  10. Uzlopak commented on Feb 14, 2024

    @Uzlopak
    Contributor

    I will delve into it when i am back from the gym

  11. Uzlopak commented on Feb 15, 2024

    @Uzlopak
    Contributor

    I could reproduce this in my local Windows installation. This is probably a bug in node 21.6.2.

    I opened an issue in node core

    nodejs/node#51766

    I dont see, why a child_process kill() should throw.

  12. added a commit that references this issue on Apr 10, 2024
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

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions