[IMP] component: emit warning when async hooks take too long

This commit adds a warning when an async hook
(onWillUpdateProps/onWillStart) takes longer than 3 seconds, as these
hooks block the rendering and patching of the application, it is rarely
desirable and often a sign of a deadlock. This warning will contain the
stack trace of the call to the hook to help in debugging.

doc/reference/app.md

@@ -117,3 +117,5 @@ Dev mode activates some additional checks and developer amenities:
 - [Props validation](./props.md#props-validation) is performed
 - [t-foreach](./templates.md#loops) loops check for key unicity
 - Lifecycle hooks are wrapped to report their errors in a more developer-friendly way
+- onWillStart and onWillUpdateProps will emit a warning in the console when they
+  take longer than 3 seconds in an effort to ease debugging the presence of deadlocks

src/component/lifecycle_hooks.ts

@@ -1,14 +1,28 @@
 import { getCurrent } from "./component_node";
 import { nodeErrorHandlers } from "./error_handling";
 
+const TIMEOUT = Symbol("timeout");
 function wrapError(fn: (...args: any[]) => any, hookName: string) {
   const error = new Error(`The following error occurred in ${hookName}: `) as Error & {
     cause: any;
   };
+  const timeoutError = new Error(`${hookName}'s promise hasn't resolved after 3 seconds`);
+  const node = getCurrent();
   return (...args: any[]) => {
     try {
       const result = fn(...args);
       if (result instanceof Promise) {
+        if (hookName === "onWillStart" || hookName === "onWillUpdateProps") {
+          const fiber = node.fiber;
+          Promise.race([
+            result,
+            new Promise((resolve) => setTimeout(() => resolve(TIMEOUT), 3000)),
+          ]).then((res) => {
+            if (res === TIMEOUT && node.fiber === fiber) {
+              console.warn(timeoutError);
+            }
+          });
+        }
         return result.catch((cause) => {
           error.cause = cause;
           if (cause instanceof Error) {

tests/components/__snapshots__/lifecycle.test.ts.snap

@@ -658,6 +658,43 @@ exports[`lifecycle hooks sub widget (inside sub node): hooks are correctly calle
 }"
 `;
 
+exports[`lifecycle hooks timeout in onWillStart emits a warning 1`] = `
+"function anonymous(bdom, helpers
+) {
+  let { text, createBlock, list, multi, html, toggler, component, comment } = bdom;
+  
+  let block1 = createBlock(\`<span/>\`);
+  
+  return function template(ctx, node, key = \\"\\") {
+    return block1();
+  }
+}"
+`;
+
+exports[`lifecycle hooks timeout in onWillUpdateProps emits a warning 1`] = `
+"function anonymous(bdom, helpers
+) {
+  let { text, createBlock, list, multi, html, toggler, component, comment } = bdom;
+  
+  return function template(ctx, node, key = \\"\\") {
+    const props1 = {prop: ctx['state'].prop};
+    helpers.validateProps(\`Child\`, props1, ctx);
+    return component(\`Child\`, props1, key + \`__1\`, node, ctx);
+  }
+}"
+`;
+
+exports[`lifecycle hooks timeout in onWillUpdateProps emits a warning 2`] = `
+"function anonymous(bdom, helpers
+) {
+  let { text, createBlock, list, multi, html, toggler, component, comment } = bdom;
+  
+  return function template(ctx, node, key = \\"\\") {
+    return text(\`\`);
+  }
+}"
+`;
+
 exports[`lifecycle hooks willPatch, patched hook are called on subsubcomponents, in proper order 1`] = `
 "function anonymous(bdom, helpers
 ) {

tests/components/lifecycle.test.ts

@@ -14,6 +14,7 @@ import {
   logStep,
   makeDeferred,
   makeTestFixture,
+  nextMicroTick,
   nextTick,
   snapshotEverything,
   useLogLifecycle,
@@ -104,6 +105,83 @@ describe("lifecycle hooks", () => {
     await mount(Test, fixture);
   });
 
+  test("timeout in onWillStart emits a warning", async () => {
+    const { warn } = console;
+    let warnArgs: any[];
+    console.warn = jest.fn((...args) => (warnArgs = args));
+    const { setTimeout } = window;
+    let timeoutCbs: any = {};
+    let timeoutId = 0;
+    window.setTimeout = ((cb: any) => {
+      timeoutCbs[++timeoutId] = cb;
+      return timeoutId;
+    }) as any;
+    class Test extends Component {
+      static template = xml`<span/>`;
+      setup() {
+        onWillStart(() => new Promise(() => {}));
+      }
+    }
+    mount(Test, fixture, { test: true });
+    nextTick();
+    for (const id in timeoutCbs) {
+      timeoutCbs[id]();
+      delete timeoutCbs[id];
+    }
+    await nextMicroTick();
+    await nextMicroTick();
+    expect(console.warn).toHaveBeenCalledTimes(1);
+    expect(warnArgs![0]!.message).toBe("onWillStart's promise hasn't resolved after 3 seconds");
+    console.warn = warn;
+    window.setTimeout = setTimeout;
+  });
+
+  test("timeout in onWillUpdateProps emits a warning", async () => {
+    class Child extends Component {
+      static template = xml``;
+      setup() {
+        onWillUpdateProps(() => new Promise(() => {}));
+      }
+    }
+    class Parent extends Component {
+      static template = xml`<Child prop="state.prop"/>`;
+      static components = { Child };
+      state = useState({ prop: 1 });
+    }
+    const parent = await mount(Parent, fixture, { test: true });
+
+    const { warn } = console;
+    let warnArgs: any[];
+    console.warn = jest.fn((...args) => (warnArgs = args));
+    const { setTimeout } = window;
+    let timeoutCbs: any = {};
+    let timeoutId = 0;
+    window.setTimeout = ((cb: any) => {
+      timeoutCbs[++timeoutId] = cb;
+      return timeoutId;
+    }) as any;
+
+    parent.state.prop = 2;
+    let tick = nextTick();
+    for (const id in timeoutCbs) {
+      timeoutCbs[id]();
+      delete timeoutCbs[id];
+    }
+    await tick;
+    tick = nextTick();
+    for (const id in timeoutCbs) {
+      timeoutCbs[id]();
+      delete timeoutCbs[id];
+    }
+    await tick;
+    expect(console.warn).toHaveBeenCalledTimes(1);
+    expect(warnArgs![0]!.message).toBe(
+      "onWillUpdateProps's promise hasn't resolved after 3 seconds"
+    );
+    console.warn = warn;
+    window.setTimeout = setTimeout;
+  });
+
   test("mounted hook is called if mounted in DOM", async () => {
     let mounted = false;
     class Test extends Component {

tests/helpers.ts

@@ -49,7 +49,7 @@ export async function nextTick(): Promise<void> {
 
 interface Deferred extends Promise<any> {
   resolve(val?: any): void;
-  reject(): void;
+  reject(val?: any): void;
 }
 
 export function makeDeferred(): Deferred {