Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] Error and leaks on immediate resolved/returned data and thrown errors #49

Closed
1 task done
manuel-duchscherer opened this issue Jul 11, 2024 · 9 comments · Fixed by #48
Closed
1 task done
Labels
bug Something isn't working

Comments

@manuel-duchscherer
Copy link

Duplicate issue

  • I've searched for any related issues and avoided creating a duplicate issue.

Description

The library seems a good fit and I tried my luck with some small/minimal examples triggered by a Deno test case.
I get some errors for these "artificial" test cases. One about an undefined property and in some cases there are timer leaks.

Would be happy if you gave it a look. Maybe I made a mistake or it's secure to ignore these errors for non-artificial cases. I'm also a bit new to Deno. Thanks.

This is my worker-error.ts:

import { availableParallelism, DynamicThreadPool, PoolEvents } from '@poolifier/poolifier-web-worker';
import { afterAll, beforeAll, describe, it } from '@std/testing/bdd';
import type { WorkerData, WorkerResponse } from '<path to>/worker-error.ts';

describe('Worker', () => {
  const workerFileURL = new URL('<path to>/worker-error.ts', import.meta.url);
  let threadPool: DynamicThreadPool<WorkerData, WorkerResponse>;

  beforeAll(() => {
    threadPool = new DynamicThreadPool<WorkerData, WorkerResponse>(
      1,
      availableParallelism(),
      workerFileURL,
      {
        enableTasksQueue: true,
        tasksQueueOptions: {
          concurrency: 1,
          size: 1,
          taskStealing: true,
          tasksStealingOnBackPressure: false,
        }
      }
    );
    threadPool.eventTarget?.addEventListener(PoolEvents.taskError, (err) => { console.error(err); });
    threadPool.eventTarget?.addEventListener(PoolEvents.messageerror, (err) => { console.error(err); });
    threadPool.eventTarget?.addEventListener(PoolEvents.error, (err) => { console.error(err); });
  });

  afterAll(async () => {
    await threadPool.destroy();
  });

  it('Task: default', async () => {
    const responseDefault = await threadPool.execute({ n: 1 });
    console.info('response from default: ', responseDefault);
  });

  it('Task: something', async () => {
    const taskSpawn = (n: number) => threadPool.execute({ n: n }, 'something');
    const tasks: Promise<void>[] = [];
    for (let i = 0; i < 10; i++) {
      const task = taskSpawn(i)
        .then((response: WorkerResponse) => {
          console.info('worker response: ', response);
        }).catch((err) => {
          console.error('task error: ', err);
        });
      tasks.push(task);
    }
    console.info(`added ${tasks.length} tasks`);
    await Promise.allSettled(tasks);
  });
});

... run with the --trace-leaks flag.

with import-map in deno.jsonc:

"imports": {
  "@poolifier/poolifier-web-worker": "jsr:@poolifier/poolifier-web-worker@^0.4.13",
  "@std/async/": "jsr:/@std/async@^0.224.0/",
  "@std/testing/": "jsr:/@std/testing@^0.224.0/",
}

The worker:

import { ThreadWorker } from '@poolifier/poolifier-web-worker';
import { delay } from '@std/async/delay';

export interface WorkerData {
  n: number;
}

export interface WorkerResponse {
  message: string;
  data?: WorkerData;
}

const defaultTask = (data?: WorkerData): WorkerResponse => ({ message: 'unimplemented' });

class TestWorker extends ThreadWorker<WorkerData, WorkerResponse> {
  private prop = 'test';

  constructor() {
    super(defaultTask, {
      killHandler: () => this.shutdown()
    });
    this.addTaskFunction('something', this.something);
  }

  private shutdown() {
    console.info('shutdown');
  }

  private /* async */ something(data?: WorkerData) {
    // await delay(1000);
    // return Promise.resolve({ message: this.prop, data });
    // throw new Error('a task error');
    // return { message: this.prop, data };
  }
}

export default new TestWorker();

Now I have some cases with the something method:

  1. private something(data?: WorkerData) {
      return { message: this.prop, data };
    }

    Produces timer leaks.

    Terminal Output
    ------- output -------
    response from default:  { message: "unimplemented" }
    ----- output end -----
      Task: default ... ok (481ms)
      Task: something ...
    ------- output -------
    added 10 tasks
    worker response:  { message: "test", data: { n: 0 } }
    worker response:  { message: "test", data: { n: 1 } }
    worker response:  { message: "test", data: { n: 3 } }
    worker response:  { message: "test", data: { n: 6 } }
    worker response:  { message: "test", data: { n: 8 } }
    worker response:  { message: "test", data: { n: 2 } }
    worker response:  { message: "test", data: { n: 7 } }
    worker response:  { message: "test", data: { n: 5 } }
    worker response:  { message: "test", data: { n: 4 } }
    worker response:  { message: "test", data: { n: 9 } }
    ----- output end -----
      Task: something ... ok (127ms)
    ------- output -------
    shutdown
    shutdown
    shutdown
    shutdown
    ----- output end -----
    Worker ... FAILED (637ms)
    
     ERRORS 
    
    Worker => https://jsr.io/@std/testing/0.224.0/_test_suite.ts:191:10
    error: Leaks detected:
      - 2 timers were started in this test, but never completed. This is often caused by not calling `clearTimeout`. The operation were started here:
        at Object.queueUserTimer (ext:core/01_core.js:738:9)
        at setTimeout (ext:deno_web/02_timers.js:61:15)
        at https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/utils.ts:36:5
        at new Promise (<anonymous>)
        at sleep (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/utils.ts:35:9)
        at WorkerNode.AbstractPool.handleWorkerNodeIdleEvent (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1827:5)
        at innerInvokeEventListeners (ext:deno_web/02_event.js:754:7)
        at invokeEventListeners (ext:deno_web/02_event.js:801:5)
        at dispatch (ext:deno_web/02_event.js:658:9)
        at WorkerNode.dispatchEvent (ext:deno_web/02_event.js:1043:12)
    
     FAILURES 
    
    Worker => https://jsr.io/@std/testing/0.224.0/_test_suite.ts:191:10
    
    FAILED | 0 passed (2 steps) | 1 failed (641ms)
    
    error: Test failed
  2. private async something(data?: WorkerData) {
       await delay(1000);
       return Promise.resolve({ message: this.prop, data });
    }

    This is ok and produces no errors.

    Terminal Output
     ------- output -------
     response from default:  { message: "unimplemented" }
     ----- output end -----
       Task: default ... ok (58ms)
       Task: something ...
     ------- output -------
     added 10 tasks
     worker response:  { message: "test", data: { n: 0 } }
     worker response:  { message: "test", data: { n: 2 } }
     worker response:  { message: "test", data: { n: 5 } }
     worker response:  { message: "test", data: { n: 9 } }
     worker response:  { message: "test", data: { n: 1 } }
     worker response:  { message: "test", data: { n: 4 } }
     worker response:  { message: "test", data: { n: 8 } }
     worker response:  { message: "test", data: { n: 3 } }
     worker response:  { message: "test", data: { n: 6 } }
     worker response:  { message: "test", data: { n: 7 } }
     ----- output end -----
       Task: something ... ok (3s)
     ------- output -------
     shutdown
     shutdown
     shutdown
     shutdown
     ----- output end -----
     Worker ... ok (3s)
     
     ok | 1 passed (2 steps) | 0 failed (3s)
  3. private async something(data?: WorkerData) {
       return Promise.resolve({ message: this.prop, data });
    }   

    But without a delay it does have leaks.

    Terminal Output
     ------- output -------
     response from default:  { message: "unimplemented" }
     ----- output end -----
       Task: default ... ok (58ms)
       Task: something ...
     ------- output -------
     added 10 tasks
     worker response:  { message: "test", data: { n: 0 } }
     worker response:  { message: "test", data: { n: 1 } }
     worker response:  { message: "test", data: { n: 3 } }
     worker response:  { message: "test", data: { n: 6 } }
     worker response:  { message: "test", data: { n: 8 } }
     worker response:  { message: "test", data: { n: 2 } }
     worker response:  { message: "test", data: { n: 7 } }
     worker response:  { message: "test", data: { n: 5 } }
     worker response:  { message: "test", data: { n: 4 } }
     worker response:  { message: "test", data: { n: 9 } }
     ----- output end -----
       Task: something ... ok (134ms)
     ------- output -------
     shutdown
     shutdown
     shutdown
     shutdown
     ----- output end -----
     Worker ... FAILED (219ms)
     
      ERRORS 
     
     Worker => https://jsr.io/@std/testing/0.224.0/_test_suite.ts:191:10
     error: Leaks detected:
       - 2 timers were started in this test, but never completed. This is often caused by not calling `clearTimeout`. The operation were started here:
         at Object.queueUserTimer (ext:core/01_core.js:738:9)
         at setTimeout (ext:deno_web/02_timers.js:61:15)
         at https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/utils.ts:36:5
         at new Promise (<anonymous>)
         at sleep (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/utils.ts:35:9)
         at WorkerNode.AbstractPool.handleWorkerNodeIdleEvent (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1827:5)
         at innerInvokeEventListeners (ext:deno_web/02_event.js:754:7)
         at invokeEventListeners (ext:deno_web/02_event.js:801:5)
         at dispatch (ext:deno_web/02_event.js:658:9)
         at WorkerNode.dispatchEvent (ext:deno_web/02_event.js:1043:12)
     
      FAILURES 
     
     Worker => https://jsr.io/@std/testing/0.224.0/_test_suite.ts:191:10
     
     FAILED | 0 passed (2 steps) | 1 failed (223ms)
     
     error: Test failed
  4. private async something(data?: WorkerData): Promise<WorkerResponse> {
      await delay(1000);
      throw new Error('a task error');
    }

    Throwing an error is propagated to the taskError event handler, but not catched by the taskSpawn().catch, is this normal?
    Maybe it's prevented by the TypeError thrown in DynamicThreadPool (see log).

    Terminal Output
     ------- output -------
     response from default:  { message: "unimplemented" }
     ----- output end -----
       Task: default ... ok (478ms)
       Task: something ...
     ------- output -------
     added 10 tasks
     ErrorEvent {
       bubbles: false,
       cancelable: false,
       composed: false,
       currentTarget: EventTarget {},
       defaultPrevented: false,
       eventPhase: 2,
       srcElement: null,
       target: EventTarget {},
       returnValue: true,
       timeStamp: 0,
       type: "taskError",
       message: "",
       filename: "",
       lineno: 0,
       colno: 0,
       error: {
         name: "something",
         message: Error: a task error
         at TestWorker.something (file:///.../worker-error.ts:32:11)
         at eventLoopTick (ext:core/01_core.js:207:9),
         data: { n: 0 }
       }
     }
     Uncaught error from .../worker-error.test.ts FAILED
     Worker ... cancelled (0ms)
     
      ERRORS 
     
     ..../worker-error.test.ts (uncaught error)
     error: TypeError: Cannot read properties of undefined (reading 'name')
               message.taskPerformance!.name,
                                        ^
         at DynamicThreadPool.afterTaskExecutionHook (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1320:36)
         at DynamicThreadPool.handleTaskExecutionResponse (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1981:12)
         at AbstractPool.workerMessageListener (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1940:12)
         at WorkerNode.<anonymous> (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/utils.ts:373:19)
         at innerInvokeEventListeners (ext:deno_web/02_event.js:754:7)
         at invokeEventListeners (ext:deno_web/02_event.js:801:5)
         at dispatch (ext:deno_web/02_event.js:658:9)
         at WorkerNode.dispatchEvent (ext:deno_web/02_event.js:1043:12)
         at MessagePort.WorkerNode.messageChannel.port1.onmessage (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/worker-node.ts:67:12)
     This error was not caught from a test and caused the test runner to fail on the referenced module.
     It most likely originated from a dangling promise, event/timeout handler or top-level code.
     
      FAILURES 
     
     ..../worker-error.test.ts (uncaught error)
     
     FAILED | 0 passed (1 step) | 2 failed (1s)
     
     error: Test failed

Expected behavior

No response

Actual behavior

No response

Steps to reproduce

No response

poolifier version

0.4.14

Javascript runtime

Deno

Deno, Bun or browser version

deno 1.44.4 (release, x86_64-unknown-linux-gnu) v8 12.6.228.9 typescript 5.4.5

System

No response

Attachments

No response

@manuel-duchscherer manuel-duchscherer added the bug Something isn't working label Jul 11, 2024
@jerome-benoit
Copy link
Contributor

jerome-benoit commented Jul 11, 2024

Deno is not able to properly track ressource leaks when web worker are used and must be disabled in its testing framework to avoid false positive.

If the issues are reproducible without any testing framework and with a kind of bare metal deno implementation, it worth investigating.

@manuel-duchscherer
Copy link
Author

Ok. You say, the timer leak messages can be securely ignored?
And the TypeError within DynamicThreadPool.afterTaskExecutionHook?

bdd is the Deno std library behavior driven testing, so still Deno standard.

@manuel-duchscherer
Copy link
Author

I reduced it to Deno.test, which makes no difference.

import { availableParallelism, DynamicThreadPool, PoolEvents } from '@poolifier/poolifier-web-worker';
import type { WorkerData, WorkerResponse } from '.../worker-error.ts';

Deno.test('Worker', async () => {
  const workerFileURL = new URL('.../worker-error.ts', import.meta.url);

  const threadPool = new DynamicThreadPool<WorkerData, WorkerResponse>(
    1,
    availableParallelism(),
    workerFileURL,
    {
      enableTasksQueue: true,
      tasksQueueOptions: {
        concurrency: 1,
        size: 1,
        taskStealing: true,
        tasksStealingOnBackPressure: false,
      }
    }
  );
  threadPool.eventTarget?.addEventListener(PoolEvents.taskError, (err) => { console.error(err); });
  threadPool.eventTarget?.addEventListener(PoolEvents.messageerror, (err) => { console.error(err); });
  threadPool.eventTarget?.addEventListener(PoolEvents.error, (err) => { console.error(err); });

  const taskSpawn = (n: number) => threadPool.execute({ n: n }, 'something');
  const tasks: Promise<void>[] = [];
  for (let i = 0; i < 10; i++) {
    const task = taskSpawn(i)
      .then((response: WorkerResponse) => {
        console.info('worker response: ', response);
      }).catch((err) => {
        console.error('task error: ', err);
      });
    tasks.push(task);
  }
  console.info(`added ${tasks.length} tasks`);
  await Promise.allSettled(tasks);

  await threadPool.destroy();
});

@jerome-benoit
Copy link
Contributor

Ok. You say, the timer leak messages can be securely ignored? And the TypeError within DynamicThreadPool.afterTaskExecutionHook?

The error worker side is propagated to the main thread in the response (and an event if event emission is enabled) and the worker is not crashed (no error propagation in the worker). It's the intended behavior.

bdd is the Deno std library behavior driven testing, so still Deno standard.

And: "Deno is not able to properly track ressource leaks when web worker are used and must be disabled in its testing framework to avoid false positive". Look at the code in tests/, resources leaks detection is often disabled because of false positive.

@jerome-benoit
Copy link
Contributor

execute() is not throwing error if a task fail: it's not acceptable to crash the whole pool because of an error at one task execution. Task execution error is intended to be handle by the execute() response handler, not in a try ... catch ...

@manuel-duchscherer
Copy link
Author

Thank you, { sanitizeResources: false, sanitizeOps: false } disables resource leak info.

I'm not sure what you mean with execute-response handler. I don't use try/catch, but catch on the returned Promise from execute. Is this not already what you mean?

And I still don't understand the correlation for case 4., where I throw an error in the worker, which results in a TypeError within DynamicThreadPool.afterTaskExecutionHook:

error: TypeError: Cannot read properties of undefined (reading 'name')
          message.taskPerformance!.name,
                                   ^
    at DynamicThreadPool.afterTaskExecutionHook (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1320:36)
    at DynamicThreadPool.handleTaskExecutionResponse (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1981:12)
    at AbstractPool.workerMessageListener (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1940:12)
    at WorkerNode.<anonymous> (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/utils.ts:373:19)
    at innerInvokeEventListeners (ext:deno_web/02_event.js:754:7)
    at invokeEventListeners (ext:deno_web/02_event.js:801:5)
    at dispatch (ext:deno_web/02_event.js:658:9)
    at WorkerNode.dispatchEvent (ext:deno_web/02_event.js:1043:12)
    at MessagePort.WorkerNode.messageChannel.port1.onmessage (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/worker-node.ts:67:12)

This error seems completely unrelated to my manually thrown error, which I'm not sure how to properly handle.

@jerome-benoit
Copy link
Contributor

I'm not sure what you mean with execute-response handler. I don't use try/catch, but catch on the returned Promise from execute. Is this not already what you mean?

Avoid testing by using an indirection layer like a unit tests framework: it uses native OS thread for unit tests (in Deno), ... The number of indirection layers introduced will not make the debugging close to the real world usage.

taskSpawn() miss the async keyword.

And I still don't understand the correlation for case 4., where I throw an error in the worker, which results in a TypeError within DynamicThreadPool.afterTaskExecutionHook:

error: TypeError: Cannot read properties of undefined (reading 'name')
          message.taskPerformance!.name,
                                   ^
    at DynamicThreadPool.afterTaskExecutionHook (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1320:36)
    at DynamicThreadPool.handleTaskExecutionResponse (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1981:12)
    at AbstractPool.workerMessageListener (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/abstract-pool.ts:1940:12)
    at WorkerNode.<anonymous> (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/utils.ts:373:19)
    at innerInvokeEventListeners (ext:deno_web/02_event.js:754:7)
    at invokeEventListeners (ext:deno_web/02_event.js:801:5)
    at dispatch (ext:deno_web/02_event.js:658:9)
    at WorkerNode.dispatchEvent (ext:deno_web/02_event.js:1043:12)
    at MessagePort.WorkerNode.messageChannel.port1.onmessage (https://jsr.io/@poolifier/poolifier-web-worker/0.4.14/src/pools/worker-node.ts:67:12)

This error seems completely unrelated to my manually thrown error, which I'm not sure how to properly handle.

I missed that one in the report. It looks genuine since in case of task error taskPerformance is not defined. But I do not understand why the current UTs are not detecting it.

@jerome-benoit
Copy link
Contributor

Please reopen if not fixed in 0.4.15 release.

@manuel-duchscherer
Copy link
Author

Thank you very much for your swift response and fix. Errors are gone.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants