investigate flaky test-http2-pack-end-stream-flag #37639

Activity

1. Trott

   added

   flaky-testIssues and PRs involving tests that fail intermittently in CI.Issues and PRs involving tests that fail intermittently in CI.

   freebsdIssues and PRs related to the FreeBSD platform.Issues and PRs related to the FreeBSD platform.

   http2Issues and PRs related to the http2 subsystem.Issues and PRs related to the http2 subsystem.

   on Mar 6, 2021
2. targos

   added

   macosIssues and PRs related to the macOS platform.Issues and PRs related to the macOS platform.

   on Mar 8, 2021
3. targos commented on Mar 8, 2021

   

   targos

   on Mar 8, 2021

   Member

   More actions

   I've seen it fail on macOS too:
   https://ci.nodejs.org/job/node-test-commit-osx/39328/nodes=osx1014/console
   https://ci.nodejs.org/job/node-test-commit-osx/39332/nodes=osx1014/console
4. Trott commented on Mar 12, 2021

   

   Trott

   on Mar 12, 2021

   MemberAuthor

   More actions

   https://ci.nodejs.org/job/node-test-commit-freebsd/38594/nodes=freebsd11-x64/console

   Details

   00:18:34 not ok 1635 parallel/test-http2-pack-end-stream-flag
   00:18:35   ---
   00:18:35   duration_ms: 120.94
   00:18:35   severity: fail
   00:18:35   exitcode: -15
   00:18:35   stack: |-
   00:18:35     timeout
   00:18:35   ...
   
5. Trott commented on Mar 12, 2021

   

   Trott

   on Mar 12, 2021

   MemberAuthor

   More actions

   https://ci.nodejs.org/job/node-test-commit-osx/39441/nodes=osx1014/console

   Details

   00:14:03 not ok 2222 parallel/test-http2-pack-end-stream-flag
   00:14:03   ---
   00:14:03   duration_ms: 120.75
   00:14:03   severity: fail
   00:14:03   exitcode: -15
   00:14:03   stack: |-
   00:14:03     timeout
   00:14:03   ...
   
6. Trott commented on Mar 12, 2021

   

   Trott

   on Mar 12, 2021

   MemberAuthor

   More actions

   I'm able to replicate the problam on macOS without even running stuff in parallel.

    tools/test.py --repeat=192 test/parallel/test-http2-pack-end-stream-flag.js
   
7. Trott commented on Mar 12, 2021

   

   Trott

   on Mar 12, 2021

   Last edited by Trott

   MemberAuthor

   More actions

   Bisecting points to f3eb224 as the change where this issue starts to manifest itself.
8. Trott commented on Mar 18, 2021

   

   Trott

   on Mar 18, 2021

   MemberAuthor

   More actions

   Still happening on CI with some frequency:

   https://ci.nodejs.org/job/node-test-commit-osx/39504/nodes=osx1014/console

   00:16:27 not ok 2194 parallel/test-http2-pack-end-stream-flag
   00:16:27   ---
   00:16:27   duration_ms: 120.91
   00:16:27   severity: fail
   00:16:27   exitcode: -15
   00:16:27   stack: |-
   00:16:27     timeout
   00:16:27   ...
   
9. Trott commented on Mar 18, 2021

   

   Trott

   on Mar 18, 2021

   MemberAuthor

   More actions

   After some debugging, seems to me that this is a legitimate failure indicative of an http2 and/or perf_hooks bug whereby, for whatever reason, sometimes (infrequently) the Http2Session entry with detail type client never occurs.

   This bug appears to have been introduced in f3eb224.

   @jasnell
10. jasnell commented on Mar 18, 2021

    

    jasnell

    on Mar 18, 2021

    Member

    More actions

    I'll take a look a bit later today

    👍React with 👍1Reacted by Rich Trott
11. Trott commented on Mar 18, 2021

    

    Trott

    on Mar 18, 2021

    MemberAuthor

    More actions

    I'll take a look a bit later today

    If it helps, I debugged by adding console.error() statements (don't judge) along with a setTimeout() to throw an error after 5 seconds. So with the modified code below, tools/test.py --timeout=10 --repeat 1920 test/parallel/test-http2-pack-end-stream-flag.js showed the issue. In CI, it happens on macOS and FreeBSD.

    'use strict';
    
    console.error('starting');
    
    const common = require('../common');
    if (!common.hasCrypto)
      common.skip('missing crypto');
    const assert = require('assert');
    const http2 = require('http2');
    
    const { PerformanceObserver } = require('perf_hooks');
    
    const server = http2.createServer();
    
    server.on('stream', (stream, headers) => {
      stream.respond({
        'content-type': 'text/html',
        ':status': 200
      });
      switch (headers[':path']) {
        case '/singleEnd':
          stream.end('OK');
          break;
        case '/sequentialEnd':
          stream.write('OK');
          stream.end();
          break;
        case '/delayedEnd':
          stream.write('OK', () => stream.end());
          break;
      }
    });
    
    function testRequest(path, targetFrameCount, callback) {
      console.error('test request');
      const obs = new PerformanceObserver(
        common.mustCallAtLeast((list, observer) => {
          console.error('mustcallatleast');
          const entry = list.getEntries()[0];
          console.error(entry.name, entry.detail.type);
          if (entry.name !== 'Http2Session') return;
          if (entry.detail.type !== 'client') return;
          assert.strictEqual(entry.detail.framesReceived, targetFrameCount);
          observer.disconnect();
          callback();
        }));
      obs.observe({ type: 'http2' });
      const client =
        http2.connect(`http://localhost:${server.address().port}`, () => {
          const req = client.request({ ':path': path });
          req.resume();
          req.end();
          req.on('end', () => client.close());
        });
    }
    
    // SETTINGS => SETTINGS => HEADERS => DATA
    const MIN_FRAME_COUNT = 4;
    
    server.listen(0, () => {
      console.error('listening');
      testRequest('/singleEnd', MIN_FRAME_COUNT, () => {
        console.error('singleend');
        testRequest('/sequentialEnd', MIN_FRAME_COUNT, () => {
          console.error('sequentialend');
          testRequest('/delayedEnd', MIN_FRAME_COUNT + 1, () => {
            console.error('closing');
            server.close();
          });
        });
      });
    });
    
    setTimeout(() => { throw new Error('foo'); }, 5000).unref();
12. jasnell

    closed this as completedin 978bbf9on Mar 22, 2021
13. MayaLekova

    added a commit that references this issue on May 22, 2026

    test: fix flaky test-http2-pack-end-stream-flag

    ...

    978bbf9