feat(inspector): pipe console messages between terminal and inspector (#11134)

This commit adds support for piping console messages to inspector.

This is done by "wrapping" Deno's console implementation with default
console provided by V8 by the means of "Deno.core.callConsole" binding.

Effectively each call to "console.*" methods calls a method on Deno's
console and V8's console.

cli/tests/integration_tests.rs

@@ -4556,6 +4556,7 @@ console.log("finish");
       child.wait().unwrap();
     }
 
+    #[derive(Debug)]
     enum TestStep {
       StdOut(&'static str),
       StdErr(&'static str),
@@ -4806,6 +4807,9 @@ console.log("finish");
         // Expect the number {i} on stdout.
         let s = i.to_string();
         assert_eq!(stdout_lines.next().unwrap(), s);
+        // Expect console.log
+        let s = r#"{"method":"Runtime.consoleAPICalled","#;
+        assert!(socket_rx.next().await.unwrap().starts_with(s));
         // Expect hitting the `debugger` statement.
         let s = r#"{"method":"Debugger.paused","#;
         assert!(socket_rx.next().await.unwrap().starts_with(s));
@@ -4918,6 +4922,7 @@ console.log("finish");
         WsSend(
           r#"{"id":6,"method":"Runtime.evaluate","params":{"expression":"console.error('done');","objectGroup":"console","includeCommandLineAPI":true,"silent":false,"contextId":1,"returnByValue":true,"generatePreview":true,"userGesture":true,"awaitPromise":false,"replMode":true}}"#,
         ),
+        WsRecv(r#"{"method":"Runtime.consoleAPICalled"#),
         WsRecv(r#"{"id":6,"result":{"result":{"type":"undefined"}}}"#),
         StdErr("done"),
       ];

cli/tests/unit/console_test.ts

@@ -315,25 +315,25 @@ unitTest(function consoleTestStringifyCircular(): void {
   assertEquals(
     stringify(console),
     `console {
-  log: [Function: log],
-  debug: [Function: debug],
-  info: [Function: info],
-  dir: [Function: dir],
-  dirxml: [Function: dir],
-  warn: [Function: warn],
-  error: [Function: error],
-  assert: [Function: assert],
-  count: [Function: count],
-  countReset: [Function: countReset],
-  table: [Function: table],
-  time: [Function: time],
-  timeLog: [Function: timeLog],
-  timeEnd: [Function: timeEnd],
-  group: [Function: group],
-  groupCollapsed: [Function: group],
-  groupEnd: [Function: groupEnd],
-  clear: [Function: clear],
-  trace: [Function: trace],
+  log: [Function: bound ],
+  debug: [Function: bound ],
+  info: [Function: bound ],
+  dir: [Function: bound ],
+  dirxml: [Function: bound ],
+  warn: [Function: bound ],
+  error: [Function: bound ],
+  assert: [Function: bound ],
+  count: [Function: bound ],
+  countReset: [Function: bound ],
+  table: [Function: bound ],
+  time: [Function: bound ],
+  timeLog: [Function: bound ],
+  timeEnd: [Function: bound ],
+  group: [Function: bound ],
+  groupCollapsed: [Function: bound ],
+  groupEnd: [Function: bound ],
+  clear: [Function: bound ],
+  trace: [Function: bound ],
   indentLevel: 0,
   [Symbol(isConsoleInstance)]: true
 }`,

core/bindings.rs

@@ -59,6 +59,9 @@ lazy_static::lazy_static! {
       v8::ExternalReference {
         function: memory_usage.map_fn_to(),
       },
+      v8::ExternalReference {
+        function: call_console.map_fn_to(),
+      },
     ]);
 }
 
@@ -134,6 +137,7 @@ pub fn initialize_context<'s>(
   set_func(scope, core_val, "getPromiseDetails", get_promise_details);
   set_func(scope, core_val, "getProxyDetails", get_proxy_details);
   set_func(scope, core_val, "memoryUsage", memory_usage);
+  set_func(scope, core_val, "callConsole", call_console);
   set_func(scope, core_val, "createHostObject", create_host_object);
 
   // Direct bindings on `window`.
@@ -460,6 +464,54 @@ fn eval_context(
   rv.set(to_v8(tc_scope, output).unwrap());
 }
 
+/// This binding should be used if there's a custom console implementation
+/// available. Using it will make sure that proper stack frames are displayed
+/// in the inspector console.
+///
+/// Each method on console object should be bound to this function, eg:
+/// ```ignore
+/// function wrapConsole(consoleFromDeno, consoleFromV8) {
+///   const callConsole = core.callConsole;
+///
+///   for (const key of Object.keys(consoleFromV8)) {
+///     if (consoleFromDeno.hasOwnProperty(key)) {
+///       consoleFromDeno[key] = callConsole.bind(
+///         consoleFromDeno,
+///         consoleFromV8[key],
+///         consoleFromDeno[key],
+///       );
+///     }
+///   }
+/// }
+/// ```
+///
+/// Inspired by:
+/// https://github.com/nodejs/node/blob/1317252dfe8824fd9cfee125d2aaa94004db2f3b/src/inspector_js_api.cc#L194-L222
+fn call_console(
+  scope: &mut v8::HandleScope,
+  args: v8::FunctionCallbackArguments,
+  _rv: v8::ReturnValue,
+) {
+  assert!(args.length() >= 2);
+
+  assert!(args.get(0).is_function());
+  assert!(args.get(1).is_function());
+
+  let mut call_args = vec![];
+  for i in 2..args.length() {
+    call_args.push(args.get(i));
+  }
+
+  let receiver = args.this();
+  let inspector_console_method =
+    v8::Local::<v8::Function>::try_from(args.get(0)).unwrap();
+  let deno_console_method =
+    v8::Local::<v8::Function>::try_from(args.get(1)).unwrap();
+
+  inspector_console_method.call(scope, receiver.into(), &call_args);
+  deno_console_method.call(scope, receiver.into(), &call_args);
+}
+
 fn encode(
   scope: &mut v8::HandleScope,
   args: v8::FunctionCallbackArguments,

extensions/console/02_console.js

@@ -1774,6 +1774,32 @@
     });
   }
 
+  // A helper function that will bind our own console implementation
+  // with default implementation of Console from V8. This will cause
+  // console messages to be piped to inspector console.
+  //
+  // We are using `Deno.core.callConsole` binding to preserve proper stack
+  // frames in inspector console. This has to be done because V8 considers
+  // the last JS stack frame as gospel for the inspector. In our case we
+  // specifically want the latest user stack frame to be the one that matters
+  // though.
+  //
+  // Inspired by:
+  // https://github.com/nodejs/node/blob/1317252dfe8824fd9cfee125d2aaa94004db2f3b/lib/internal/util/inspector.js#L39-L61
+  function wrapConsole(consoleFromDeno, consoleFromV8) {
+    const callConsole = core.callConsole;
+
+    for (const key of Object.keys(consoleFromV8)) {
+      if (consoleFromDeno.hasOwnProperty(key)) {
+        consoleFromDeno[key] = callConsole.bind(
+          consoleFromDeno,
+          consoleFromV8[key],
+          consoleFromDeno[key],
+        );
+      }
+    }
+  }
+
   // Expose these fields to internalObject for tests.
   window.__bootstrap.internals = {
     ...window.__bootstrap.internals ?? {},
@@ -1790,5 +1816,6 @@
     Console,
     customInspect,
     inspect,
+    wrapConsole,
   };
 })(this);

runtime/js/99_main.js

@@ -459,6 +459,10 @@ delete Object.prototype.__proto__;
     if (hasBootstrapped) {
       throw new Error("Worker runtime already bootstrapped");
     }
+
+    const consoleFromV8 = window.console;
+    const wrapConsole = window.__bootstrap.console.wrapConsole;
+
     // Remove bootstrapping data from the global scope
     delete globalThis.__bootstrap;
     delete globalThis.bootstrap;
@@ -467,6 +471,10 @@ delete Object.prototype.__proto__;
     Object.defineProperties(globalThis, windowOrWorkerGlobalScope);
     Object.defineProperties(globalThis, mainRuntimeGlobalProperties);
     Object.setPrototypeOf(globalThis, Window.prototype);
+
+    const consoleFromDeno = globalThis.console;
+    wrapConsole(consoleFromDeno, consoleFromV8);
+
     eventTarget.setEventTargetData(globalThis);
 
     defineEventHandler(window, "load", null);
@@ -539,6 +547,10 @@ delete Object.prototype.__proto__;
     if (hasBootstrapped) {
       throw new Error("Worker runtime already bootstrapped");
     }
+
+    const consoleFromV8 = window.console;
+    const wrapConsole = window.__bootstrap.console.wrapConsole;
+
     // Remove bootstrapping data from the global scope
     delete globalThis.__bootstrap;
     delete globalThis.bootstrap;
@@ -548,6 +560,10 @@ delete Object.prototype.__proto__;
     Object.defineProperties(globalThis, workerRuntimeGlobalProperties);
     Object.defineProperties(globalThis, { name: util.readOnly(name) });
     Object.setPrototypeOf(globalThis, DedicatedWorkerGlobalScope.prototype);
+
+    const consoleFromDeno = globalThis.console;
+    wrapConsole(consoleFromDeno, consoleFromV8);
+
     eventTarget.setEventTargetData(globalThis);
 
     runtimeStart(