Skip to content

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

Description

@Trott
  • Test: test-http2-pack-end-stream-flag
  • Platform: freebsd11-x64
  • Console Output:
07:19:22 not ok 1964 parallel/test-http2-pack-end-stream-flag
07:19:22   ---
07:19:22   duration_ms: 120.47
07:19:22   severity: fail
07:19:22   exitcode: -15
07:19:22   stack: |-
07:19:22     timeout
07:19:22   ...

Activity

  1. added
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    freebsdIssues and PRs related to the FreeBSD platform.
    http2Issues and PRs related to the http2 subsystem.
    on Mar 6, 2021
  2. added
    macosIssues and PRs related to the macOS platform.
    on Mar 8, 2021
  3. Trott commented on Mar 12, 2021

    @Trott
    MemberAuthor

    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   ...
    
  4. Trott commented on Mar 12, 2021

    @Trott
    MemberAuthor

    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   ...
    
  5. Trott commented on Mar 12, 2021

    @Trott
    MemberAuthor

    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
    
  6. Trott commented on Mar 12, 2021

    @Trott
    MemberAuthor

    Bisecting points to f3eb224 as the change where this issue starts to manifest itself.

  7. Trott commented on Mar 18, 2021

    @Trott
    MemberAuthor

    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   ...
    
  8. Trott commented on Mar 18, 2021

    @Trott
    MemberAuthor

    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

  9. jasnell commented on Mar 18, 2021

    @jasnell
    Member

    I'll take a look a bit later today

  10. Trott commented on Mar 18, 2021

    @Trott
    MemberAuthor

    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();
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

    flaky-testIssues and PRs involving tests that fail intermittently in CI.freebsdIssues and PRs related to the FreeBSD platform.http2Issues and PRs related to the http2 subsystem.macosIssues and PRs related to the macOS platform.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions