gulpjs / glob-stream

Readable streamx interface over anymatch.
MIT License
178 stars 51 forks source link

Strange race condition on empy streams #135

Open pavelhoral opened 5 months ago

pavelhoral commented 5 months ago

What were you expecting to happen?

I have the following Vitest-based test in my project:

import { pipeline } from 'streamx';
import globStream from 'glob-stream';
import toThrough from 'to-through';

describe('globStream', () => {

  it('should concat glob streams', () => new Promise(done => {
    const stream = pipeline(
      globStream('src/*/non-existing.js', { base: 'src', allowEmpty: true }),
      toThrough(globStream('src/foobar/non-existing.js', { base: 'src', allowEmpty: true })),
    );
    stream
      .on('data', () => {})
      .on('end', done);
  }));

});

This test should end without any error. However once in a 10 tries it ends up with timeout (running with vitest). There is a switched order of flush / end events in the second vinyl stream. The issue happens more often if the first glob stream actually matches some files.

I am still trying to find the root cause - whether it is in streamx, to-through or gulp-stream (already spent 8 hours getting to this point so I am quite exhausted).

Terminal output

Successful run:

% npm run -w packages/pipeline test globStream

> <REMOVED-FOR-ISSUE-REPORT>@0.16.1 test
> vitest run globStream

 RUN  v1.6.0 /<REMOVED-FOR-ISSUE-REPORT>

 ✓ src/utils/globStream.spec.ts (1)
   ✓ globStream (1)
     ✓ should concat glob streams

 Test Files  1 passed (1)
      Tests  1 passed (1)
   Start at  23:34:55
   Duration  456ms (transform 79ms, setup 0ms, collect 74ms, tests 11ms, environment 0ms, prepare 151ms)

Failed run:

% npm run -w packages/pipeline test globStream

> @<REMOVED-FOR-ISSUE-REPORT>@0.16.1 test
> vitest run globStream

 RUN  v1.6.0 /<REMOVED-FOR-ISSUE-REPORT>

 ❯ src/utils/globStream.spec.ts (1) 5012ms
   ❯ globStream (1) 5010ms
     × should concat glob streams 5010ms

⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯ Failed Tests 1 ⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯

 FAIL  src/utils/globStream.spec.ts > globStream > should concat glob streams
Error: Test timed out in 5000ms.
If this is a long-running test, pass a timeout value as the last argument or configure it globally with "testTimeout".
⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯[1/1]⎯

 Test Files  1 failed (1)
      Tests  1 failed (1)
   Start at  23:34:58
   Duration  5.58s (transform 37ms, setup 0ms, collect 48ms, tests 5.01s, environment 0ms, prepare 164ms)

npm ERR! Lifecycle script `test` failed with error: 
npm ERR! Error: command failed 
npm ERR!   in workspace: @<REMOVED-FOR-ISSUE-REPORT>@0.16.1 
npm ERR!   at location: /<REMOVED-FOR-ISSUE-REPORT>

Please provide the following information:

Library versions (only Gulp 5.0.0 is in my package.json so the rest is transitive):

Tested on OSX with NodeJS v20.12.2 and on Kubuntu 24.04 with NodeJS v22.3.0.

pavelhoral commented 5 months ago

Getting closer to the culprit - seems like the globStream is closed before the pipeline starts flowing. Seems like the issue is that walking is started immediatelly upon stream construction - https://github.com/gulpjs/glob-stream/blob/77826594b4479fe5fefd6a751c28c7f686c24a87/index.js#L286C6-L286C16 and the empty stream can end before the whole pipeline starts flowing.

Got the following sample that IMO illustrates what is happening:

    const readable = new Readable();
    nextTick(() => readable.push(null));
    pipeline(Readable.from([]), toThrough(readable))
      .on('data', () => {})
      .on('end', done); // -> never called