From 003b5eacaf9fcc135532c28206698b4753a8b47a Mon Sep 17 00:00:00 2001 From: Pavel Savara Date: Thu, 18 May 2023 15:09:43 +0200 Subject: [PATCH] [browser] logging cleanup (#86431) * introduce logging functions --- src/mono/wasm/runtime/.eslintrc.cjs | 1 + src/mono/wasm/runtime/assets.ts | 23 +++--- src/mono/wasm/runtime/cwraps.ts | 21 +++--- src/mono/wasm/runtime/debug.ts | 9 ++- .../runtime/diagnostics/browser/controller.ts | 13 ++-- src/mono/wasm/runtime/diagnostics/index.ts | 11 +-- .../wasm/runtime/diagnostics/mock/index.ts | 71 +++++++------------ .../diagnostics/server_pthread/index.ts | 35 ++++----- .../server_pthread/ipc-protocol/parser.ts | 5 +- .../diagnostics/server_pthread/mock-remote.ts | 3 +- .../server_pthread/protocol-socket.ts | 21 +++--- .../server_pthread/socket-connection.ts | 7 +- src/mono/wasm/runtime/exports-internal.ts | 2 +- src/mono/wasm/runtime/exports.ts | 6 +- src/mono/wasm/runtime/http.ts | 2 +- src/mono/wasm/runtime/invoke-cs.ts | 5 +- src/mono/wasm/runtime/invoke-js.ts | 18 ++--- .../wasm/runtime/jiterpreter-interp-entry.ts | 15 ++-- src/mono/wasm/runtime/jiterpreter-jit-call.ts | 27 +++---- src/mono/wasm/runtime/jiterpreter-support.ts | 71 ++++++++++--------- .../runtime/jiterpreter-trace-generator.ts | 57 +++++++-------- src/mono/wasm/runtime/jiterpreter.ts | 57 +++++++-------- src/mono/wasm/runtime/loader/assets.ts | 23 +++--- .../blazor/WebAssemblyResourceLoader.ts | 8 +++ src/mono/wasm/runtime/loader/config.ts | 7 +- src/mono/wasm/runtime/loader/exit.ts | 16 ++--- src/mono/wasm/runtime/loader/icu.ts | 9 +-- src/mono/wasm/runtime/loader/logging.ts | 26 +++++++ src/mono/wasm/runtime/loader/polyfills.ts | 2 + src/mono/wasm/runtime/loader/run.ts | 4 +- src/mono/wasm/runtime/loader/worker.ts | 5 +- src/mono/wasm/runtime/logging.ts | 25 ++++++- src/mono/wasm/runtime/marshal-to-js.ts | 2 - .../runtime/net6-legacy/method-binding.ts | 7 +- src/mono/wasm/runtime/polyfills.ts | 5 +- .../wasm/runtime/pthreads/browser/index.ts | 7 +- .../shared/emscripten-replacements.ts | 6 +- .../wasm/runtime/pthreads/worker/index.ts | 15 ++-- src/mono/wasm/runtime/rollup.config.js | 1 + src/mono/wasm/runtime/run.ts | 3 +- src/mono/wasm/runtime/snapshot.ts | 9 +-- src/mono/wasm/runtime/startup.ts | 68 +++++++++--------- src/mono/wasm/runtime/web-socket.ts | 3 +- 43 files changed, 390 insertions(+), 341 deletions(-) diff --git a/src/mono/wasm/runtime/.eslintrc.cjs b/src/mono/wasm/runtime/.eslintrc.cjs index dc9e8df25e432..5cdee1555241a 100644 --- a/src/mono/wasm/runtime/.eslintrc.cjs +++ b/src/mono/wasm/runtime/.eslintrc.cjs @@ -37,6 +37,7 @@ module.exports = { } ], "no-multi-spaces": ["error"], + "no-console": ["error"], "arrow-spacing": ["error"], "block-spacing": ["error"], "comma-spacing": ["error"], diff --git a/src/mono/wasm/runtime/assets.ts b/src/mono/wasm/runtime/assets.ts index 489f482716826..a459b11072567 100644 --- a/src/mono/wasm/runtime/assets.ts +++ b/src/mono/wasm/runtime/assets.ts @@ -4,7 +4,7 @@ import cwraps from "./cwraps"; import { mono_wasm_load_icu_data } from "./icu"; import { ENVIRONMENT_IS_SHELL, ENVIRONMENT_IS_WEB, Module, loaderHelpers, runtimeHelpers } from "./globals"; -import { parseSymbolMapFile } from "./logging"; +import { mono_log_info, mono_log_debug, mono_log_warn, parseSymbolMapFile } from "./logging"; import { mono_wasm_load_bytes_into_heap } from "./memory"; import { endMeasure, MeasuredBlock, startMeasure } from "./profiler"; import { AssetEntryInternal } from "./types/internal"; @@ -13,8 +13,7 @@ import { InstantiateWasmSuccessCallback, VoidPtr } from "./types/emscripten"; // this need to be run only after onRuntimeInitialized event, when the memory is ready export function instantiate_asset(asset: AssetEntry, url: string, bytes: Uint8Array): void { - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: Loaded:${asset.name} as ${asset.behavior} size ${bytes.length} from ${url}`); + mono_log_debug(`Loaded:${asset.name} as ${asset.behavior} size ${bytes.length} from ${url}`); const mark = startMeasure(); const virtualName: string = typeof (asset.virtualPath) === "string" @@ -50,8 +49,7 @@ export function instantiate_asset(asset: AssetEntry, url: string, bytes: Uint8Ar if (fileName.startsWith("/")) fileName = fileName.substr(1); if (parentDirectory) { - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: Creating directory '${parentDirectory}'`); + mono_log_debug(`Creating directory '${parentDirectory}'`); Module.FS_createPath( "/", parentDirectory, true, true // fixme: should canWrite be false? @@ -60,8 +58,7 @@ export function instantiate_asset(asset: AssetEntry, url: string, bytes: Uint8Ar parentDirectory = "/"; } - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: Creating file '${fileName}' in directory '${parentDirectory}'`); + mono_log_debug(`Creating file '${fileName}' in directory '${parentDirectory}'`); if (!mono_wasm_load_data_archive(bytes, parentDirectory)) { Module.FS_createDataFile( @@ -90,7 +87,7 @@ export function instantiate_asset(asset: AssetEntry, url: string, bytes: Uint8Ar } else if (asset.behavior === "icu") { if (!mono_wasm_load_icu_data(offset!)) - Module.err(`MONO_WASM: Error loading ICU asset ${asset.name}`); + Module.err(`Error loading ICU asset ${asset.name}`); } else if (asset.behavior === "resource") { cwraps.mono_wasm_add_satellite_assembly(virtualName, asset.culture || "", offset!, bytes.length); @@ -110,16 +107,16 @@ export async function instantiate_wasm_asset( let compiledInstance: WebAssembly.Instance; let compiledModule: WebAssembly.Module; if (typeof WebAssembly.instantiateStreaming === "function" && contentType === "application/wasm") { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: instantiate_wasm_module streaming"); + mono_log_debug("instantiate_wasm_module streaming"); const streamingResult = await WebAssembly.instantiateStreaming(response, wasmModuleImports!); compiledInstance = streamingResult.instance; compiledModule = streamingResult.module; } else { if (ENVIRONMENT_IS_WEB && contentType !== "application/wasm") { - console.warn("MONO_WASM: WebAssembly resource does not have the expected content type \"application/wasm\", so falling back to slower ArrayBuffer instantiation."); + mono_log_warn("WebAssembly resource does not have the expected content type \"application/wasm\", so falling back to slower ArrayBuffer instantiation."); } const arrayBuffer = await response.arrayBuffer(); - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: instantiate_wasm_module buffered"); + mono_log_debug("instantiate_wasm_module buffered"); if (ENVIRONMENT_IS_SHELL) { // workaround for old versions of V8 with https://bugs.chromium.org/p/v8/issues/detail?id=13823 compiledModule = new WebAssembly.Module(arrayBuffer); @@ -139,7 +136,7 @@ export async function instantiate_symbols_asset(pendingAsset: AssetEntryInternal const text = await response.text(); parseSymbolMapFile(text); } catch (error: any) { - console.log(`MONO_WASM: Error loading symbol file ${pendingAsset.name}: ${JSON.stringify(error)}`); + mono_log_info(`Error loading symbol file ${pendingAsset.name}: ${JSON.stringify(error)}`); } } @@ -199,7 +196,7 @@ export async function wait_for_all_assets() { mono_assert(loaderHelpers.actual_downloaded_assets_count == loaderHelpers.expected_downloaded_assets_count, () => `Expected ${loaderHelpers.expected_downloaded_assets_count} assets to be downloaded, but only finished ${loaderHelpers.actual_downloaded_assets_count}`); mono_assert(loaderHelpers.actual_instantiated_assets_count == loaderHelpers.expected_instantiated_assets_count, () => `Expected ${loaderHelpers.expected_instantiated_assets_count} assets to be in memory, but only instantiated ${loaderHelpers.actual_instantiated_assets_count}`); loaderHelpers._loaded_files.forEach(value => loaderHelpers.loadedFiles.push(value.url)); - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: all assets are loaded in wasm memory"); + mono_log_debug("all assets are loaded in wasm memory"); } } diff --git a/src/mono/wasm/runtime/cwraps.ts b/src/mono/wasm/runtime/cwraps.ts index 225cdef57e293..715a3936cec07 100644 --- a/src/mono/wasm/runtime/cwraps.ts +++ b/src/mono/wasm/runtime/cwraps.ts @@ -9,6 +9,7 @@ import type { import type { VoidPtr, CharPtrPtr, Int32Ptr, CharPtr, ManagedPointer } from "./types/emscripten"; import WasmEnableLegacyJsInterop from "consts:WasmEnableLegacyJsInterop"; import { disableLegacyJsInterop, Module } from "./globals"; +import { mono_log_error } from "./logging"; type SigLine = [lazy: boolean, name: string, returnType: string | null, argTypes?: string[], opts?: any]; @@ -252,7 +253,7 @@ export interface t_Cwraps { mono_jiterp_get_opcode_value_table_entry(opcode: number): number; mono_jiterp_get_simd_intrinsic(arity: number, index: number): VoidPtr; mono_jiterp_get_simd_opcode(arity: number, index: number): number; - mono_jiterp_get_arg_offset (imethod: number, sig: number, index: number): number; + mono_jiterp_get_arg_offset(imethod: number, sig: number, index: number): number; mono_jiterp_get_opcode_info(opcode: number, type: number): number; } @@ -270,23 +271,23 @@ export const enum I52Error { const fastCwrapTypes = ["void", "number", null]; -function cwrap (name: string, returnType: string | null, argTypes: string[] | undefined, opts: any, throwOnError: boolean) : Function { +function cwrap(name: string, returnType: string | null, argTypes: string[] | undefined, opts: any, throwOnError: boolean): Function { // Attempt to bypass emscripten's generated wrapper if it is safe to do so let fce = // Special cwrap options disable the fast path (typeof (opts) === "undefined") && - // Only attempt to do fast calls if all the args and the return type are either number or void - (fastCwrapTypes.indexOf(returnType) >= 0) && - (!argTypes || argTypes.every(atype => fastCwrapTypes.indexOf(atype) >= 0)) && - // Module["asm"] may not be defined yet if we are early enough in the startup process - // in that case, we need to rely on emscripten's lazy wrappers - Module["asm"] + // Only attempt to do fast calls if all the args and the return type are either number or void + (fastCwrapTypes.indexOf(returnType) >= 0) && + (!argTypes || argTypes.every(atype => fastCwrapTypes.indexOf(atype) >= 0)) && + // Module["asm"] may not be defined yet if we are early enough in the startup process + // in that case, we need to rely on emscripten's lazy wrappers + Module["asm"] ? ((Module["asm"])[name]) : undefined; // If the argument count for the wasm function doesn't match the signature, fall back to cwrap if (fce && argTypes && (fce.length !== argTypes.length)) { - console.error(`MONO_WASM: argument count mismatch for cwrap ${name}`); + mono_log_error(`argument count mismatch for cwrap ${name}`); fce = undefined; } @@ -299,7 +300,7 @@ function cwrap (name: string, returnType: string | null, argTypes: string[] | un if (throwOnError) throw new Error(msg); else - console.error("MONO_WASM: " + msg); + mono_log_error("" + msg); } return fce; } diff --git a/src/mono/wasm/runtime/debug.ts b/src/mono/wasm/runtime/debug.ts index 7dcc132ff4518..044758caf4a97 100644 --- a/src/mono/wasm/runtime/debug.ts +++ b/src/mono/wasm/runtime/debug.ts @@ -6,6 +6,7 @@ import { INTERNAL, Module, runtimeHelpers } from "./globals"; import { toBase64StringImpl } from "./base64"; import cwraps from "./cwraps"; import { VoidPtr, CharPtr } from "./types/emscripten"; +import { mono_log_warn } from "./logging"; const commands_received: any = new Map(); commands_received.remove = function (key: number): CommandResponse { const value = this.get(key); this.delete(key); return value; }; let _call_function_res_cache: any = {}; @@ -31,6 +32,7 @@ export function mono_wasm_runtime_ready(): void { export function mono_wasm_fire_debugger_agent_message_with_data_to_pause(base64String: string): void { //keep this console.assert, otherwise optimization will remove the assignments + // eslint-disable-next-line no-console console.assert(true, `mono_wasm_fire_debugger_agent_message_with_data ${base64String}`); // eslint-disable-next-line no-debugger debugger; @@ -52,7 +54,7 @@ export function mono_wasm_add_dbg_command_received(res_ok: boolean, id: number, } }; if (commands_received.has(id)) - console.warn(`MONO_WASM: Adding an id (${id}) that already exists in commands_received`); + mono_log_warn(`Adding an id (${id}) that already exists in commands_received`); commands_received.set(id, buffer_obj); } @@ -124,6 +126,7 @@ export function mono_wasm_raise_debug_event(event: WasmEvent, args = {}): void { if (typeof args !== "object") throw new Error(`args must be an object, but got ${JSON.stringify(args)}`); + // eslint-disable-next-line no-console console.debug("mono_wasm_debug_event_raised:aef14bca-5519-4dfe-b35a-f867abc123ae", JSON.stringify(event), JSON.stringify(args)); } @@ -150,6 +153,7 @@ export function mono_wasm_set_entrypoint_breakpoint(assembly_name: CharPtr, entr _assembly_name_str = Module.UTF8ToString(assembly_name).concat(".dll"); _entrypoint_method_token = entrypoint_method_token; //keep this console.assert, otherwise optimization will remove the assignments + // eslint-disable-next-line no-console console.assert(true, `Adding an entrypoint breakpoint ${_assembly_name_str} at method token ${_entrypoint_method_token}`); // eslint-disable-next-line no-debugger debugger; @@ -345,7 +349,8 @@ export function mono_wasm_debugger_log(level: number, message_ptr: CharPtr): voi } if (BuildConfiguration === "Debug") { - console.debug(`MONO_WASM: Debugger.Debug: ${message}`); + // eslint-disable-next-line no-console + console.debug(`Debugger.Debug: ${message}`); } } diff --git a/src/mono/wasm/runtime/diagnostics/browser/controller.ts b/src/mono/wasm/runtime/diagnostics/browser/controller.ts index 9eedcdd80aaef..3f3c9213c8362 100644 --- a/src/mono/wasm/runtime/diagnostics/browser/controller.ts +++ b/src/mono/wasm/runtime/diagnostics/browser/controller.ts @@ -3,6 +3,7 @@ import cwraps from "../../cwraps"; import { INTERNAL } from "../../globals"; +import { mono_log_info, mono_log_debug, mono_log_warn } from "../../logging"; import { withStackAlloc, getI32 } from "../../memory"; import { Thread, waitForThread } from "../../pthreads/browser"; import { isDiagnosticMessage, makeDiagnosticServerControlCommand } from "../shared/controller-commands"; @@ -18,15 +19,15 @@ class ServerControllerImpl implements ServerController { server.port.addEventListener("message", this.onServerReply.bind(this)); } start(): void { - console.debug("MONO_WASM: signaling the diagnostic server to start"); + mono_log_debug("signaling the diagnostic server to start"); this.server.postMessageToWorker(makeDiagnosticServerControlCommand("start")); } stop(): void { - console.debug("MONO_WASM: signaling the diagnostic server to stop"); + mono_log_debug("signaling the diagnostic server to stop"); this.server.postMessageToWorker(makeDiagnosticServerControlCommand("stop")); } postServerAttachToRuntime(): void { - console.debug("MONO_WASM: signal the diagnostic server to attach to the runtime"); + mono_log_debug("signal the diagnostic server to attach to the runtime"); this.server.postMessageToWorker(makeDiagnosticServerControlCommand("attach_to_runtime")); } @@ -35,7 +36,7 @@ class ServerControllerImpl implements ServerController { if (isDiagnosticMessage(d)) { switch (d.cmd) { default: - console.warn("MONO_WASM: Unknown control reply command: ", d); + mono_log_warn("Unknown control reply command: ", d); break; } } @@ -52,7 +53,7 @@ export function getController(): ServerController { export async function startDiagnosticServer(websocket_url: string): Promise { const sizeOfPthreadT = 4; - console.info(`MONO_WASM: starting the diagnostic server url: ${websocket_url}`); + mono_log_info(`starting the diagnostic server url: ${websocket_url}`); const result: number | undefined = withStackAlloc(sizeOfPthreadT, (pthreadIdPtr) => { if (!cwraps.mono_wasm_diagnostic_server_create_thread(websocket_url, pthreadIdPtr)) return undefined; @@ -60,7 +61,7 @@ export async function startDiagnosticServer(websocket_url: string): Promise { if (diagnosticsInitialized) return; if (!monoWasmThreads) { - console.warn("MONO_WASM: ignoring diagnostics options because this runtime does not support diagnostics"); + mono_log_warn("ignoring diagnostics options because this runtime does not support diagnostics"); return; } else { const options = diagnostic_options_from_environment(); @@ -96,12 +97,12 @@ function diagnostic_options_from_ports_spec(val: string): DiagnosticOptions | nu if (ports.length === 0) return null; if (ports.length !== 1) { - console.warn("MONO_WASM: multiple diagnostic ports specified, only the last one will be used"); + mono_log_warn("multiple diagnostic ports specified, only the last one will be used"); } const portSpec = ports[ports.length - 1]; const components = portSpec.split(","); if (components.length < 1 || components.length > 3) { - console.warn("MONO_WASM: invalid diagnostic port specification, should be of the form [,],[]"); + mono_log_warn("invalid diagnostic port specification, should be of the form [,],[]"); return null; } const uri: string = components[0]; @@ -124,12 +125,12 @@ function diagnostic_options_from_ports_spec(val: string): DiagnosticOptions | nu connect = true; break; default: - console.warn(`MONO_WASM: invalid diagnostic port specification component: ${component}`); + mono_log_warn(`invalid diagnostic port specification component: ${component}`); break; } } if (!connect) { - console.warn("MONO_WASM: this runtime does not support listening on a diagnostic port; no diagnostic server started"); + mono_log_warn("this runtime does not support listening on a diagnostic port; no diagnostic server started"); return null; } return { diff --git a/src/mono/wasm/runtime/diagnostics/mock/index.ts b/src/mono/wasm/runtime/diagnostics/mock/index.ts index 30d08017ebb6f..8130415407133 100644 --- a/src/mono/wasm/runtime/diagnostics/mock/index.ts +++ b/src/mono/wasm/runtime/diagnostics/mock/index.ts @@ -6,6 +6,7 @@ import monoDiagnosticsMock from "consts:monoDiagnosticsMock"; import { createMockEnvironment } from "./environment"; import type { MockEnvironment, MockScriptConnection } from "./export-types"; import { assertNever } from "../../types/internal"; +import { mono_log_debug, mono_log_warn } from "../../logging"; export interface MockRemoteSocket extends EventTarget { addEventListener(type: T, listener: (this: MockRemoteSocket, ev: WebSocketEventMap[T]) => any, options?: boolean | AddEventListenerOptions): void; @@ -20,23 +21,17 @@ export interface Mock { run(): Promise; } -interface MockOptions { - readonly trace: boolean; -} - type MockConnectionScript = (engine: MockScriptConnection) => Promise; export type MockScript = (env: MockEnvironment) => MockConnectionScript[]; -let MockImplConstructor: new (script: MockScript, options?: MockOptions) => Mock; -export function mock(script: MockScript, options?: MockOptions): Mock { +let MockImplConstructor: new (script: MockScript) => Mock; +export function mock(script: MockScript): Mock { if (monoDiagnosticsMock) { if (!MockImplConstructor) { class MockScriptEngineSocketImpl implements MockRemoteSocket { constructor(private readonly engine: MockScriptEngineImpl) { } send(data: string | ArrayBuffer): void { - if (this.engine.trace) { - console.debug(`mock ${this.engine.ident} client sent: `, data); - } + mono_log_debug(`mock ${this.engine.ident} client sent: `, data); let event: MessageEvent | null = null; if (typeof data === "string") { event = new MessageEvent("message", { data }); @@ -51,21 +46,15 @@ export function mock(script: MockScript, options?: MockOptions): Mock { } addEventListener(event: T, listener: (event: WebSocketEventMap[T]) => any, options?: boolean | AddEventListenerOptions): void; addEventListener(event: string, listener: EventListenerOrEventListenerObject, options?: boolean | AddEventListenerOptions): void { - if (this.engine.trace) { - console.debug(`mock ${this.engine.ident} client added listener for ${event}`); - } + mono_log_debug(`mock ${this.engine.ident} client added listener for ${event}`); this.engine.eventTarget.addEventListener(event, listener, options); } removeEventListener(event: string, listener: EventListenerOrEventListenerObject): void { - if (this.engine.trace) { - console.debug(`mock ${this.engine.ident} client removed listener for ${event}`); - } + mono_log_debug(`mock ${this.engine.ident} client removed listener for ${event}`); this.engine.eventTarget.removeEventListener(event, listener); } close(): void { - if (this.engine.trace) { - console.debug(`mock ${this.engine.ident} client closed`); - } + mono_log_debug(`mock ${this.engine.ident} client closed`); this.engine.mockReplyEventTarget.dispatchEvent(new CloseEvent("close")); } dispatchEvent(ev: Event): boolean { @@ -79,14 +68,12 @@ export function mock(script: MockScript, options?: MockOptions): Mock { readonly eventTarget: EventTarget = new EventTarget(); // eventTarget that the MockReplySocket with send() to readonly mockReplyEventTarget: EventTarget = new EventTarget(); - constructor(readonly trace: boolean, readonly ident: number) { + constructor(readonly ident: number) { this.socket = new MockScriptEngineSocketImpl(this); } reply(data: ArrayBuffer | Uint8Array) { - if (this.trace) { - console.debug(`mock ${this.ident} reply:`, data); - } + mono_log_debug(`mock ${this.ident} reply:`, data); let sendData: ArrayBuffer; if (typeof data === "object" && data instanceof ArrayBuffer) { sendData = new ArrayBuffer(data.byteLength); @@ -98,17 +85,15 @@ export function mock(script: MockScript, options?: MockOptions): Mock { const sendDataView = new Uint8Array(sendData); sendDataView.set(data); } else { - console.warn(`mock ${this.ident} reply got wrong kind of reply data, expected ArrayBuffer`, data); + mono_log_warn(`mock ${this.ident} reply got wrong kind of reply data, expected ArrayBuffer`, data); assertNever(data); } this.eventTarget.dispatchEvent(new MessageEvent("message", { data: sendData })); } processSend(onMessage: (data: ArrayBuffer) => any): Promise { - const trace = this.trace; - if (trace) { - console.debug(`mock ${this.ident} processSend`); - } + mono_log_debug(`mock ${this.ident} processSend`); + return new Promise((resolve, reject) => { this.mockReplyEventTarget.addEventListener("close", () => { resolve(); @@ -116,33 +101,29 @@ export function mock(script: MockScript, options?: MockOptions): Mock { this.mockReplyEventTarget.addEventListener("message", (event: any) => { const data = event.data; if (typeof data === "string") { - console.warn(`mock ${this.ident} waitForSend got string:`, data); + mono_log_warn(`mock ${this.ident} waitForSend got string:`, data); reject(new Error("mock script connection received string data")); } - if (trace) { - console.debug(`mock ${this.ident} processSend got:`, data.byteLength); - } + mono_log_debug(`mock ${this.ident} processSend got:`, data.byteLength); + onMessage(data); }); }); } async waitForSend(filter: (data: ArrayBuffer) => boolean, extract?: (data: ArrayBuffer) => T): Promise { - const trace = this.trace; - if (trace) { - console.debug(`mock ${this.ident} waitForSend`); - } + mono_log_debug(`mock ${this.ident} waitForSend`); + const data = await new Promise((resolve) => { this.mockReplyEventTarget.addEventListener("message", (event: any) => { const data = event.data; if (typeof data === "string") { - console.warn(`mock ${this.ident} waitForSend got string:`, data); + mono_log_warn(`mock ${this.ident} waitForSend got string:`, data); throw new Error("mock script connection received string data"); } - if (trace) { - console.debug(`mock ${this.ident} waitForSend got:`, data.byteLength); - } + mono_log_debug(`mock ${this.ident} waitForSend got:`, data.byteLength); + resolve(data); }, { once: true }); }); @@ -160,23 +141,19 @@ export function mock(script: MockScript, options?: MockOptions): Mock { openCount: number; engines: MockScriptEngineImpl[]; connectionScripts: MockConnectionScript[]; - readonly trace: boolean; - constructor(public readonly mockScript: MockScript, options?: MockOptions) { + constructor(public readonly mockScript: MockScript) { const env: MockEnvironment = createMockEnvironment(); this.connectionScripts = mockScript(env); this.openCount = 0; - this.trace = options?.trace ?? false; const count = this.connectionScripts.length; this.engines = new Array(count); for (let i = 0; i < count; ++i) { - this.engines[i] = new MockScriptEngineImpl(this.trace, i); + this.engines[i] = new MockScriptEngineImpl(i); } } open(): MockRemoteSocket { const i = this.openCount++; - if (this.trace) { - console.debug(`mock ${i} open`); - } + mono_log_debug(`mock ${i} open`); return this.engines[i].socket; } @@ -186,7 +163,7 @@ export function mock(script: MockScript, options?: MockOptions): Mock { } }; } - return new MockImplConstructor(script, options); + return new MockImplConstructor(script); } else { return undefined as unknown as Mock; } diff --git a/src/mono/wasm/runtime/diagnostics/server_pthread/index.ts b/src/mono/wasm/runtime/diagnostics/server_pthread/index.ts index 6180834a90650..6970fbae7c4a1 100644 --- a/src/mono/wasm/runtime/diagnostics/server_pthread/index.ts +++ b/src/mono/wasm/runtime/diagnostics/server_pthread/index.ts @@ -46,6 +46,7 @@ import { createAdvertise, createBinaryCommandOKReply, } from "./ipc-protocol/serializer"; +import { mono_log_error, mono_log_info, mono_log_debug, mono_log_warn } from "../../logging"; function addOneShotProtocolCommandEventListener(src: EventTarget): Promise { return new Promise((resolve) => { @@ -83,7 +84,7 @@ class DiagnosticServerImpl implements DiagnosticServer { private attachToRuntimeController = createPromiseController().promise_control; start(): void { - console.log(`MONO_WASM: starting diagnostic server with url: ${this.websocketUrl}`); + mono_log_info(`starting diagnostic server with url: ${this.websocketUrl}`); this.startRequestedController.resolve(); } stop(): void { @@ -100,7 +101,7 @@ class DiagnosticServerImpl implements DiagnosticServer { await this.startRequestedController.promise; await this.attachToRuntimeController.promise; // can't start tracing until we've attached to the runtime while (!this.stopRequested) { - console.debug("MONO_WASM: diagnostic server: advertising and waiting for client"); + mono_log_debug("diagnostic server: advertising and waiting for client"); const p1: Promise<"first" | "second"> = this.advertiseAndWaitForClient().then(() => "first"); const p2: Promise<"first" | "second"> = this.stopRequestedController.promise.then(() => "second"); const result = await Promise.race([p1, p2]); @@ -108,7 +109,7 @@ class DiagnosticServerImpl implements DiagnosticServer { case "first": break; case "second": - console.debug("MONO_WASM: stop requested"); + mono_log_debug("stop requested"); break; default: assertNever(result); @@ -132,12 +133,12 @@ class DiagnosticServerImpl implements DiagnosticServer { async advertiseAndWaitForClient(): Promise { try { const connNum = this.openCount++; - console.debug("MONO_WASM: opening websocket and sending ADVR_V1", connNum); + mono_log_debug("opening websocket and sending ADVR_V1", connNum); const ws = await this.openSocket(); const p = addOneShotProtocolCommandEventListener(createProtocolSocket(ws)); this.sendAdvertise(ws); const message = await p; - console.debug("MONO_WASM: received advertising response: ", message, connNum); + mono_log_debug("received advertising response: ", message, connNum); queueMicrotask(() => this.parseAndDispatchMessage(ws, connNum, message)); } finally { // if there were errors, resume the runtime anyway @@ -149,14 +150,14 @@ class DiagnosticServerImpl implements DiagnosticServer { try { const cmd = this.parseCommand(message, connNum); if (cmd === null) { - console.error("MONO_WASM: unexpected message from client", message, connNum); + mono_log_error("unexpected message from client", message, connNum); return; } else if (isEventPipeCommand(cmd)) { await this.dispatchEventPipeCommand(ws, cmd); } else if (isProcessCommand(cmd)) { await this.dispatchProcessCommand(ws, cmd); // resume } else { - console.warn("MONO_WASM Client sent unknown command", cmd); + mono_log_warn("MONO_WASM Client sent unknown command", cmd); } } finally { // if there were errors, resume the runtime anyway @@ -176,13 +177,13 @@ class DiagnosticServerImpl implements DiagnosticServer { } parseCommand(message: ProtocolCommandEvent, connNum: number): ProtocolClientCommandBase | null { - console.debug("MONO_WASM: parsing byte command: ", message.data, connNum); + mono_log_debug("parsing byte command: ", message.data, connNum); const result = parseProtocolCommand(message.data); - console.debug("MONO_WASM: parsed byte command: ", result, connNum); + mono_log_debug("parsed byte command: ", result, connNum); if (result.success) { return result.result; } else { - console.warn("MONO_WASM: failed to parse command: ", result.error, connNum); + mono_log_warn("failed to parse command: ", result.error, connNum); return null; } } @@ -207,7 +208,7 @@ class DiagnosticServerImpl implements DiagnosticServer { this.attachToRuntime(); break; default: - console.warn("MONO_WASM: Unknown control command: ", cmd); + mono_log_warn("Unknown control command: ", cmd); break; } } @@ -219,7 +220,7 @@ class DiagnosticServerImpl implements DiagnosticServer { } else if (isEventPipeCommandStopTracing(cmd)) { await this.stopEventPipe(ws, cmd.sessionID); } else { - console.warn("MONO_WASM: unknown EventPipe command: ", cmd); + mono_log_warn("unknown EventPipe command: ", cmd); } } @@ -229,7 +230,7 @@ class DiagnosticServerImpl implements DiagnosticServer { } async stopEventPipe(ws: WebSocket | MockRemoteSocket, sessionID: EventPipeSessionIDImpl): Promise { - console.debug("MONO_WASM: stopEventPipe", sessionID); + mono_log_debug("stopEventPipe", sessionID); cwraps.mono_wasm_event_pipe_session_disable(sessionID); // we might send OK before the session is actually stopped since the websocket is async // but the client end should be robust to that. @@ -245,7 +246,7 @@ class DiagnosticServerImpl implements DiagnosticServer { sessionIDbuf[3] = (session.sessionID >> 24) & 0xFF; // sessionIDbuf[4..7] is 0 because all our session IDs are 32-bit this.postClientReplyOK(ws, sessionIDbuf); - console.debug("MONO_WASM: created session, now streaming: ", session); + mono_log_debug("created session, now streaming: ", session); cwraps.mono_wasm_event_pipe_session_start_streaming(session.sessionID); } @@ -254,7 +255,7 @@ class DiagnosticServerImpl implements DiagnosticServer { if (isProcessCommandResumeRuntime(cmd)) { this.processResumeRuntime(ws); } else { - console.warn("MONO_WASM: unknown Process command", cmd); + mono_log_warn("unknown Process command", cmd); } } @@ -265,7 +266,7 @@ class DiagnosticServerImpl implements DiagnosticServer { resumeRuntime(): void { if (!this.runtimeResumed) { - console.debug("MONO_WASM: resuming runtime startup"); + mono_log_debug("resuming runtime startup"); cwraps.mono_wasm_diagnostic_server_post_resume_runtime(); this.runtimeResumed = true; } @@ -283,7 +284,7 @@ function parseProtocolCommand(data: ArrayBuffer | BinaryProtocolCommand): ParseC /// Called by the runtime to initialize the diagnostic server workers export function mono_wasm_diagnostic_server_on_server_thread_created(websocketUrlPtr: CharPtr): void { const websocketUrl = Module.UTF8ToString(websocketUrlPtr); - console.debug(`mono_wasm_diagnostic_server_on_server_thread_created, url ${websocketUrl}`); + mono_log_debug(`mono_wasm_diagnostic_server_on_server_thread_created, url ${websocketUrl}`); let mock: PromiseAndController | undefined = undefined; if (monoDiagnosticsMock && websocketUrl.startsWith("mock:")) { mock = createPromiseController(); diff --git a/src/mono/wasm/runtime/diagnostics/server_pthread/ipc-protocol/parser.ts b/src/mono/wasm/runtime/diagnostics/server_pthread/ipc-protocol/parser.ts index fe695a3525bab..765e16718c953 100644 --- a/src/mono/wasm/runtime/diagnostics/server_pthread/ipc-protocol/parser.ts +++ b/src/mono/wasm/runtime/diagnostics/server_pthread/ipc-protocol/parser.ts @@ -19,6 +19,7 @@ import { EventPipeCommandId, ProcessCommandId, } from "./types"; +import { mono_log_warn } from "../../../logging"; interface ParseClientCommandResultOk extends ParseResultOk { readonly result: C; @@ -52,7 +53,7 @@ function parseEventPipeCommand(cmd: BinaryProtocolCommand & { commandSet: Comman case EventPipeCommandId.CollectTracing2: return parseEventPipeCollectTracing2(cmd); default: - console.warn("MONO_WASM: unexpected EventPipe command: " + cmd.command); + mono_log_warn("unexpected EventPipe command: " + cmd.command); return { success: false, error: `unexpected EventPipe command ${cmd.command}` }; } } @@ -132,7 +133,7 @@ function parseProcessCommand(cmd: BinaryProtocolCommand & { commandSet: CommandS case ProcessCommandId.ProcessInfo2: throw new Error("TODO"); default: - console.warn("MMONO_WASM: unexpected Process command: " + cmd.command); + mono_log_warn("unexpected Process command: " + cmd.command); return { success: false, error: `unexpected Process command ${cmd.command}` }; } } diff --git a/src/mono/wasm/runtime/diagnostics/server_pthread/mock-remote.ts b/src/mono/wasm/runtime/diagnostics/server_pthread/mock-remote.ts index 97fe3804a2f1e..b3d07952de76d 100644 --- a/src/mono/wasm/runtime/diagnostics/server_pthread/mock-remote.ts +++ b/src/mono/wasm/runtime/diagnostics/server_pthread/mock-remote.ts @@ -4,7 +4,6 @@ import monoDiagnosticsMock from "consts:monoDiagnosticsMock"; import type { Mock } from "../mock"; import { mock } from "../mock"; -import { runtimeHelpers } from "../../globals"; export function importAndInstantiateMock(mockURL: string): Promise { if (monoDiagnosticsMock) { @@ -12,7 +11,7 @@ export function importAndInstantiateMock(mockURL: string): Promise { const scriptURL = mockURL.substring(mockPrefix.length); return import(scriptURL).then((mockModule) => { const script = mockModule.default; - return mock(script, { trace: runtimeHelpers.diagnosticTracing }); + return mock(script); }); } else { return Promise.resolve(undefined as unknown as Mock); diff --git a/src/mono/wasm/runtime/diagnostics/server_pthread/protocol-socket.ts b/src/mono/wasm/runtime/diagnostics/server_pthread/protocol-socket.ts index ffa8ce47bca10..7bd03e0d003a3 100644 --- a/src/mono/wasm/runtime/diagnostics/server_pthread/protocol-socket.ts +++ b/src/mono/wasm/runtime/diagnostics/server_pthread/protocol-socket.ts @@ -10,6 +10,7 @@ import { import Magic from "./ipc-protocol/magic"; import Parser from "./ipc-protocol/base-parser"; import { assertNever } from "../../types/internal"; +import { mono_log_debug, mono_log_warn } from "../../logging"; export const dotnetDiagnosticsServerProtocolCommandEvent = "dotnet:diagnostics:protocolCommand" as const; @@ -73,14 +74,14 @@ class StatefulParser { result = this.tryAppendBuffer(new Uint8Array(buf)); } if (result.success) { - console.debug("MONO_WASM: protocol-socket: got result", result); + mono_log_debug("protocol-socket: got result", result); this.setState(result.newState); if (result.command) { const command = result.command; this.emitCommandCallback(command); } } else { - console.warn("MONO_WASM: socket received invalid command header", buf, result.error); + mono_log_warn("socket received invalid command header", buf, result.error); // FIXME: dispatch error event? this.setState({ state: InState.Error }); } @@ -139,7 +140,7 @@ class StatefulParser { const pos = { pos: Magic.MinimalHeaderSize }; let result = this.tryParseCompletedBuffer(buf, pos); if (overflow) { - console.warn("MONO_WASM: additional bytes past command payload", overflow); + mono_log_warn("additional bytes past command payload", overflow); if (result.success) { const newResult: ParseResultBinaryCommandOk = { success: true, command: result.command, newState: { state: InState.Error } }; result = newResult; @@ -176,14 +177,14 @@ class ProtocolSocketImpl implements ProtocolSocket { onMessage(this: ProtocolSocketImpl, ev: MessageEvent): void { const data = ev.data; - console.debug("MONO_WASM: protocol socket received message", ev.data); + mono_log_debug("protocol socket received message", ev.data); if (typeof data === "object" && data instanceof ArrayBuffer) { this.onArrayBuffer(data); } else if (typeof data === "object" && data instanceof Blob) { data.arrayBuffer().then(this.onArrayBuffer.bind(this)); } else if (typeof data === "string") { // otherwise it's string, ignore it. - console.debug("MONO_WASM: protocol socket received string message; ignoring it", ev.data); + mono_log_debug("protocol socket received string message; ignoring it", ev.data); } else { assertNever(data); } @@ -194,15 +195,15 @@ class ProtocolSocketImpl implements ProtocolSocket { } onArrayBuffer(this: ProtocolSocketImpl, buf: ArrayBuffer) { - console.debug("MONO_WASM: protocol-socket: parsing array buffer", buf); + mono_log_debug("protocol-socket: parsing array buffer", buf); this.statefulParser.receiveBuffer(buf); } // called by the stateful parser when it has a complete command emitCommandCallback(this: this, command: BinaryProtocolCommand): void { - console.debug("MONO_WASM: protocol-socket: queueing command", command); + mono_log_debug("protocol-socket: queueing command", command); queueMicrotask(() => { - console.debug("MONO_WASM: dispatching protocol event with command", command); + mono_log_debug("dispatching protocol event with command", command); this.dispatchProtocolCommandEvent(command); }); } @@ -219,7 +220,7 @@ class ProtocolSocketImpl implements ProtocolSocket { this.sock.addEventListener(type, listener, options); if (type === dotnetDiagnosticsServerProtocolCommandEvent) { if (this.protocolListeners === 0) { - console.debug("MONO_WASM: adding protocol listener, with a message chaser"); + mono_log_debug("adding protocol listener, with a message chaser"); this.sock.addEventListener("message", this.messageListener); } this.protocolListeners++; @@ -229,7 +230,7 @@ class ProtocolSocketImpl implements ProtocolSocket { removeEventListener(type: K, listener: (this: ProtocolSocket, ev: ProtocolSocketEventMap[K]) => any): void; removeEventListener(type: string, listener: EventListenerOrEventListenerObject): void { if (type === dotnetDiagnosticsServerProtocolCommandEvent) { - console.debug("MONO_WASM: removing protocol listener and message chaser"); + mono_log_debug("removing protocol listener and message chaser"); this.protocolListeners--; if (this.protocolListeners === 0) { this.sock.removeEventListener("message", this.messageListener); diff --git a/src/mono/wasm/runtime/diagnostics/server_pthread/socket-connection.ts b/src/mono/wasm/runtime/diagnostics/server_pthread/socket-connection.ts index c2f8aae007f10..15be79ef232cd 100644 --- a/src/mono/wasm/runtime/diagnostics/server_pthread/socket-connection.ts +++ b/src/mono/wasm/runtime/diagnostics/server_pthread/socket-connection.ts @@ -5,6 +5,7 @@ import { assertNever } from "../../types/internal"; import { VoidPtr } from "../../types/emscripten"; import { Module } from "../../globals"; import type { CommonSocket } from "./common-socket"; +import { mono_log_debug, mono_log_warn } from "../../logging"; enum ListenerState { Sending, Closed, @@ -38,7 +39,7 @@ export class EventPipeSocketConnection { } close(): void { - console.debug("MONO_WASM: EventPipe session stream closing websocket"); + mono_log_debug("EventPipe session stream closing websocket"); switch (this._state) { case ListenerState.Error: return; @@ -68,7 +69,7 @@ export class EventPipeSocketConnection { switch (this._state) { case ListenerState.Sending: /* unexpected message */ - console.warn("MONO_WASM: EventPipe session stream received unexpected message from websocket", event); + mono_log_warn("EventPipe session stream received unexpected message from websocket", event); // TODO notify runtime that the connection had an error this._state = ListenerState.Error; break; @@ -99,7 +100,7 @@ export class EventPipeSocketConnection { } private _onError(event: Event) { - console.debug("MONO_WASM: EventPipe session stream websocket error", event); + mono_log_debug("EventPipe session stream websocket error", event); this._state = ListenerState.Error; this.stream.close(); // TODO: notify runtime that connection had an error diff --git a/src/mono/wasm/runtime/exports-internal.ts b/src/mono/wasm/runtime/exports-internal.ts index 1301eeea307e5..497198c88b437 100644 --- a/src/mono/wasm/runtime/exports-internal.ts +++ b/src/mono/wasm/runtime/exports-internal.ts @@ -18,7 +18,7 @@ import { mono_wasm_gc_lock, mono_wasm_gc_unlock } from "./gc-lock"; export function export_internal(): any { return { // tests - mono_wasm_exit: (exit_code: number) => { Module.err("MONO_WASM: early exit " + exit_code); }, + mono_wasm_exit: (exit_code: number) => { Module.err("early exit " + exit_code); }, mono_wasm_enable_on_demand_gc: cwraps.mono_wasm_enable_on_demand_gc, mono_wasm_profiler_init_aot: cwraps.mono_wasm_profiler_init_aot, mono_wasm_profiler_init_browser: cwraps.mono_wasm_profiler_init_browser, diff --git a/src/mono/wasm/runtime/exports.ts b/src/mono/wasm/runtime/exports.ts index 407c14c8b3cf1..903f835a97a8d 100644 --- a/src/mono/wasm/runtime/exports.ts +++ b/src/mono/wasm/runtime/exports.ts @@ -20,7 +20,7 @@ import { initializeReplacements } from "./polyfills"; import { mono_bind_static_method } from "./net6-legacy/method-calls"; import { export_binding_api, export_internal_api, export_mono_api } from "./net6-legacy/exports-legacy"; import { initializeLegacyExports } from "./net6-legacy/globals"; -import { mono_wasm_stringify_as_error_with_stack } from "./logging"; +import { mono_log_warn, mono_wasm_stringify_as_error_with_stack } from "./logging"; import { instantiate_asset, instantiate_symbols_asset } from "./assets"; import { jiterpreter_dump_stats } from "./jiterpreter"; @@ -77,7 +77,7 @@ function initializeExports(globalObjects: GlobalObjects): RuntimeAPI { // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-ignore module.mono_bind_static_method = (fqn: string, signature: string/*ArgsMarshalString*/): Function => { - console.warn("MONO_WASM: Module.mono_bind_static_method is obsolete, please use [JSExportAttribute] interop instead"); + mono_log_warn("Module.mono_bind_static_method is obsolete, please use [JSExportAttribute] interop instead"); return mono_bind_static_method(fqn, signature); }; } @@ -93,7 +93,7 @@ function initializeExports(globalObjects: GlobalObjects): RuntimeAPI { if (is_nullish(value)) { const stack = (new Error()).stack; const nextLine = stack ? stack.substr(stack.indexOf("\n", 8) + 1) : ""; - console.warn(`MONO_WASM: global ${name} is obsolete, please use Module.${name} instead ${nextLine}`); + mono_log_warn(`global ${name} is obsolete, please use Module.${name} instead ${nextLine}`); value = provider(); } return value; diff --git a/src/mono/wasm/runtime/http.ts b/src/mono/wasm/runtime/http.ts index ef0ee24edba18..9034494a4615c 100644 --- a/src/mono/wasm/runtime/http.ts +++ b/src/mono/wasm/runtime/http.ts @@ -23,7 +23,7 @@ export function http_wasm_abort_response(res: ResponseExtension): void { if (res.__reader) { res.__reader.cancel().catch((err) => { if (err && err.name !== "AbortError") { - Module.err("MONO_WASM: Error in http_wasm_abort_response: " + err); + Module.err("Error in http_wasm_abort_response: " + err); } // otherwise, it's expected }); diff --git a/src/mono/wasm/runtime/invoke-cs.ts b/src/mono/wasm/runtime/invoke-cs.ts index 27b2f3343a472..bae3872e35b45 100644 --- a/src/mono/wasm/runtime/invoke-cs.ts +++ b/src/mono/wasm/runtime/invoke-cs.ts @@ -17,6 +17,7 @@ import cwraps from "./cwraps"; import { assembly_load } from "./class-loader"; import { wrap_error_root, wrap_no_error_root } from "./invoke-js"; import { startMeasure, MeasuredBlock, endMeasure } from "./profiler"; +import { mono_log_debug } from "./logging"; export function mono_wasm_bind_cs_function(fully_qualified_name: MonoStringRef, signature_hash: number, signature: JSFunctionSignature, is_exception: Int32Ptr, result_address: MonoObjectRef): void { const fqn_root = mono_wasm_new_external_root(fully_qualified_name), resultRoot = mono_wasm_new_external_root(result_address); @@ -29,9 +30,7 @@ export function mono_wasm_bind_cs_function(fully_qualified_name: MonoStringRef, const js_fqn = conv_string_root(fqn_root)!; mono_assert(js_fqn, "fully_qualified_name must be string"); - if (runtimeHelpers.diagnosticTracing) { - console.debug(`MONO_WASM: Binding [JSExport] ${js_fqn}`); - } + mono_log_debug(`Binding [JSExport] ${js_fqn}`); const { assembly, namespace, classname, methodname } = parseFQN(js_fqn); diff --git a/src/mono/wasm/runtime/invoke-js.ts b/src/mono/wasm/runtime/invoke-js.ts index cda5b3b5f89bd..ee1220b8d9ab3 100644 --- a/src/mono/wasm/runtime/invoke-js.ts +++ b/src/mono/wasm/runtime/invoke-js.ts @@ -7,10 +7,10 @@ import { setI32_unchecked } from "./memory"; import { conv_string_root, js_string_to_mono_string_root } from "./strings"; import { MonoObject, MonoObjectRef, MonoString, MonoStringRef, JSFunctionSignature, JSMarshalerArguments, WasmRoot, BoundMarshalerToJs, JSFnHandle, BoundMarshalerToCs, JSHandle, MarshalerType } from "./types/internal"; import { Int32Ptr } from "./types/emscripten"; -import { INTERNAL, Module, runtimeHelpers } from "./globals"; +import { INTERNAL, Module } from "./globals"; import { bind_arg_marshal_to_js } from "./marshal-to-js"; import { mono_wasm_new_external_root } from "./roots"; -import { mono_wasm_symbolicate_string } from "./logging"; +import { mono_log_debug, mono_wasm_symbolicate_string } from "./logging"; import { mono_wasm_get_jsobj_from_js_handle } from "./gc-handles"; import { endMeasure, MeasuredBlock, startMeasure } from "./profiler"; import { wrap_as_cancelable_promise } from "./cancelable-promise"; @@ -28,9 +28,8 @@ export function mono_wasm_bind_js_function(function_name: MonoStringRef, module_ const js_function_name = conv_string_root(function_name_root)!; const mark = startMeasure(); const js_module_name = conv_string_root(module_name_root)!; - if (runtimeHelpers.diagnosticTracing) { - console.debug(`MONO_WASM: Binding [JSImport] ${js_function_name} from ${js_module_name}`); - } + mono_log_debug(`Binding [JSImport] ${js_function_name} from ${js_module_name}`); + const fn = mono_wasm_lookup_function(js_function_name, js_module_name); const args_count = get_signature_argument_count(signature); @@ -249,8 +248,7 @@ export function mono_wasm_invoke_import(fn_handle: JSFnHandle, args: JSMarshaler export function mono_wasm_set_module_imports(module_name: string, moduleImports: any) { importedModules.set(module_name, moduleImports); - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: added module imports '${module_name}'`); + mono_log_debug(`added module imports '${module_name}'`); } function mono_wasm_lookup_function(function_name: string, js_module_name: string): Function { @@ -320,8 +318,7 @@ export function dynamic_import(module_name: string, module_url: string): Promise let promise = importedModulesPromises.get(module_name); const newPromise = !promise; if (newPromise) { - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: importing ES6 module '${module_name}' from '${module_url}'`); + mono_log_debug(`importing ES6 module '${module_name}' from '${module_url}'`); promise = import(/* webpackIgnore: true */module_url); importedModulesPromises.set(module_name, promise); } @@ -330,8 +327,7 @@ export function dynamic_import(module_name: string, module_url: string): Promise const module = await promise; if (newPromise) { importedModules.set(module_name, module); - if (runtimeHelpers.diagnosticTracing) - console.debug(`MONO_WASM: imported ES6 module '${module_name}' from '${module_url}'`); + mono_log_debug(`imported ES6 module '${module_name}' from '${module_url}'`); } return module; }); diff --git a/src/mono/wasm/runtime/jiterpreter-interp-entry.ts b/src/mono/wasm/runtime/jiterpreter-interp-entry.ts index 190c42c6bdc67..6f0dac1bcd4e9 100644 --- a/src/mono/wasm/runtime/jiterpreter-interp-entry.ts +++ b/src/mono/wasm/runtime/jiterpreter-interp-entry.ts @@ -15,6 +15,7 @@ import { getWasmFunctionTable, recordFailure, getOptions, JiterpreterOptions, getMemberOffset, JiterpMember } from "./jiterpreter-support"; +import { mono_log_error, mono_log_info } from "./logging"; // Controls miscellaneous diagnostic output. const trace = 0; @@ -344,7 +345,7 @@ function flush_wasm_entry_trampoline_jit_queue() { compileStarted = _now(); const buffer = builder.getArrayView(); if (trace > 0) - console.log(`jit queue generated ${buffer.length} byte(s) of wasm`); + mono_log_info(`jit queue generated ${buffer.length} byte(s) of wasm`); counters.bytesGenerated += buffer.length; const traceModule = new WebAssembly.Module(buffer); const wasmImports = builder.getWasmImports(); @@ -369,7 +370,7 @@ function flush_wasm_entry_trampoline_jit_queue() { rejected = false; // console.error(`${traceName} failed: ${exc} ${exc.stack}`); // HACK: exc.stack is enormous garbage in v8 console - console.error(`MONO_WASM: interp_entry code generation failed: ${exc}`); + mono_log_error(`interp_entry code generation failed: ${exc}`); recordFailure(); } finally { const finished = _now(); @@ -381,7 +382,7 @@ function flush_wasm_entry_trampoline_jit_queue() { } if (threw || (!rejected && ((trace >= 2) || dumpWrappers))) { - console.log(`// MONO_WASM: ${jitQueue.length} trampolines generated, blob follows //`); + mono_log_info(`// ${jitQueue.length} trampolines generated, blob follows //`); let s = "", j = 0; try { if (builder.inSection) @@ -399,15 +400,15 @@ function flush_wasm_entry_trampoline_jit_queue() { s += b.toString(16); s += " "; if ((s.length % 10) === 0) { - console.log(`${j}\t${s}`); + mono_log_info(`${j}\t${s}`); s = ""; j = i + 1; } } - console.log(`${j}\t${s}`); - console.log("// end blob //"); + mono_log_info(`${j}\t${s}`); + mono_log_info("// end blob //"); } else if (rejected && !threw) { - console.error("MONO_WASM: failed to generate trampoline for unknown reason"); + mono_log_error("failed to generate trampoline for unknown reason"); } jitQueue.length = 0; diff --git a/src/mono/wasm/runtime/jiterpreter-jit-call.ts b/src/mono/wasm/runtime/jiterpreter-jit-call.ts index db38070e1e2fa..e88f6b00f8416 100644 --- a/src/mono/wasm/runtime/jiterpreter-jit-call.ts +++ b/src/mono/wasm/runtime/jiterpreter-jit-call.ts @@ -14,6 +14,7 @@ import { recordFailure, getOptions, bytesFromHex } from "./jiterpreter-support"; import cwraps from "./cwraps"; +import { mono_log_error, mono_log_info } from "./logging"; // Controls miscellaneous diagnostic output. const trace = 0; @@ -242,7 +243,7 @@ function getIsWasmEhSupported(): boolean { doJitCallModule = new WebAssembly.Module(bytes); wasmEhSupported = true; } catch (exc) { - console.log("MONO_WASM: Disabling WASM EH support due to JIT failure", exc); + mono_log_info("Disabling WASM EH support due to JIT failure", exc); wasmEhSupported = false; } @@ -289,7 +290,7 @@ export function mono_jiterp_do_jit_call_indirect( cwraps.mono_jiterp_update_jit_call_dispatcher(result); failed = false; } catch (exc) { - console.error("MONO_WASM: failed to compile do_jit_call handler", exc); + mono_log_error("failed to compile do_jit_call handler", exc); failed = true; } // If wasm EH support was detected, a native wasm implementation of the dispatcher was already registered. @@ -444,7 +445,7 @@ export function mono_interp_flush_jitcall_queue(): void { compileStarted = _now(); const buffer = builder.getArrayView(); if (trace > 0) - console.log(`do_jit_call queue flush generated ${buffer.length} byte(s) of wasm`); + mono_log_info(`do_jit_call queue flush generated ${buffer.length} byte(s) of wasm`); counters.bytesGenerated += buffer.length; const traceModule = new WebAssembly.Module(buffer); const wasmImports = builder.getWasmImports(); @@ -460,7 +461,7 @@ export function mono_interp_flush_jitcall_queue(): void { if (!idx) throw new Error("add_function_pointer returned a 0 index"); else if (trace >= 2) - console.log(`${info.name} -> fn index ${idx}`); + mono_log_info(`${info.name} -> fn index ${idx}`); info.result = idx; cwraps.mono_jiterp_register_jit_call_thunk(info.cinfo, idx); @@ -478,7 +479,7 @@ export function mono_interp_flush_jitcall_queue(): void { rejected = false; // console.error(`${traceName} failed: ${exc} ${exc.stack}`); // HACK: exc.stack is enormous garbage in v8 console - console.error(`MONO_WASM: jit_call code generation failed: ${exc}`); + mono_log_error(`jit_call code generation failed: ${exc}`); recordFailure(); } finally { const finished = _now(); @@ -498,9 +499,9 @@ export function mono_interp_flush_jitcall_queue(): void { // FIXME if (threw || (!rejected && ((trace >= 2) || dumpWrappers))) { - console.log(`// MONO_WASM: ${jitQueue.length} jit call wrappers generated, blob follows //`); + mono_log_info(`// ${jitQueue.length} jit call wrappers generated, blob follows //`); for (let i = 0; i < jitQueue.length; i++) - console.log(`// #${i} === ${jitQueue[i].name} hasThis=${jitQueue[i].hasThisReference} hasRet=${jitQueue[i].hasReturnValue} wasmArgTypes=${jitQueue[i].wasmNativeSignature}`); + mono_log_info(`// #${i} === ${jitQueue[i].name} hasThis=${jitQueue[i].hasThisReference} hasRet=${jitQueue[i].hasReturnValue} wasmArgTypes=${jitQueue[i].wasmNativeSignature}`); let s = "", j = 0; try { @@ -519,15 +520,15 @@ export function mono_interp_flush_jitcall_queue(): void { s += b.toString(16); s += " "; if ((s.length % 10) === 0) { - console.log(`${j}\t${s}`); + mono_log_info(`${j}\t${s}`); s = ""; j = i + 1; } } - console.log(`${j}\t${s}`); - console.log("// end blob //"); + mono_log_info(`${j}\t${s}`); + mono_log_info("// end blob //"); } else if (rejected && !threw) { - console.error("MONO_WASM: failed to generate trampoline for unknown reason"); + mono_log_error("failed to generate trampoline for unknown reason"); } jitQueue.length = 0; @@ -702,7 +703,7 @@ function generate_wasm_body( } else { const loadWasmOp = (wasmOpcodeFromCilOpcode as any)[loadCilOp]; if (!loadWasmOp) { - console.error(`No wasm load op for arg #${i} type ${info.paramTypes[i]} cil opcode ${loadCilOp}`); + mono_log_error(`No wasm load op for arg #${i} type ${info.paramTypes[i]} cil opcode ${loadCilOp}`); return false; } @@ -764,7 +765,7 @@ function generate_wasm_body( const storeCilOp = cwraps.mono_jiterp_type_to_stind(info.returnType); const storeWasmOp = (wasmOpcodeFromCilOpcode as any)[storeCilOp]; if (!storeWasmOp) { - console.error(`No wasm store op for return type ${info.returnType} cil opcode ${storeCilOp}`); + mono_log_error(`No wasm store op for return type ${info.returnType} cil opcode ${storeCilOp}`); return false; } diff --git a/src/mono/wasm/runtime/jiterpreter-support.ts b/src/mono/wasm/runtime/jiterpreter-support.ts index a5f9eb3b6e42f..71b0219ebd86a 100644 --- a/src/mono/wasm/runtime/jiterpreter-support.ts +++ b/src/mono/wasm/runtime/jiterpreter-support.ts @@ -6,6 +6,7 @@ import { Module, runtimeHelpers } from "./globals"; import { WasmOpcode, WasmSimdOpcode } from "./jiterpreter-opcodes"; import { MintOpcode } from "./mintops"; import cwraps from "./cwraps"; +import { mono_log_error, mono_log_info } from "./logging"; export const maxFailures = 2, maxMemsetSize = 64, @@ -234,8 +235,8 @@ export class WasmBuilder { return current.getArrayView(false).slice(0, current.size); } - getWasmImports () : WebAssembly.Imports { - const result : any = { + getWasmImports(): WebAssembly.Imports { + const result: any = { c: this.getConstants(), m: { h: (Module).asm.memory }, f: { f: getWasmFunctionTable() }, @@ -262,7 +263,7 @@ export class WasmBuilder { // HACK: Approximate amount of space we need to generate the full module at present // FIXME: This does not take into account any other functions already generated if they weren't // emitted into the module immediately - get bytesGeneratedSoFar () { + get bytesGeneratedSoFar() { const importSize = this.compressImportNames // mod (2 bytes) name (2-3 bytes) type (1 byte) typeidx (1-2 bytes) ? 8 @@ -293,13 +294,13 @@ export class WasmBuilder { return this.current.appendU8(value); } - appendSimd (value: WasmSimdOpcode) { + appendSimd(value: WasmSimdOpcode) { this.current.appendU8(WasmOpcode.PREFIX_simd); // Yes that's right. We're using LEB128 to encode 8-bit opcodes. Why? I don't know return this.current.appendULeb(value); } - appendU32 (value: number) { + appendU32(value: number) { return this.current.appendU32(value); } @@ -359,7 +360,7 @@ export class WasmBuilder { this.appendU8(WasmOpcode.get_global); this.appendLeb(idx); } else { - // console.log(`Warning: no constant slot for ${pointer} (${this.nextConstantSlot} slots used)`); + // mono_log_info(`Warning: no constant slot for ${pointer} (${this.nextConstantSlot} slots used)`); this.i32_const(pointer); } } @@ -428,7 +429,7 @@ export class WasmBuilder { this.appendULeb(this.functionTypeCount); /* if (trace > 1) - console.log(`Generated ${this.functionTypeCount} wasm type(s) from ${Object.keys(this.functionTypes).length} named function types`); + mono_log_info(`Generated ${this.functionTypeCount} wasm type(s) from ${Object.keys(this.functionTypes).length} named function types`); */ for (let i = 0; i < this.functionTypeCount; i++) { const parameters = this.functionTypesByIndex[i][0], @@ -459,8 +460,8 @@ export class WasmBuilder { return imports; } - getCompressedName (ifi: ImportedFunctionInfo) { - if (!this.compressImportNames || typeof(ifi.index) !== "number") + getCompressedName(ifi: ImportedFunctionInfo) { + if (!this.compressImportNames || typeof (ifi.index) !== "number") return ifi.name; let result = compressedNameCache[ifi.index!]; @@ -469,7 +470,7 @@ export class WasmBuilder { return result; } - getImportsToEmit () { + getImportsToEmit() { const result = []; for (const k in this.importedFunctions) { const v = this.importedFunctions[k]; @@ -478,11 +479,11 @@ export class WasmBuilder { result.push(v); } result.sort((lhs, rhs) => lhs.index! - rhs.index!); - // console.log("result=[" + result.map(f => `#${f.index} ${f.module}.${f.name}`) + "]"); + // mono_log_info("result=[" + result.map(f => `#${f.index} ${f.module}.${f.name}`) + "]"); return result; } - _generateImportSection () { + _generateImportSection() { const importsToEmit = this.getImportsToEmit(); this.lockImports = true; @@ -490,10 +491,10 @@ export class WasmBuilder { this.beginSection(2); this.appendULeb(2 + importsToEmit.length + this.constantSlots.length); - // console.log(`referenced ${importsToEmit.length} import(s)`); + // mono_log_info(`referenced ${importsToEmit.length} import(s)`); for (let i = 0; i < importsToEmit.length; i++) { const ifi = importsToEmit[i]; - // console.log(` #${ifi.index} ${ifi.module}.${ifi.name} = ${ifi.func}. typeIndex=${ifi.typeIndex}`); + // mono_log_info(` #${ifi.index} ${ifi.module}.${ifi.name} = ${ifi.func}. typeIndex=${ifi.typeIndex}`); this.appendName(ifi.module); this.appendName(this.getCompressedName(ifi)); this.appendU8(0x0); // function @@ -530,7 +531,7 @@ export class WasmBuilder { defineImportedFunction( module: string, name: string, functionTypeName: string, permanent: boolean, func: Function | number - ) : ImportedFunctionInfo { + ): ImportedFunctionInfo { if (this.lockImports) throw new Error("Import section already generated"); if (permanent && (this.importedFunctionCount > 0)) @@ -636,7 +637,7 @@ export class WasmBuilder { this.endSection(); } - call_indirect (functionTypeName: string, tableIndex: number) { + call_indirect(functionTypeName: string, tableIndex: number) { const type = this.functionTypes[functionTypeName]; if (!type) throw new Error("No function type named " + functionTypeName); @@ -646,7 +647,7 @@ export class WasmBuilder { this.appendULeb(tableIndex); } - callImport (name: string) { + callImport(name: string) { const func = this.importedFunctions[name]; if (!func) throw new Error("No imported function named " + name); @@ -680,7 +681,7 @@ export class WasmBuilder { let result = 0; for (const k in parms) { this.locals.set(k, result); - // console.log(`parm ${k} -> ${result}`); + // mono_log_info(`parm ${k} -> ${result}`); result++; } return result; @@ -733,7 +734,7 @@ export class WasmBuilder { this.locals.set(k, idx); break; } - // console.log(`local ${k} ${locals[k]} -> ${idx}`); + // mono_log_info(`local ${k} ${locals[k]} -> ${idx}`); } return localGroupCount; @@ -775,7 +776,7 @@ export class WasmBuilder { const c = counts[k]; if (!c) continue; - // console.log(`${k} x${c}`); + // mono_log_info(`${k} x${c}`); this.appendULeb(c); this.appendU8(k); } @@ -1171,7 +1172,7 @@ class Cfg { } emitBlob(segment: CfgBlob, source: Uint8Array) { - // console.log(`segment @${(segment.ip).toString(16)} ${segment.start}-${segment.start + segment.length}`); + // mono_log_info(`segment @${(segment.ip).toString(16)} ${segment.start}-${segment.start + segment.length}`); const view = source.subarray(segment.start, segment.start + segment.length); this.builder.appendBytes(view); } @@ -1235,13 +1236,13 @@ class Cfg { if (this.backDispatchOffsets.length === 0) { if (this.trace > 0) - console.log("No back branch targets were reachable after filtering"); + mono_log_info("No back branch targets were reachable after filtering"); } else if (this.backDispatchOffsets.length === 1) { if (this.trace > 0) { if (this.backDispatchOffsets[0] === this.entryIp) - console.log(`Exactly one back dispatch offset and it was the entry point 0x${(this.entryIp).toString(16)}`); + mono_log_info(`Exactly one back dispatch offset and it was the entry point 0x${(this.entryIp).toString(16)}`); else - console.log(`Exactly one back dispatch offset and it was 0x${(this.backDispatchOffsets[0]).toString(16)}`); + mono_log_info(`Exactly one back dispatch offset and it was 0x${(this.backDispatchOffsets[0]).toString(16)}`); } // if (disp) goto back_branch_target else fallthrough @@ -1281,7 +1282,7 @@ class Cfg { } if (this.trace > 1) - console.log(`blockStack=${this.blockStack}`); + mono_log_info(`blockStack=${this.blockStack}`); for (let i = 0; i < this.segments.length; i++) { const segment = this.segments[i]; @@ -1312,7 +1313,7 @@ class Cfg { if (this.dispatchTable.has(segment.target)) { const disp = this.dispatchTable.get(segment.target)!; if (this.trace > 1) - console.log(`backward br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)}: disp=${disp}`); + mono_log_info(`backward br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)}: disp=${disp}`); // Set the back branch taken flag local so it will get flushed on monitoring exit this.builder.i32_const(1); @@ -1324,7 +1325,7 @@ class Cfg { successfulBackBranch = true; } else { if (this.trace > 0) - console.log(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed: back branch target not in dispatch table`); + mono_log_info(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed: back branch target not in dispatch table`); indexInStack = -1; } } @@ -1335,14 +1336,14 @@ class Cfg { this.builder.appendU8(WasmOpcode.br); this.builder.appendULeb(offset + indexInStack); if (this.trace > 1) - console.log(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} breaking out ${offset + indexInStack + 1} level(s)`); + mono_log_info(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} breaking out ${offset + indexInStack + 1} level(s)`); } else { if (this.trace > 0) { const base = this.base; if ((segment.target >= base) && (segment.target < this.exitIp)) - console.log(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed (inside of trace!)`); + mono_log_info(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed (inside of trace!)`); else if (this.trace > 1) - console.log(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed (outside of trace 0x${base.toString(16)} - 0x${(this.exitIp).toString(16)})`); + mono_log_info(`br from ${(segment.from).toString(16)} to ${(segment.target).toString(16)} failed (outside of trace 0x${base.toString(16)} - 0x${(this.exitIp).toString(16)})`); } append_bailout(this.builder, segment.target, BailoutReason.Branch); } @@ -1393,7 +1394,7 @@ export const elapsedTimes = { compilation: 0 }; -export const simdFallbackCounters : { [name: string] : number } = { +export const simdFallbackCounters: { [name: string]: number } = { }; export const counters = { @@ -1653,7 +1654,7 @@ export function append_memmove_dest_src(builder: WasmBuilder, count: number) { export function recordFailure(): void { counters.failures++; if (counters.failures >= maxFailures) { - console.log(`MONO_WASM: Disabling jiterpreter after ${counters.failures} failures`); + mono_log_info(`Disabling jiterpreter after ${counters.failures} failures`); applyOptions({ enableTraces: false, enableInterpEntry: false, @@ -1709,7 +1710,7 @@ export function importDef(name: string, fn: Function): [string, string, Function return [name, name, fn]; } -export function bytesFromHex (hex: string) : Uint8Array { +export function bytesFromHex(hex: string): Uint8Array { const bytes = new Uint8Array(hex.length / 2); for (let i = 0; i < hex.length; i += 2) bytes[i / 2] = parseInt(hex.substring(i, i + 2), 16); @@ -1798,7 +1799,7 @@ export function applyOptions(options: JiterpreterOptions) { for (const k in options) { const info = optionNames[k]; if (!info) { - console.error(`Unrecognized jiterpreter option: ${k}`); + mono_log_error(`Unrecognized jiterpreter option: ${k}`); continue; } @@ -1808,7 +1809,7 @@ export function applyOptions(options: JiterpreterOptions) { else if (typeof (v) === "number") cwraps.mono_jiterp_parse_option(`--${info}=${v}`); else - console.error(`Jiterpreter option must be a boolean or a number but was ${typeof (v)} '${v}'`); + mono_log_error(`Jiterpreter option must be a boolean or a number but was ${typeof (v)} '${v}'`); } } diff --git a/src/mono/wasm/runtime/jiterpreter-trace-generator.ts b/src/mono/wasm/runtime/jiterpreter-trace-generator.ts index 6c9bc03867e7f..8df1ff8a93059 100644 --- a/src/mono/wasm/runtime/jiterpreter-trace-generator.ts +++ b/src/mono/wasm/runtime/jiterpreter-trace-generator.ts @@ -49,6 +49,7 @@ import { simdCreateLoadOps, simdCreateSizes, simdCreateStoreOps, simdShiftTable, } from "./jiterpreter-tables"; +import { mono_log_error, mono_log_info } from "./logging"; /* struct MonoVTable { @@ -186,7 +187,7 @@ export function generateWasmBody( if (ip >= endOfBody) { record_abort(traceIp, ip, traceName, "end-of-body"); if (instrumentedTraceId) - console.log(`instrumented trace ${traceName} exited at end of body @${(ip).toString(16)}`); + mono_log_info(`instrumented trace ${traceName} exited at end of body @${(ip).toString(16)}`); break; } @@ -196,10 +197,10 @@ export function generateWasmBody( const maxBytesGenerated = 3840, spaceLeft = maxBytesGenerated - builder.bytesGeneratedSoFar - builder.cfg.overheadBytes; if (builder.size >= spaceLeft) { - // console.log(`trace too big, estimated size is ${builder.size + builder.bytesGeneratedSoFar}`); + // mono_log_info(`trace too big, estimated size is ${builder.size + builder.bytesGeneratedSoFar}`); record_abort(traceIp, ip, traceName, "trace-too-big"); if (instrumentedTraceId) - console.log(`instrumented trace ${traceName} exited because of size limit at @${(ip).toString(16)} (spaceLeft=${spaceLeft}b)`); + mono_log_info(`instrumented trace ${traceName} exited because of size limit at @${(ip).toString(16)} (spaceLeft=${spaceLeft}b)`); break; } @@ -250,7 +251,7 @@ export function generateWasmBody( // opcodes know that it's available by branching to the top of the dispatch loop if (isBackBranchTarget) { if (traceBackBranches > 1) - console.log(`${traceName} recording back branch target 0x${(ip).toString(16)}`); + mono_log_info(`${traceName} recording back branch target 0x${(ip).toString(16)}`); builder.backBranchOffsets.push(ip); } @@ -451,7 +452,7 @@ export function generateWasmBody( // We will have bailed out if the object was null if (builder.allowNullCheckOptimization) { if (traceNullCheckOptimizations) - console.log(`(0x${(ip).toString(16)}) locals[${dest}] passed cknull`); + mono_log_info(`(0x${(ip).toString(16)}) locals[${dest}] passed cknull`); notNullSince.set(dest, ip); } skipDregInvalidation = true; @@ -521,7 +522,7 @@ export function generateWasmBody( const offset = getArgU16(ip, 2), flag = isAddressTaken(builder, offset); if (!flag) - console.error(`MONO_WASM: ${traceName}: Expected local ${offset} to have address taken flag`); + mono_log_error(`${traceName}: Expected local ${offset} to have address taken flag`); append_ldloca(builder, offset); append_stloc_tail(builder, getArgU16(ip, 1), WasmOpcode.i32_store); break; @@ -1004,7 +1005,7 @@ export function generateWasmBody( (builder.callHandlerReturnAddresses.length > 0) && (builder.callHandlerReturnAddresses.length <= maxCallHandlerReturnAddresses) ) { - // console.log(`endfinally @0x${(ip).toString(16)}. return addresses:`, builder.callHandlerReturnAddresses.map(ra => (ra).toString(16))); + // mono_log_info(`endfinally @0x${(ip).toString(16)}. return addresses:`, builder.callHandlerReturnAddresses.map(ra => (ra).toString(16))); // FIXME: Clean this codegen up // Load ret_ip const clauseIndex = getArgU16(ip, 1), @@ -1360,7 +1361,7 @@ export function generateWasmBody( } else { /* if (opcodeValue > 0) - console.log(`JITERP: aborting trace for opcode ${opname} with value ${opcodeValue}`); + mono_log_info(`JITERP: aborting trace for opcode ${opname} with value ${opcodeValue}`); */ ip = abort; } @@ -1409,7 +1410,7 @@ export function generateWasmBody( prologueOpcodeCounter++; result += opcodeValue; } else if (opcodeValue < 0) { - // console.log(`JITERP: opcode ${opname} did not abort but had value ${opcodeValue}`); + // mono_log_info(`JITERP: opcode ${opname} did not abort but had value ${opcodeValue}`); } ip += (opLengthU16 * 2); @@ -1420,7 +1421,7 @@ export function generateWasmBody( builder.appendU8(WasmOpcode.nop); } else { if (instrumentedTraceId) - console.log(`instrumented trace ${traceName} aborted for opcode ${opname} @${(_ip).toString(16)}`); + mono_log_info(`instrumented trace ${traceName} aborted for opcode ${opname} @${(_ip).toString(16)}`); record_abort(traceIp, _ip, traceName, opcode); } } @@ -1435,7 +1436,7 @@ export function generateWasmBody( builder.cfg.exitIp = rip; - // console.log(`estimated size: ${builder.size + builder.cfg.overheadBytes + builder.bytesGeneratedSoFar}`); + // mono_log_info(`estimated size: ${builder.size + builder.cfg.overheadBytes + builder.bytesGeneratedSoFar}`); // HACK: Traces containing simd will be *much* shorter than non-simd traces, // which will cause both the heuristic and our length requirement outside @@ -1552,15 +1553,15 @@ function append_ldloc_cknull(builder: WasmBuilder, localOffset: number, ip: Mint counters.nullChecksEliminated++; if (nullCheckCaching && (cknullOffset === localOffset)) { if (traceNullCheckOptimizations) - console.log(`(0x${(ip).toString(16)}) cknull_ptr == locals[${localOffset}], not null since 0x${notNullSince.get(localOffset)!.toString(16)}`); + mono_log_info(`(0x${(ip).toString(16)}) cknull_ptr == locals[${localOffset}], not null since 0x${notNullSince.get(localOffset)!.toString(16)}`); if (leaveOnStack) builder.local("cknull_ptr"); } else { - // console.log(`skipping null check for ${localOffset}`); + // mono_log_info(`skipping null check for ${localOffset}`); append_ldloc(builder, localOffset, WasmOpcode.i32_load); builder.local("cknull_ptr", leaveOnStack ? WasmOpcode.tee_local : WasmOpcode.set_local); if (traceNullCheckOptimizations) - console.log(`(0x${(ip).toString(16)}) cknull_ptr := locals[${localOffset}] (fresh load, already null checked at 0x${notNullSince.get(localOffset)!.toString(16)})`); + mono_log_info(`(0x${(ip).toString(16)}) cknull_ptr := locals[${localOffset}] (fresh load, already null checked at 0x${notNullSince.get(localOffset)!.toString(16)})`); cknullOffset = localOffset; } @@ -1590,7 +1591,7 @@ function append_ldloc_cknull(builder: WasmBuilder, localOffset: number, ip: Mint ) { notNullSince.set(localOffset, ip); if (traceNullCheckOptimizations) - console.log(`(0x${(ip).toString(16)}) cknull_ptr := locals[${localOffset}] (fresh load, fresh null check)`); + mono_log_info(`(0x${(ip).toString(16)}) cknull_ptr := locals[${localOffset}] (fresh load, fresh null check)`); cknullOffset = localOffset; } else cknullOffset = -1; @@ -1849,7 +1850,7 @@ function emit_fieldop( builder.endBlock(); } else { if (traceNullCheckOptimizations) - console.log(`(0x${(ip).toString(16)}) locals[${objectOffset}] not null since 0x${notNullSince.get(objectOffset)!.toString(16)}`); + mono_log_info(`(0x${(ip).toString(16)}) locals[${objectOffset}] not null since 0x${notNullSince.get(objectOffset)!.toString(16)}`); builder.appendU8(WasmOpcode.drop); counters.nullChecksEliminated++; @@ -2330,7 +2331,7 @@ function append_call_handler_store_ret_ip( builder.appendU8(WasmOpcode.i32_store); builder.appendMemarg(clauseDataOffset, 0); // FIXME: 32-bit alignment? - // console.log(`call_handler @0x${(ip).toString(16)} retIp=0x${retIp.toString(16)}`); + // mono_log_info(`call_handler @0x${(ip).toString(16)} retIp=0x${retIp.toString(16)}`); builder.callHandlerReturnAddresses.push(retIp); } @@ -2363,7 +2364,7 @@ function emit_branch( : getArgI16(ip, 1); if (traceBranchDisplacements) - console.log(`br.s @${ip} displacement=${displacement}`); + mono_log_info(`br.s @${ip} displacement=${displacement}`); const destination = ip + (displacement * 2); if (displacement <= 0) { @@ -2372,7 +2373,7 @@ function emit_branch( // to the top of the loop body // append_safepoint(builder, ip); if (traceBackBranches > 1) - console.log(`performing backward branch to 0x${destination.toString(16)}`); + mono_log_info(`performing backward branch to 0x${destination.toString(16)}`); if (isCallHandler) append_call_handler_store_ret_ip(builder, ip, frame, opcode); builder.cfg.branch(destination, true, false); @@ -2381,9 +2382,9 @@ function emit_branch( } else { if (destination < builder.cfg.entryIp) { if ((traceBackBranches > 1) || (builder.cfg.trace > 1)) - console.log(`${getOpcodeName(opcode)} target 0x${destination.toString(16)} before start of trace`); + mono_log_info(`${getOpcodeName(opcode)} target 0x${destination.toString(16)} before start of trace`); } else if ((traceBackBranches > 0) || (builder.cfg.trace > 0)) - console.log(`0x${(ip).toString(16)} ${getOpcodeName(opcode)} target 0x${destination.toString(16)} not found in list ` + + mono_log_info(`0x${(ip).toString(16)} ${getOpcodeName(opcode)} target 0x${destination.toString(16)} not found in list ` + builder.backBranchOffsets.map(bbo => "0x" + (bbo).toString(16)).join(", ") ); @@ -2452,7 +2453,7 @@ function emit_branch( if (!displacement) throw new Error("Branch had no displacement"); else if (traceBranchDisplacements) - console.log(`${getOpcodeName(opcode)} @${ip} displacement=${displacement}`); + mono_log_info(`${getOpcodeName(opcode)} @${ip} displacement=${displacement}`); const destination = ip + (displacement * 2); @@ -2469,15 +2470,15 @@ function emit_branch( // We found a backwards branch target we can reach via our outer trace loop, so // we update eip and branch out to the top of the loop block if (traceBackBranches > 1) - console.log(`performing conditional backward branch to 0x${destination.toString(16)}`); + mono_log_info(`performing conditional backward branch to 0x${destination.toString(16)}`); builder.cfg.branch(destination, true, true); counters.backBranchesEmitted++; } else { if (destination < builder.cfg.entryIp) { if ((traceBackBranches > 1) || (builder.cfg.trace > 1)) - console.log(`${getOpcodeName(opcode)} target 0x${destination.toString(16)} before start of trace`); + mono_log_info(`${getOpcodeName(opcode)} target 0x${destination.toString(16)} before start of trace`); } else if ((traceBackBranches > 0) || (builder.cfg.trace > 0)) - console.log(`0x${(ip).toString(16)} ${getOpcodeName(opcode)} target 0x${destination.toString(16)} not found in list ` + + mono_log_info(`0x${(ip).toString(16)} ${getOpcodeName(opcode)} target 0x${destination.toString(16)} not found in list ` + builder.backBranchOffsets.map(bbo => "0x" + (bbo).toString(16)).join(", ") ); // We didn't find a loop to branch to, so bail out @@ -2522,7 +2523,7 @@ function emit_relop_branch( builder.block(); const displacement = getArgI16(ip, 3); if (traceBranchDisplacements) - console.log(`relop @${ip} displacement=${displacement}`); + mono_log_info(`relop @${ip} displacement=${displacement}`); const operandLoadOp = relopInfo ? relopInfo[1] @@ -3012,7 +3013,7 @@ function getIsWasmSimdSupported(): boolean { new WebAssembly.Module(bytes); wasmSimdSupported = true; } catch (exc) { - console.log("MONO_WASM: Disabling WASM SIMD support due to JIT failure", exc); + mono_log_info("Disabling WASM SIMD support due to JIT failure", exc); wasmSimdSupported = false; } @@ -3126,7 +3127,7 @@ function emit_simd( return true; } default: - console.log(`MONO_WASM: jiterpreter emit_simd failed for ${opname}`); + mono_log_info(`jiterpreter emit_simd failed for ${opname}`); return false; } } diff --git a/src/mono/wasm/runtime/jiterpreter.ts b/src/mono/wasm/runtime/jiterpreter.ts index 5fd241c43049f..7f25b4f1d22bb 100644 --- a/src/mono/wasm/runtime/jiterpreter.ts +++ b/src/mono/wasm/runtime/jiterpreter.ts @@ -21,6 +21,7 @@ import { import { generateWasmBody } from "./jiterpreter-trace-generator"; +import { mono_log_error, mono_log_info, mono_log_warn } from "./logging"; // Controls miscellaneous diagnostic output. export const trace = 0; @@ -235,7 +236,7 @@ function recordBailout(ip: number, base: MintOpcodePtr, reason: BailoutReason) { const info = traceInfo[base]; if (!info) { - console.error(`trace info not found for ${base}`); + mono_log_error(`trace info not found for ${base}`); return; } let table = info.bailoutCounts; @@ -728,7 +729,7 @@ function generate_wasm( if (useDebugCount) { if (cwraps.mono_jiterp_debug_count() === 0) { if (countLimitedPrintCounter-- >= 0) - console.log(`COUNT limited: ${methodFullName || methodName} @${(traceOffset).toString(16)}`); + mono_log_info(`COUNT limited: ${methodFullName || methodName} @${(traceOffset).toString(16)}`); return 0; } } @@ -744,7 +745,7 @@ function generate_wasm( ); const instrumentedTraceId = instrument ? nextInstrumentedTraceId++ : 0; if (instrument) { - console.log(`instrumenting: ${methodFullName}`); + mono_log_info(`instrumenting: ${methodFullName}`); instrumentedTraces[instrumentedTraceId] = new InstrumentedTraceState(methodFullName); } builder.compressImportNames = compressImportNames && !instrument; @@ -811,20 +812,20 @@ function generate_wasm( ti.abortReason = "trace-too-small"; if (traceTooSmall && (traceValue > 1)) - console.log(`${traceName} too small: value=${traceValue}, ${builder.current.size} wasm bytes`); + mono_log_info(`${traceName} too small: value=${traceValue}, ${builder.current.size} wasm bytes`); return 0; } compileStarted = _now(); const buffer = builder.getArrayView(); - // console.log(`bytes generated: ${buffer.length}`); + // mono_log_info(`bytes generated: ${buffer.length}`); if (trace > 0) - console.log(`${((builder.base)).toString(16)} ${methodFullName || traceName} generated ${buffer.length} byte(s) of wasm`); + mono_log_info(`${((builder.base)).toString(16)} ${methodFullName || traceName} generated ${buffer.length} byte(s) of wasm`); counters.bytesGenerated += buffer.length; if (buffer.length >= maxModuleSize) { - console.warn(`MONO_WASM: Jiterpreter generated too much code (${buffer.length} bytes) for trace ${traceName}. Please report this issue.`); + mono_log_warn(`Jiterpreter generated too much code (${buffer.length} bytes) for trace ${traceName}. Please report this issue.`); return 0; } @@ -854,7 +855,7 @@ function generate_wasm( if (!idx) throw new Error("add_function_pointer returned a 0 index"); else if (trace >= 2) - console.log(`${traceName} -> fn index ${idx}`); + mono_log_info(`${traceName} -> fn index ${idx}`); // Ensure that a bit of ongoing diagnostic output is printed for very long-running test // suites or benchmarks if you've enabled stats @@ -865,7 +866,7 @@ function generate_wasm( } catch (exc: any) { threw = true; rejected = false; - console.error(`MONO_WASM: ${methodFullName || traceName} code generation failed: ${exc} ${exc.stack}`); + mono_log_error(`${methodFullName || traceName} code generation failed: ${exc} ${exc.stack}`); recordFailure(); return 0; } finally { @@ -880,10 +881,10 @@ function generate_wasm( if (threw || (!rejected && ((trace >= 2) || mostRecentOptions!.dumpTraces)) || instrument) { if (threw || (trace >= 3) || mostRecentOptions!.dumpTraces || instrument) { for (let i = 0; i < builder.traceBuf.length; i++) - console.log(builder.traceBuf[i]); + mono_log_info(builder.traceBuf[i]); } - console.log(`// MONO_WASM: ${methodFullName || traceName} generated, blob follows //`); + mono_log_info(`// ${methodFullName || traceName} generated, blob follows //`); let s = "", j = 0; try { // We may have thrown an uncaught exception while inside a block, @@ -906,13 +907,13 @@ function generate_wasm( s += b.toString(16); s += " "; if ((s.length % 10) === 0) { - console.log(`${j}\t${s}`); + mono_log_info(`${j}\t${s}`); s = ""; j = i + 1; } } - console.log(`${j}\t${s}`); - console.log("// end blob //"); + mono_log_info(`${j}\t${s}`); + mono_log_info("// end blob //"); } } } @@ -947,7 +948,7 @@ export function record_abort(traceIp: MintOpcodePtr, ip: MintOpcodePtr, traceNam } if ((traceAbortLocations && (reason !== "end-of-body")) || (trace >= 2)) - console.log(`abort ${traceIp} ${traceName}@${ip} ${reason}`); + mono_log_info(`abort ${traceIp} ${traceName}@${ip} ${reason}`); traceInfo[traceIp].abortReason = reason; } @@ -1034,10 +1035,10 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { if (!mostRecentOptions.enableStats && (b !== undefined)) return; - console.log(`// jitted ${counters.bytesGenerated} bytes; ${counters.tracesCompiled} traces (${counters.traceCandidates} candidates, ${(counters.tracesCompiled / counters.traceCandidates * 100).toFixed(1)}%); ${counters.jitCallsCompiled} jit_calls (${(counters.directJitCallsCompiled / counters.jitCallsCompiled * 100).toFixed(1)}% direct); ${counters.entryWrappersCompiled} interp_entries`); + mono_log_info(`// jitted ${counters.bytesGenerated} bytes; ${counters.tracesCompiled} traces (${counters.traceCandidates} candidates, ${(counters.tracesCompiled / counters.traceCandidates * 100).toFixed(1)}%); ${counters.jitCallsCompiled} jit_calls (${(counters.directJitCallsCompiled / counters.jitCallsCompiled * 100).toFixed(1)}% direct); ${counters.entryWrappersCompiled} interp_entries`); const backBranchHitRate = (counters.backBranchesEmitted / (counters.backBranchesEmitted + counters.backBranchesNotEmitted)) * 100; const tracesRejected = cwraps.mono_jiterp_get_rejected_trace_count(); - console.log(`// time: ${elapsedTimes.generation | 0}ms generating, ${elapsedTimes.compilation | 0}ms compiling wasm. ${counters.nullChecksEliminated} cknulls removed. ${counters.backBranchesEmitted} back-branches (${counters.backBranchesNotEmitted} failed, ${backBranchHitRate.toFixed(1)}%), ${tracesRejected} traces rejected`); + mono_log_info(`// time: ${elapsedTimes.generation | 0}ms generating, ${elapsedTimes.compilation | 0}ms compiling wasm. ${counters.nullChecksEliminated} cknulls removed. ${counters.backBranchesEmitted} back-branches (${counters.backBranchesNotEmitted} failed, ${backBranchHitRate.toFixed(1)}%), ${tracesRejected} traces rejected`); if (concise) return; @@ -1047,7 +1048,7 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { for (let i = 0; i < BailoutReasonNames.length; i++) { const bailoutCount = cwraps.mono_jiterp_get_trace_bailout_count(i); if (bailoutCount) - console.log(`// traces bailed out ${bailoutCount} time(s) due to ${BailoutReasonNames[i]}`); + mono_log_info(`// traces bailed out ${bailoutCount} time(s) due to ${BailoutReasonNames[i]}`); } for (let i = 0, c = 0; i < traces.length && c < summaryStatCount; i++) { @@ -1055,9 +1056,9 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { if (!trace.bailoutCount) continue; c++; - console.log(`${trace.name}: ${trace.bailoutCount} bailout(s)`); + mono_log_info(`${trace.name}: ${trace.bailoutCount} bailout(s)`); for (const k in trace.bailoutCounts) - console.log(` ${BailoutReasonNames[k]} x${trace.bailoutCounts[k]}`); + mono_log_info(` ${BailoutReasonNames[k]} x${trace.bailoutCounts[k]}`); } } @@ -1079,7 +1080,7 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { } if (countCallTargets) { - console.log("// hottest call targets:"); + mono_log_info("// hottest call targets:"); const targetPointers = Object.keys(callTargetCounts); targetPointers.sort((l, r) => callTargetCounts[Number(r)] - callTargetCounts[Number(l)]); for (let i = 0, c = Math.min(summaryStatCount, targetPointers.length); i < c; i++) { @@ -1088,12 +1089,12 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { const targetMethodName = Module.UTF8ToString(pMethodName); const hitCount = callTargetCounts[targetMethod]; Module._free(pMethodName); - console.log(`${targetMethodName} ${hitCount}`); + mono_log_info(`${targetMethodName} ${hitCount}`); } } traces.sort((l, r) => r.hitCount - l.hitCount); - console.log("// hottest failed traces:"); + mono_log_info("// hottest failed traces:"); for (let i = 0, c = 0; i < traces.length && c < summaryStatCount; i++) { // this means the trace has a low hit count and we don't know its identity. no value in // logging it. @@ -1142,7 +1143,7 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { } c++; - console.log(`${traces[i].name} @${traces[i].ip} (${traces[i].hitCount} hits) ${traces[i].abortReason}`); + mono_log_info(`${traces[i].name} @${traces[i].ip} (${traces[i].hitCount} hits) ${traces[i].abortReason}`); } const tuples: Array<[string, number]> = []; @@ -1151,9 +1152,9 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { tuples.sort((l, r) => r[1] - l[1]); - console.log("// heat:"); + mono_log_info("// heat:"); for (let i = 0; i < tuples.length; i++) - console.log(`// ${tuples[i][0]}: ${tuples[i][1]}`); + mono_log_info(`// ${tuples[i][0]}: ${tuples[i][1]}`); } else { for (let i = 0; i < MintOpcode.MINT_LASTOP; i++) { const opname = getOpcodeName(i); @@ -1167,11 +1168,11 @@ export function jiterpreter_dump_stats(b?: boolean, concise?: boolean) { const keys = Object.keys(abortCounts); keys.sort((l, r) => abortCounts[r] - abortCounts[l]); for (let i = 0; i < keys.length; i++) - console.log(`// ${keys[i]}: ${abortCounts[keys[i]]} abort(s)`); + mono_log_info(`// ${keys[i]}: ${abortCounts[keys[i]]} abort(s)`); } for (const k in counters.simdFallback) - console.log(`// simd ${k}: ${counters.simdFallback[k]} fallback insn(s)`); + mono_log_info(`// simd ${k}: ${counters.simdFallback[k]} fallback insn(s)`); if ((typeof (globalThis.setTimeout) === "function") && (b !== undefined)) setTimeout( diff --git a/src/mono/wasm/runtime/loader/assets.ts b/src/mono/wasm/runtime/loader/assets.ts index a99f80a754a33..61298966c0fe9 100644 --- a/src/mono/wasm/runtime/loader/assets.ts +++ b/src/mono/wasm/runtime/loader/assets.ts @@ -5,6 +5,7 @@ import type { AssetEntryInternal, PromiseAndController } from "../types/internal import type { AssetBehaviours, AssetEntry, LoadingResource, ResourceRequest } from "../types"; import { ENVIRONMENT_IS_NODE, ENVIRONMENT_IS_SHELL, loaderHelpers, runtimeHelpers } from "./globals"; import { createPromiseController } from "./promise-controller"; +import { mono_log_debug } from "./logging"; let throttlingPromise: PromiseAndController | undefined; @@ -70,7 +71,7 @@ export function resolve_asset_path(behavior: AssetBehaviours): AssetEntryInterna return asset; } export async function mono_download_assets(): Promise { - if (loaderHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_download_assets"); + mono_log_debug("mono_download_assets"); loaderHelpers.maxParallelDownloads = loaderHelpers.config.maxParallelDownloads || loaderHelpers.maxParallelDownloads; loaderHelpers.enableDownloadRetry = loaderHelpers.config.enableDownloadRetry || loaderHelpers.enableDownloadRetry; try { @@ -180,7 +181,7 @@ export async function mono_download_assets(): Promise { Promise.all(promises_of_asset_instantiation).then(() => { runtimeHelpers.allAssetsInMemory.promise_control.resolve(); }).catch(e => { - loaderHelpers.err("MONO_WASM: Error in mono_download_assets: " + e); + loaderHelpers.err("Error in mono_download_assets: " + e); loaderHelpers.abort_startup(e, true); }); // OPTIMIZATION explained: @@ -188,7 +189,7 @@ export async function mono_download_assets(): Promise { // spreading in time // rather than to block all downloads after onRuntimeInitialized or block onRuntimeInitialized after all downloads are done. That would create allocation burst. } catch (e: any) { - loaderHelpers.err("MONO_WASM: Error in mono_download_assets: " + e); + loaderHelpers.err("Error in mono_download_assets: " + e); throw e; } } @@ -244,8 +245,7 @@ async function start_asset_download_with_throttle(asset: AssetEntryInternal): Pr try { ++parallel_count; if (parallel_count == loaderHelpers.maxParallelDownloads) { - if (loaderHelpers.diagnosticTracing) - console.debug("MONO_WASM: Throttling further parallel downloads"); + mono_log_debug("Throttling further parallel downloads"); throttlingPromise = createPromiseController(); } @@ -264,8 +264,7 @@ async function start_asset_download_with_throttle(asset: AssetEntryInternal): Pr finally { --parallel_count; if (throttlingPromise && parallel_count == loaderHelpers.maxParallelDownloads - 1) { - if (loaderHelpers.diagnosticTracing) - console.debug("MONO_WASM: Resuming more parallel downloads"); + mono_log_debug("Resuming more parallel downloads"); const old_throttling = throttlingPromise; throttlingPromise = undefined; old_throttling.promise_control.resolve(); @@ -307,11 +306,9 @@ async function start_asset_download_sources(asset: AssetEntryInternal): Promise< const attemptUrl = resolve_path(asset, sourcePrefix); if (asset.name === attemptUrl) { - if (loaderHelpers.diagnosticTracing) - console.debug(`MONO_WASM: Attempting to download '${attemptUrl}'`); + mono_log_debug(`Attempting to download '${attemptUrl}'`); } else { - if (loaderHelpers.diagnosticTracing) - console.debug(`MONO_WASM: Attempting to download '${attemptUrl}' for ${asset.name}`); + mono_log_debug(`Attempting to download '${attemptUrl}' for ${asset.name}`); } try { asset.resolvedUrl = attemptUrl; @@ -338,11 +335,11 @@ async function start_asset_download_sources(asset: AssetEntryInternal): Promise< const isOkToFail = asset.isOptional || (asset.name.match(/\.pdb$/) && loaderHelpers.config.ignorePdbLoadErrors); mono_assert(response, () => `Response undefined ${asset.name}`); if (!isOkToFail) { - const err: any = new Error(`MONO_WASM: download '${response.url}' for ${asset.name} failed ${response.status} ${response.statusText}`); + const err: any = new Error(`download '${response.url}' for ${asset.name} failed ${response.status} ${response.statusText}`); err.status = response.status; throw err; } else { - loaderHelpers.out(`MONO_WASM: optional download '${response.url}' for ${asset.name} failed ${response.status} ${response.statusText}`); + loaderHelpers.out(`optional download '${response.url}' for ${asset.name} failed ${response.status} ${response.statusText}`); return undefined; } } diff --git a/src/mono/wasm/runtime/loader/blazor/WebAssemblyResourceLoader.ts b/src/mono/wasm/runtime/loader/blazor/WebAssemblyResourceLoader.ts index d0960a287e96a..0c3208e785174 100644 --- a/src/mono/wasm/runtime/loader/blazor/WebAssemblyResourceLoader.ts +++ b/src/mono/wasm/runtime/loader/blazor/WebAssemblyResourceLoader.ts @@ -48,20 +48,28 @@ export class WebAssemblyResourceLoader { } const linkerDisabledWarning = this.bootConfig.linkerEnabled ? "%c" : "\n%cThis application was built with linking (tree shaking) disabled. Published applications will be significantly smaller."; + // eslint-disable-next-line no-console console.groupCollapsed(`%cdotnet%c Loaded ${toDataSizeString(totalResponseBytes)} resources${linkerDisabledWarning}`, "background: purple; color: white; padding: 1px 3px; border-radius: 3px;", "font-weight: bold;", "font-weight: normal;"); if (cacheLoadsEntries.length) { + // eslint-disable-next-line no-console console.groupCollapsed(`Loaded ${toDataSizeString(cacheResponseBytes)} resources from cache`); + // eslint-disable-next-line no-console console.table(this.cacheLoads); + // eslint-disable-next-line no-console console.groupEnd(); } if (networkLoadsEntries.length) { + // eslint-disable-next-line no-console console.groupCollapsed(`Loaded ${toDataSizeString(networkResponseBytes)} resources from network`); + // eslint-disable-next-line no-console console.table(this.networkLoads); + // eslint-disable-next-line no-console console.groupEnd(); } + // eslint-disable-next-line no-console console.groupEnd(); } diff --git a/src/mono/wasm/runtime/loader/config.ts b/src/mono/wasm/runtime/loader/config.ts index 1d09292a0c9f1..695911efe018b 100644 --- a/src/mono/wasm/runtime/loader/config.ts +++ b/src/mono/wasm/runtime/loader/config.ts @@ -8,6 +8,7 @@ import { exportedRuntimeAPI, loaderHelpers, runtimeHelpers } from "./globals"; import { initializeBootConfig, loadBootConfig } from "./blazor/_Integration"; import { BootConfigResult } from "./blazor/BootConfig"; import { BootJsonData } from "../types/blazor"; +import { mono_log_error, mono_log_debug } from "./logging"; export function deep_merge_config(target: MonoConfigInternal, source: MonoConfigInternal): MonoConfigInternal { const providedConfig: MonoConfigInternal = { ...source }; @@ -56,7 +57,7 @@ export function normalizeConfig() { runtimeHelpers.waitForDebugger = config.waitForDebugger; config.startupMemoryCache = !!config.startupMemoryCache; if (config.startupMemoryCache && runtimeHelpers.waitForDebugger) { - if (loaderHelpers.diagnosticTracing) console.info("MONO_WASM: Disabling startupMemoryCache because waitForDebugger is set"); + mono_log_debug("Disabling startupMemoryCache because waitForDebugger is set"); config.startupMemoryCache = false; } @@ -79,7 +80,7 @@ export async function mono_wasm_load_config(module: DotnetModuleInternal): Promi loaderHelpers.afterConfigLoaded.promise_control.resolve(loaderHelpers.config); return; } - if (loaderHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_load_config"); + mono_log_debug("mono_wasm_load_config"); try { loaderHelpers.config.applicationEnvironment = loaderHelpers.config.applicationEnvironment ?? loaderHelpers.config.startupOptions?.environment ?? "Production"; @@ -111,7 +112,7 @@ export async function mono_wasm_load_config(module: DotnetModuleInternal): Promi normalizeConfig(); } catch (err: any) { - console.error("MONO_WASM: onConfigLoaded() failed", err); + mono_log_error("onConfigLoaded() failed", err); throw err; } } diff --git a/src/mono/wasm/runtime/loader/exit.ts b/src/mono/wasm/runtime/loader/exit.ts index 818e8116bd3f0..340d99c386b95 100644 --- a/src/mono/wasm/runtime/loader/exit.ts +++ b/src/mono/wasm/runtime/loader/exit.ts @@ -2,10 +2,10 @@ // The .NET Foundation licenses this file to you under the MIT license. import { ENVIRONMENT_IS_NODE, ENVIRONMENT_IS_SHELL, ENVIRONMENT_IS_WEB, INTERNAL, loaderHelpers, runtimeHelpers } from "./globals"; -import { consoleWebSocket } from "./logging"; +import { mono_log_debug, consoleWebSocket, mono_log_error, mono_log_info_no_prefix } from "./logging"; export function abort_startup(reason: any, should_exit: boolean): void { - if (loaderHelpers.diagnosticTracing) console.trace("MONO_WASM: abort_startup"); + mono_log_debug("abort_startup"); loaderHelpers.allDownloadsQueued.promise_control.reject(reason); loaderHelpers.afterConfigLoaded.promise_control.reject(reason); loaderHelpers.wasmDownloadPromise.promise_control.reject(reason); @@ -67,7 +67,7 @@ async function flush_node_streams() { const stdoutFlushed = flushStream(process.stdout); await Promise.all([stdoutFlushed, stderrFlushed]); } catch (err) { - console.error(`flushing std* streams failed: ${err}`); + mono_log_error(`flushing std* streams failed: ${err}`); } } @@ -126,18 +126,18 @@ function logErrorOnExit(exit_code: number, reason?: any) { if (loaderHelpers.config && loaderHelpers.config.logExitCode) { if (exit_code != 0 && reason) { if (reason instanceof Error && runtimeHelpers.stringify_as_error_with_stack) - console.error(runtimeHelpers.stringify_as_error_with_stack(reason)); + mono_log_error(runtimeHelpers.stringify_as_error_with_stack(reason)); else if (typeof reason == "string") - console.error(reason); + mono_log_error(reason); else - console.error(JSON.stringify(reason)); + mono_log_error(JSON.stringify(reason)); } if (consoleWebSocket) { const stop_when_ws_buffer_empty = () => { if (consoleWebSocket.bufferedAmount == 0) { // tell xharness WasmTestMessagesProcessor we are done. // note this sends last few bytes into the same WS - console.log("WASM EXIT " + exit_code); + mono_log_info_no_prefix("WASM EXIT " + exit_code); } else { setTimeout(stop_when_ws_buffer_empty, 100); @@ -145,7 +145,7 @@ function logErrorOnExit(exit_code: number, reason?: any) { }; stop_when_ws_buffer_empty(); } else { - console.log("WASM EXIT " + exit_code); + mono_log_info_no_prefix("WASM EXIT " + exit_code); } } } diff --git a/src/mono/wasm/runtime/loader/icu.ts b/src/mono/wasm/runtime/loader/icu.ts index 39e2bccd14b29..74990738b7266 100644 --- a/src/mono/wasm/runtime/loader/icu.ts +++ b/src/mono/wasm/runtime/loader/icu.ts @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. import { ENVIRONMENT_IS_WEB, loaderHelpers } from "./globals"; +import { mono_log_info, mono_log_debug } from "./logging"; export function init_globalization() { loaderHelpers.invariantMode = loaderHelpers.config.globalizationMode === "invariant"; @@ -9,14 +10,14 @@ export function init_globalization() { if (!loaderHelpers.invariantMode) { if (loaderHelpers.preferredIcuAsset) { - if (loaderHelpers.diagnosticTracing) console.debug("MONO_WASM: ICU data archive(s) available, disabling invariant mode"); + mono_log_debug("ICU data archive(s) available, disabling invariant mode"); } else if (loaderHelpers.config.globalizationMode !== "icu") { - if (loaderHelpers.diagnosticTracing) console.debug("MONO_WASM: ICU data archive(s) not available, using invariant globalization mode"); + mono_log_debug("ICU data archive(s) not available, using invariant globalization mode"); loaderHelpers.invariantMode = true; loaderHelpers.preferredIcuAsset = null; } else { const msg = "invariant globalization mode is inactive and no ICU data archives are available"; - loaderHelpers.err(`MONO_WASM: ERROR: ${msg}`); + loaderHelpers.err(`ERROR: ${msg}`); throw new Error(msg); } } @@ -38,7 +39,7 @@ export function init_globalization() { env_variables!["TZ"] = timezone; } } catch { - console.info("MONO_WASM: failed to detect timezone, will fallback to UTC"); + mono_log_info("failed to detect timezone, will fallback to UTC"); } } } diff --git a/src/mono/wasm/runtime/loader/logging.ts b/src/mono/wasm/runtime/loader/logging.ts index 7be1ec67bd022..72a62f97487fb 100644 --- a/src/mono/wasm/runtime/loader/logging.ts +++ b/src/mono/wasm/runtime/loader/logging.ts @@ -1,6 +1,32 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. +/* eslint-disable no-console */ +import { loaderHelpers } from "./globals"; + +const prefix = "MONO_WASM: "; + +export function mono_log_debug(msg: string, ...data: any) { + if (loaderHelpers.diagnosticTracing) { + console.debug(prefix + msg, ...data); + } +} + +export function mono_log_info(msg: string, ...data: any) { + console.info(prefix + msg, ...data); +} + +export function mono_log_info_no_prefix(msg: string, ...data: any) { + console.info(msg, ...data); +} + +export function mono_log_warn(msg: string, ...data: any) { + console.warn(prefix + msg, ...data); +} + +export function mono_log_error(msg: string, ...data: any) { + console.error(prefix + msg, ...data); +} export let consoleWebSocket: WebSocket; export function setup_proxy_console(id: string, console: Console, origin: string): void { diff --git a/src/mono/wasm/runtime/loader/polyfills.ts b/src/mono/wasm/runtime/loader/polyfills.ts index dd757148528be..fb5c4bc2a6c2e 100644 --- a/src/mono/wasm/runtime/loader/polyfills.ts +++ b/src/mono/wasm/runtime/loader/polyfills.ts @@ -15,7 +15,9 @@ export async function init_polyfills(module: DotnetModuleInternal): Promise(); const regexes: any[] = []; @@ -54,7 +75,7 @@ export function mono_wasm_symbolicate_string(message: string): string { return origMessage; } catch (error) { - console.debug(`MONO_WASM: failed to symbolicate: ${error}`); + console.debug(`failed to symbolicate: ${error}`); return message; } } @@ -117,5 +138,5 @@ export function parseSymbolMapFile(text: string) { wasm_func_map.set(Number(parts[0]), parts[1]); }); - if (runtimeHelpers.diagnosticTracing) console.debug(`MONO_WASM: Loaded ${wasm_func_map.size} symbols`); + mono_log_debug(`Loaded ${wasm_func_map.size} symbols`); } \ No newline at end of file diff --git a/src/mono/wasm/runtime/marshal-to-js.ts b/src/mono/wasm/runtime/marshal-to-js.ts index 1cbf461e6a7f0..eebe3a9d53edc 100644 --- a/src/mono/wasm/runtime/marshal-to-js.ts +++ b/src/mono/wasm/runtime/marshal-to-js.ts @@ -217,7 +217,6 @@ export function marshal_task_to_js(arg: JSMarshalerArgument, _?: MarshalerType, } const js_handle = get_arg_js_handle(arg); - // console.log("_marshal_task_to_js A" + js_handle); if (js_handle == JSHandleNull) { // this is already resolved void return new Promise((resolve) => resolve(undefined)); @@ -229,7 +228,6 @@ export function marshal_task_to_js(arg: JSMarshalerArgument, _?: MarshalerType, const orig_resolve = promise_control.resolve; promise_control.resolve = (argInner: JSMarshalerArgument) => { - // console.log("_marshal_task_to_js R" + js_handle); const type = get_arg_type(argInner); if (type === MarshalerType.None) { orig_resolve(null); diff --git a/src/mono/wasm/runtime/net6-legacy/method-binding.ts b/src/mono/wasm/runtime/net6-legacy/method-binding.ts index 18ec6210acf43..8434bcfe6dc9b 100644 --- a/src/mono/wasm/runtime/net6-legacy/method-binding.ts +++ b/src/mono/wasm/runtime/net6-legacy/method-binding.ts @@ -15,6 +15,7 @@ import { get_js_owned_object_by_gc_handle_ref, _unbox_mono_obj_root_with_known_n import { legacyHelpers } from "./globals"; import { js_to_mono_obj_root, _js_to_mono_uri_root, js_to_mono_enum } from "./js-to-cs"; import { _teardown_after_call } from "./method-calls"; +import { mono_log_warn } from "../logging"; const escapeRE = /[^A-Za-z0-9_$]/g; @@ -308,7 +309,7 @@ export function _compile_converter_for_marshal_string(args_marshal: string/*Args converter.compiled_function = compiledFunction; } catch (exc) { converter.compiled_function = null; - console.warn("MONO_WASM: compiling converter failed for", bodyJs, "with error", exc); + mono_log_warn("compiling converter failed for", bodyJs, "with error", exc); throw exc; } @@ -341,7 +342,7 @@ export function _compile_converter_for_marshal_string(args_marshal: string/*Args converter.compiled_variadic_function = compiledVariadicFunction; } catch (exc) { converter.compiled_variadic_function = null; - console.warn("MONO_WASM: compiling converter failed for", bodyJs, "with error", exc); + mono_log_warn("compiling converter failed for", bodyJs, "with error", exc); throw exc; } @@ -355,7 +356,7 @@ function _maybe_produce_signature_warning(converter: Converter) { if (converter.has_warned_about_signature) return; - console.warn("MONO_WASM: Deprecated raw return value signature: '" + converter.args_marshal + "'. End the signature with '!' instead of 'm'."); + mono_log_warn("Deprecated raw return value signature: '" + converter.args_marshal + "'. End the signature with '!' instead of 'm'."); converter.has_warned_about_signature = true; } diff --git a/src/mono/wasm/runtime/polyfills.ts b/src/mono/wasm/runtime/polyfills.ts index 597821b56768c..8502962e60260 100644 --- a/src/mono/wasm/runtime/polyfills.ts +++ b/src/mono/wasm/runtime/polyfills.ts @@ -7,6 +7,7 @@ import type { EmscriptenReplacements } from "./types/internal"; import type { TypedArray } from "./types/emscripten"; import { ENVIRONMENT_IS_NODE, ENVIRONMENT_IS_WEB, INTERNAL, Module, loaderHelpers, runtimeHelpers } from "./globals"; import { replaceEmscriptenPThreadLibrary } from "./pthreads/shared/emscripten-replacements"; +import { mono_log_info } from "./logging"; const dummyPerformance = { now: function () { @@ -28,8 +29,8 @@ export function initializeReplacements(replacements: EmscriptenReplacements): vo } if (BuildConfiguration === "Debug") { - console.debug(`MONO_WASM: starting script ${loaderHelpers.scriptUrl}`); - console.debug(`MONO_WASM: starting in ${loaderHelpers.scriptDirectory}`); + mono_log_info(`starting script ${loaderHelpers.scriptUrl}`); + mono_log_info(`starting in ${loaderHelpers.scriptDirectory}`); } // prefer fetch_like over global fetch for assets diff --git a/src/mono/wasm/runtime/pthreads/browser/index.ts b/src/mono/wasm/runtime/pthreads/browser/index.ts index 0fbefa9cf9443..134f78ecdc268 100644 --- a/src/mono/wasm/runtime/pthreads/browser/index.ts +++ b/src/mono/wasm/runtime/pthreads/browser/index.ts @@ -8,6 +8,7 @@ import Internals from "../shared/emscripten-internals"; import { createPromiseController, runtimeHelpers } from "../../globals"; import { PromiseController } from "../../types/internal"; import { MonoConfig } from "../../types"; +import { mono_log_debug } from "../../logging"; const threads: Map = new Map(); @@ -81,7 +82,7 @@ export const getThreadIds = (): IterableIterator => threads.keys(); function monoDedicatedChannelMessageFromWorkerToMain(event: MessageEvent, thread: Thread): void { // TODO: add callbacks that will be called from here - console.debug("MONO_WASM: got message from worker on the dedicated channel", event.data, thread); + mono_log_debug("got message from worker on the dedicated channel", event.data, thread); } // handler that runs in the main thread when a message is received from a pthread worker @@ -93,7 +94,7 @@ function monoWorkerMessageHandler(worker: Worker, ev: MessageEvent monoWorkerMessageHandler(worker, ev)); - console.debug("MONO_WASM: afterLoadWasmModuleToWorker added message event handler", worker); + mono_log_debug("afterLoadWasmModuleToWorker added message event handler", worker); } /// We call on the main thread this during startup to pre-allocate a pool of pthread workers. diff --git a/src/mono/wasm/runtime/pthreads/shared/emscripten-replacements.ts b/src/mono/wasm/runtime/pthreads/shared/emscripten-replacements.ts index be5962ef6269d..a179b5b111cd1 100644 --- a/src/mono/wasm/runtime/pthreads/shared/emscripten-replacements.ts +++ b/src/mono/wasm/runtime/pthreads/shared/emscripten-replacements.ts @@ -5,8 +5,9 @@ import MonoWasmThreads from "consts:monoWasmThreads"; import { afterLoadWasmModuleToWorker } from "../browser"; import { afterThreadInitTLS } from "../worker"; import Internals from "./emscripten-internals"; -import { loaderHelpers, runtimeHelpers } from "../../globals"; +import { loaderHelpers } from "../../globals"; import { PThreadReplacements } from "../../types/internal"; +import { mono_log_debug } from "../../logging"; /** @module emscripten-replacements Replacements for individual functions in the emscripten PThreads library. * These have a hard dependency on the version of Emscripten that we are using and may need to be kept in sync with @@ -33,8 +34,7 @@ export function replaceEmscriptenPThreadLibrary(replacements: PThreadReplacement /// We replace Module["PThreads"].allocateUnusedWorker with this version that knows about assets function replacementAllocateUnusedWorker(): void { - if (runtimeHelpers.diagnosticTracing) - console.debug("MONO_WASM: replacementAllocateUnusedWorker"); + mono_log_debug("replacementAllocateUnusedWorker"); const asset = loaderHelpers.resolve_asset_path("js-module-threads"); const uri = asset.resolvedUrl; mono_assert(uri !== undefined, "could not resolve the uri for the js-module-threads asset"); diff --git a/src/mono/wasm/runtime/pthreads/worker/index.ts b/src/mono/wasm/runtime/pthreads/worker/index.ts index 8d8c7e6d19aa4..376aa39bc2c3e 100644 --- a/src/mono/wasm/runtime/pthreads/worker/index.ts +++ b/src/mono/wasm/runtime/pthreads/worker/index.ts @@ -4,7 +4,7 @@ /// import MonoWasmThreads from "consts:monoWasmThreads"; -import { Module, ENVIRONMENT_IS_PTHREAD, runtimeHelpers } from "../../globals"; +import { Module, ENVIRONMENT_IS_PTHREAD } from "../../globals"; import { makeChannelCreatedMonoMessage } from "../shared"; import type { pthread_ptr } from "../shared/types"; import { is_nullish } from "../../types/internal"; @@ -17,6 +17,7 @@ import { WorkerThreadEventTarget } from "./events"; import { preRunWorker } from "../../startup"; +import { mono_log_debug } from "../../logging"; // re-export some of the events types export { @@ -50,7 +51,7 @@ export let pthread_self: PThreadSelf = null as any as PThreadSelf; /// pthreads that are running on the current worker. /// Example: /// currentWorkerThreadEvents.addEventListener(dotnetPthreadCreated, (ev: WorkerThreadEvent) => { -/// console.debug("MONO_WASM: thread created on worker with id", ev.pthread_ptr); +/// mono_trace("thread created on worker with id", ev.pthread_ptr); /// }); export const currentWorkerThreadEvents: WorkerThreadEventTarget = MonoWasmThreads ? new EventTarget() : null as any as WorkerThreadEventTarget; // treeshake if threads are disabled @@ -59,12 +60,12 @@ export const currentWorkerThreadEvents: WorkerThreadEventTarget = // this is the message handler for the worker that receives messages from the main thread // extend this with new cases as needed function monoDedicatedChannelMessageFromMainToWorker(event: MessageEvent): void { - console.debug("MONO_WASM: got message from main on the dedicated channel", event.data); + mono_log_debug("got message from main on the dedicated channel", event.data); } function setupChannelToMainThread(pthread_ptr: pthread_ptr): PThreadSelf { - console.debug("MONO_WASM: creating a channel", pthread_ptr); + mono_log_debug("creating a channel", pthread_ptr); const channel = new MessageChannel(); const workerPort = channel.port1; const mainPort = channel.port2; @@ -81,8 +82,7 @@ function setupChannelToMainThread(pthread_ptr: pthread_ptr): PThreadSelf { export function mono_wasm_pthread_on_pthread_attached(pthread_id: pthread_ptr): void { const self = pthread_self; mono_assert(self !== null && self.pthread_id == pthread_id, "expected pthread_self to be set already when attaching"); - if (runtimeHelpers.diagnosticTracing) - console.debug("MONO_WASM: attaching pthread to runtime 0x" + pthread_id.toString(16)); + mono_log_debug("attaching pthread to runtime 0x" + pthread_id.toString(16)); preRunWorker(); currentWorkerThreadEvents.dispatchEvent(makeWorkerThreadEvent(dotnetPthreadAttached, self)); } @@ -95,8 +95,7 @@ export function afterThreadInitTLS(): void { if (ENVIRONMENT_IS_PTHREAD) { const pthread_ptr = (Module)["_pthread_self"](); mono_assert(!is_nullish(pthread_ptr), "pthread_self() returned null"); - if (runtimeHelpers.diagnosticTracing) - console.debug("MONO_WASM: after thread init, pthread ptr 0x" + pthread_ptr.toString(16)); + mono_log_debug("after thread init, pthread ptr 0x" + pthread_ptr.toString(16)); const self = setupChannelToMainThread(pthread_ptr); currentWorkerThreadEvents.dispatchEvent(makeWorkerThreadEvent(dotnetPthreadCreated, self)); } diff --git a/src/mono/wasm/runtime/rollup.config.js b/src/mono/wasm/runtime/rollup.config.js index 6e7279dbb3423..a9f04beddde21 100644 --- a/src/mono/wasm/runtime/rollup.config.js +++ b/src/mono/wasm/runtime/rollup.config.js @@ -375,5 +375,6 @@ function onwarn(warning) { return; } + // eslint-disable-next-line no-console console.warn(`(!) ${warning.toString()}`); } diff --git a/src/mono/wasm/runtime/run.ts b/src/mono/wasm/runtime/run.ts index bdbb2f8e7bfa8..5839b4538e868 100644 --- a/src/mono/wasm/runtime/run.ts +++ b/src/mono/wasm/runtime/run.ts @@ -6,6 +6,7 @@ import { mono_wasm_wait_for_debugger } from "./debug"; import { mono_wasm_set_main_args } from "./startup"; import cwraps from "./cwraps"; import { assembly_load } from "./class-loader"; +import { mono_log_info } from "./logging"; /** * Possible signatures are described here https://docs.microsoft.com/en-us/dotnet/csharp/fundamentals/program-structure/main-command-line @@ -30,7 +31,7 @@ export async function mono_run_main_and_exit(main_assembly_name: string, args: s export async function mono_run_main(main_assembly_name: string, args: string[]): Promise { mono_wasm_set_main_args(main_assembly_name, args); if (runtimeHelpers.waitForDebugger == -1) { - console.log("MONO_WASM: waiting for debugger..."); + mono_log_info("waiting for debugger..."); await mono_wasm_wait_for_debugger(); } const method = find_entry_point(main_assembly_name); diff --git a/src/mono/wasm/runtime/snapshot.ts b/src/mono/wasm/runtime/snapshot.ts index 02b9e452e7bda..bce9062016d33 100644 --- a/src/mono/wasm/runtime/snapshot.ts +++ b/src/mono/wasm/runtime/snapshot.ts @@ -5,6 +5,7 @@ import ProductVersion from "consts:productVersion"; import GitHash from "consts:gitHash"; import MonoWasmThreads from "consts:monoWasmThreads"; import { ENVIRONMENT_IS_WEB, loaderHelpers, runtimeHelpers } from "./globals"; +import { mono_log_warn } from "./logging"; const memoryPrefix = "https://dotnet.generated.invalid/wasm-memory"; @@ -39,7 +40,7 @@ async function openCache(): Promise { } catch { // There's no known scenario where we should get an exception here, but considering the // Chromium bug above, let's tolerate it and treat as "proceed without caching". - console.warn("MONO_WASM: Failed to open cache"); + mono_log_warn("Failed to open cache"); return null; } } @@ -58,7 +59,7 @@ export async function getMemorySnapshotSize(): Promise { const contentLength = res?.headers.get("content-length"); return contentLength ? parseInt(contentLength) : undefined; } catch (ex) { - console.warn("MONO_WASM: Failed find memory snapshot in the cache", ex); + mono_log_warn("Failed find memory snapshot in the cache", ex); return undefined; } } @@ -79,7 +80,7 @@ export async function getMemorySnapshot(): Promise { } return res.arrayBuffer(); } catch (ex) { - console.warn("MONO_WASM: Failed load memory snapshot from the cache", ex); + mono_log_warn("Failed load memory snapshot from the cache", ex); return undefined; } } @@ -110,7 +111,7 @@ export async function storeMemorySnapshot(memory: ArrayBuffer) { cleanupMemorySnapshots(cacheKey); // no await } catch (ex) { - console.warn("MONO_WASM: Failed to store memory snapshot in the cache", ex); + mono_log_warn("Failed to store memory snapshot in the cache", ex); return; } } diff --git a/src/mono/wasm/runtime/startup.ts b/src/mono/wasm/runtime/startup.ts index 848629bc7639e..91732b54774e6 100644 --- a/src/mono/wasm/runtime/startup.ts +++ b/src/mono/wasm/runtime/startup.ts @@ -29,6 +29,7 @@ import { getMemorySnapshot, storeMemorySnapshot, getMemorySnapshotSize } from ". import { init_legacy_exports } from "./net6-legacy/corebindings"; import { cwraps_binding_api, cwraps_mono_api } from "./net6-legacy/exports-legacy"; import { BINDING, MONO } from "./net6-legacy/globals"; +import { mono_log_debug, mono_log_warn } from "./logging"; // default size if MonoConfig.pthreadPoolSize is undefined @@ -45,10 +46,12 @@ export function configureEmscriptenStartup(module: DotnetModuleInternal): void { } if (!module.out) { + // eslint-disable-next-line no-console module.out = console.log.bind(console); } if (!module.err) { + // eslint-disable-next-line no-console module.err = console.error.bind(console); } loaderHelpers.out = module.out; @@ -142,12 +145,12 @@ function preInit(userPreInit: (() => void)[]) { const mark = startMeasure(); try { mono_wasm_pre_init_essential(false); - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: preInit"); + mono_log_debug("preInit"); runtimeHelpers.beforePreInit.promise_control.resolve(); // all user Module.preInit callbacks userPreInit.forEach(fn => fn()); } catch (err) { - _print_error("MONO_WASM: user preInint() failed", err); + _print_error("user preInint() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -175,17 +178,17 @@ function preInit(userPreInit: (() => void)[]) { } async function preInitWorkerAsync() { - console.debug("MONO_WASM: worker initializing essential C exports and APIs"); + mono_log_debug("worker initializing essential C exports and APIs"); const mark = startMeasure(); try { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: preInitWorker"); + mono_log_debug("preInitWorker"); runtimeHelpers.beforePreInit.promise_control.resolve(); mono_wasm_pre_init_essential(true); await init_polyfills_async(); runtimeHelpers.afterPreInit.promise_control.resolve(); endMeasure(mark, MeasuredBlock.preInitWorker); } catch (err) { - _print_error("MONO_WASM: user preInitWorker() failed", err); + _print_error("user preInitWorker() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -210,13 +213,13 @@ async function preRunAsync(userPreRun: (() => void)[]) { try { await runtimeHelpers.afterInstantiateWasm.promise; await runtimeHelpers.afterPreInit.promise; - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: preRunAsync"); + mono_log_debug("preRunAsync"); const mark = startMeasure(); // all user Module.preRun callbacks userPreRun.map(fn => fn()); endMeasure(mark, MeasuredBlock.preRun); } catch (err) { - _print_error("MONO_WASM: user callback preRun() failed", err); + _print_error("user callback preRun() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -229,7 +232,7 @@ async function onRuntimeInitializedAsync(userOnRuntimeInitialized: () => void) { try { // wait for previous stage await runtimeHelpers.afterPreRun.promise; - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: onRuntimeInitialized"); + mono_log_debug("onRuntimeInitialized"); const mark = startMeasure(); // signal this stage, this will allow pending assets to allocate memory runtimeHelpers.beforeOnRuntimeInitialized.promise_control.resolve(); @@ -283,14 +286,14 @@ async function onRuntimeInitializedAsync(userOnRuntimeInitialized: () => void) { userOnRuntimeInitialized(); } catch (err: any) { - _print_error("MONO_WASM: user callback onRuntimeInitialized() failed", err); + _print_error("user callback onRuntimeInitialized() failed", err); throw err; } // finish await mono_wasm_after_user_runtime_initialized(); endMeasure(mark, MeasuredBlock.onRuntimeInitialized); } catch (err) { - _print_error("MONO_WASM: onRuntimeInitializedAsync() failed", err); + _print_error("onRuntimeInitializedAsync() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -302,7 +305,7 @@ async function postRunAsync(userpostRun: (() => void)[]) { // wait for previous stage try { await runtimeHelpers.afterOnRuntimeInitialized.promise; - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: postRunAsync"); + mono_log_debug("postRunAsync"); const mark = startMeasure(); // create /usr/share folder which is SpecialFolder.CommonApplicationData @@ -313,7 +316,7 @@ async function postRunAsync(userpostRun: (() => void)[]) { userpostRun.map(fn => fn()); endMeasure(mark, MeasuredBlock.postRun); } catch (err) { - _print_error("MONO_WASM: user callback posRun() failed", err); + _print_error("user callback posRun() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -326,7 +329,7 @@ function mono_wasm_pre_init_essential(isWorker: boolean): void { if (!isWorker) Module.addRunDependency("mono_wasm_pre_init_essential"); - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_pre_init_essential"); + mono_log_debug("mono_wasm_pre_init_essential"); init_c_exports(); cwraps_internal(INTERNAL); @@ -344,7 +347,7 @@ function mono_wasm_pre_init_essential(isWorker: boolean): void { } async function mono_wasm_pre_init_essential_async(): Promise { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_pre_init_essential_async"); + mono_log_debug("mono_wasm_pre_init_essential_async"); Module.addRunDependency("mono_wasm_pre_init_essential_async"); await init_polyfills_async(); @@ -357,7 +360,7 @@ async function mono_wasm_pre_init_essential_async(): Promise { } async function mono_wasm_pre_init_full(): Promise { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_pre_init_full"); + mono_log_debug("mono_wasm_pre_init_full"); Module.addRunDependency("mono_wasm_pre_init_full"); await loaderHelpers.mono_download_assets(); @@ -366,7 +369,7 @@ async function mono_wasm_pre_init_full(): Promise { } async function mono_wasm_after_user_runtime_initialized(): Promise { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_after_user_runtime_initialized"); + mono_log_debug("mono_wasm_after_user_runtime_initialized"); try { if (!Module.disableDotnet6Compatibility && Module.exports) { // Export emscripten defined in module through EXPORTED_RUNTIME_METHODS @@ -381,24 +384,24 @@ async function mono_wasm_after_user_runtime_initialized(): Promise { globalThisAny[exportName] = exportValue; } else { - console.warn(`MONO_WASM: The exported symbol ${exportName} could not be found in the emscripten module`); + mono_log_warn(`The exported symbol ${exportName} could not be found in the emscripten module`); } } } - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: Initializing mono runtime"); + mono_log_debug("Initializing mono runtime"); if (Module.onDotnetReady) { try { await Module.onDotnetReady(); } catch (err: any) { - _print_error("MONO_WASM: onDotnetReady () failed", err); + _print_error("onDotnetReady () failed", err); throw err; } } } catch (err: any) { - _print_error("MONO_WASM: Error in mono_wasm_after_user_runtime_initialized", err); + _print_error("Error in mono_wasm_after_user_runtime_initialized", err); throw err; } } @@ -410,7 +413,7 @@ function _print_error(message: string, err: any): void { } Module.err(`${message}: ${JSON.stringify(err)}`); if (typeof err === "object" && err.stack) { - Module.err("MONO_WASM: Stacktrace: \n"); + Module.err("Stacktrace: \n"); Module.err(err.stack); } } @@ -461,7 +464,7 @@ async function instantiate_wasm_module( try { let memorySize: number | undefined = undefined; await loaderHelpers.afterConfigLoaded; - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: instantiate_wasm_module"); + mono_log_debug("instantiate_wasm_module"); if (runtimeHelpers.config.startupMemoryCache) { memorySize = await getMemorySnapshotSize(); @@ -483,7 +486,7 @@ async function instantiate_wasm_module( assetToLoad.pendingDownload = null as any; // GC assetToLoad.buffer = null as any; // GC - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: instantiate_wasm_module done"); + mono_log_debug("instantiate_wasm_module done"); if (runtimeHelpers.loadedMemorySnapshot) { try { @@ -493,7 +496,7 @@ async function instantiate_wasm_module( wasmMemory.grow((memorySize! - wasmMemory.buffer.byteLength + 65535) >>> 16); runtimeHelpers.updateMemoryViews(); } catch (err) { - console.warn("MONO_WASM: failed to resize memory for the snapshot", err); + mono_log_warn("failed to resize memory for the snapshot", err); runtimeHelpers.loadedMemorySnapshot = false; } // now we know if the loading of memory succeeded or not, we can start loading the rest of the assets @@ -501,7 +504,7 @@ async function instantiate_wasm_module( } runtimeHelpers.afterInstantiateWasm.promise_control.resolve(); } catch (err) { - _print_error("MONO_WASM: instantiate_wasm_module() failed", err); + _print_error("instantiate_wasm_module() failed", err); loaderHelpers.abort_startup(err, true); throw err; } @@ -513,9 +516,9 @@ async function mono_wasm_before_memory_snapshot() { if (runtimeHelpers.loadedMemorySnapshot) { // get the bytes after we re-sized the memory, so that we don't have too much memory in use at the same time const memoryBytes = await getMemorySnapshot(); - mono_assert(memoryBytes!.byteLength === Module.HEAP8.byteLength, "MONO_WASM: Loaded memory is not the expected size"); + mono_assert(memoryBytes!.byteLength === Module.HEAP8.byteLength, "Loaded memory is not the expected size"); Module.HEAP8.set(new Int8Array(memoryBytes!), 0); - if (runtimeHelpers.diagnosticTracing) console.info("MONO_WASM: Loaded WASM linear memory from browser cache"); + mono_log_debug("Loaded WASM linear memory from browser cache"); // all things below are loaded from the snapshot return; @@ -555,7 +558,7 @@ async function mono_wasm_before_memory_snapshot() { } export function mono_wasm_load_runtime(unused?: string, debugLevel?: number): void { - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: mono_wasm_load_runtime"); + mono_log_debug("mono_wasm_load_runtime"); try { const mark = startMeasure(); if (debugLevel == undefined) { @@ -568,7 +571,7 @@ export function mono_wasm_load_runtime(unused?: string, debugLevel?: number): vo endMeasure(mark, MeasuredBlock.loadRuntime); } catch (err: any) { - _print_error("MONO_WASM: mono_wasm_load_runtime () failed", err); + _print_error("mono_wasm_load_runtime () failed", err); loaderHelpers.abort_startup(err, false); } } @@ -577,7 +580,7 @@ export function bindings_init(): void { if (runtimeHelpers.mono_wasm_bindings_is_ready) { return; } - if (runtimeHelpers.diagnosticTracing) console.debug("MONO_WASM: bindings_init"); + mono_log_debug("bindings_init"); runtimeHelpers.mono_wasm_bindings_is_ready = true; try { const mark = startMeasure(); @@ -590,7 +593,7 @@ export function bindings_init(): void { runtimeHelpers._i52_error_scratch_buffer = Module._malloc(4); endMeasure(mark, MeasuredBlock.bindingsInit); } catch (err) { - _print_error("MONO_WASM: Error in bindings_init", err); + _print_error("Error in bindings_init", err); throw err; } } @@ -642,8 +645,7 @@ export function mono_wasm_set_main_args(name: string, allRuntimeArguments: strin export async function configureWorkerStartup(module: DotnetModuleInternal): Promise { // This is a good place for subsystems to attach listeners for pthreads_worker.currentWorkerThreadEvents pthreads_worker.currentWorkerThreadEvents.addEventListener(pthreads_worker.dotnetPthreadCreated, (ev) => { - if (runtimeHelpers.diagnosticTracing) - console.debug("MONO_WASM: pthread created 0x" + ev.pthread_self.pthread_id.toString(16)); + mono_log_debug("pthread created 0x" + ev.pthread_self.pthread_id.toString(16)); }); // these are the only events which are called on worker diff --git a/src/mono/wasm/runtime/web-socket.ts b/src/mono/wasm/runtime/web-socket.ts index b10307165d727..a0ec828e1c609 100644 --- a/src/mono/wasm/runtime/web-socket.ts +++ b/src/mono/wasm/runtime/web-socket.ts @@ -7,6 +7,7 @@ import { Module, createPromiseController } from "./globals"; import { setI32 } from "./memory"; import { VoidPtr } from "./types/emscripten"; import { PromiseController } from "./types/internal"; +import { mono_log_warn } from "./logging"; const wasm_ws_pending_send_buffer = Symbol.for("wasm ws_pending_send_buffer"); const wasm_ws_pending_send_buffer_offset = Symbol.for("wasm ws_pending_send_buffer_offset"); @@ -148,7 +149,7 @@ export function ws_wasm_close(ws: WebSocketExtension, code: number, reason: stri else { if (!mono_wasm_web_socket_close_warning) { mono_wasm_web_socket_close_warning = true; - console.warn("WARNING: Web browsers do not support closing the output side of a WebSocket. CloseOutputAsync has closed the socket and discarded any incoming messages."); + mono_log_warn("WARNING: Web browsers do not support closing the output side of a WebSocket. CloseOutputAsync has closed the socket and discarded any incoming messages."); } if (typeof reason === "string") { ws.close(code, reason);