[wasm] Enable the log profiler (dotnet#107434)

* feat(wasm): Enable the log profiler

* chore: Disable for wasi

* chore: Add log profiler docs

* chore: Adjust flush logs syntax

* chore: Adjust defines, add conditionals, remove Module dependency

* chore: Adjust buffer_unlock exclusion

* chore: Adjust doc

* chore: Add log profiler sample

* chore: Add more sample logging

* chore: Remove unused makefile target

* chore: Remove icall, use jit interception to take heap sot

* chore: Remove unused logs

* chore: Remove unused dependency

* Revert "chore: Remove unused dependency"

This reverts commit 33221c4.

* remove ENABLE_BROWSER_PROFILER from default build

* Draft of WBT.

* Miss-commit, there's no profiler.js in the sample.

* Shift the responsibility of checking profile's size to the browser.

* Test linking of all 3 types of loggers + running one of them.

* link all 3 at the same time

* fix     [Fact]

* Treat a list of loggers as one argument.

Avoid "MSBUILD : error MSB1005: Specify a property and its value."

* fix?

---------

Co-authored-by: pavelsavara <[email protected]>
Co-authored-by: Ilona Tomkowicz <[email protected]>
Co-authored-by: Ilona Tomkowicz <[email protected]>
Co-authored-by: Pavel Savara <[email protected]>

src/installer/pkg/sfx/Microsoft.NETCore.App/Directory.Build.props

@@ -220,6 +220,7 @@
     <PlatformManifestFileEntry Include="libmono-ee-interp.a" IsNative="true" />
     <PlatformManifestFileEntry Include="libmono-icall-table.a" IsNative="true" />
     <PlatformManifestFileEntry Include="libmono-profiler-aot.a" IsNative="true" />
+    <PlatformManifestFileEntry Include="libmono-profiler-log.a" IsNative="true" />
     <PlatformManifestFileEntry Include="libmono-profiler-browser.a" IsNative="true" />
     <PlatformManifestFileEntry Include="libmono-wasm-eh-js.a" IsNative="true" />
     <PlatformManifestFileEntry Include="libmono-wasm-eh-wasm.a" IsNative="true" />

src/mono/browser/browser.proj

@@ -385,8 +385,8 @@
       <PInvokeTableFile>$(ArtifactsObjDir)wasm/pinvoke-table.h</PInvokeTableFile>
       <InterpToNativeTableFile>$(ArtifactsObjDir)wasm/wasm_m2n_invoke.g.h</InterpToNativeTableFile>
 
-      <CMakeConfigurationEmccFlags Condition="'$(Configuration)' == 'Debug'">-g -Os -DDEBUG=1 -DENABLE_AOT_PROFILER=1 -DENABLE_BROWSER_PROFILER=1</CMakeConfigurationEmccFlags>
-      <CMakeConfigurationEmccFlags Condition="'$(Configuration)' == 'Release'">-Oz -DENABLE_BROWSER_PROFILER=1</CMakeConfigurationEmccFlags>
+      <CMakeConfigurationEmccFlags Condition="'$(Configuration)' == 'Debug'">-g -Os -DDEBUG=1 -DENABLE_AOT_PROFILER=1 -DENABLE_BROWSER_PROFILER=1 -DENABLE_LOG_PROFILER=1</CMakeConfigurationEmccFlags>
+      <CMakeConfigurationEmccFlags Condition="'$(Configuration)' == 'Release'">-Oz</CMakeConfigurationEmccFlags>
 
       <CMakeConfigurationLinkFlags Condition="'$(Configuration)' == 'Debug'"  >$(CMakeConfigurationEmccFlags) -s ASSERTIONS=1 </CMakeConfigurationLinkFlags>
       <CMakeConfigurationLinkFlags Condition="'$(Configuration)' == 'Release'">-O2</CMakeConfigurationLinkFlags>

src/mono/browser/build/BrowserWasmApp.targets

@@ -314,6 +314,7 @@
       <_EmccCFlags Include="-DLINK_ICALLS=1"                   Condition="'$(WasmLinkIcalls)' == 'true'" />
       <_EmccCFlags Include="-DENABLE_AOT_PROFILER=1"           Condition="$(WasmProfilers.Contains('aot'))" />
       <_EmccCFlags Include="-DENABLE_BROWSER_PROFILER=1"       Condition="$(WasmProfilers.Contains('browser'))" />
+      <_EmccCFlags Include="-DENABLE_LOG_PROFILER=1"           Condition="$(WasmProfilers.Contains('log'))" />
       <_EmccCFlags Include="-DENABLE_JS_INTEROP_BY_VALUE=1"    Condition="'$(WasmEnableJsInteropByValue)' == 'true'" />
 
       <_EmccCFlags Include="-DGEN_PINVOKE=1" />
@@ -368,6 +369,7 @@
       <EmscriptenEnvVars Include="WASM_ENABLE_EH=0" Condition="'$(WasmEnableExceptionHandling)' == 'false'" />
       <EmscriptenEnvVars Include="ENABLE_AOT_PROFILER=$([System.Convert]::ToInt32($(WasmProfilers.Contains('aot'))))" />
       <EmscriptenEnvVars Include="ENABLE_BROWSER_PROFILER=$([System.Convert]::ToInt32($(WasmProfilers.Contains('browser'))))" />
+      <EmscriptenEnvVars Include="ENABLE_LOG_PROFILER=$([System.Convert]::ToInt32($(WasmProfilers.Contains('log'))))" />
       <EmscriptenEnvVars Include="RUN_AOT_COMPILATION=1" Condition="'$(RunAOTCompilation)' == 'true'" />
       <EmscriptenEnvVars Include="RUN_AOT_COMPILATION=0" Condition="'$(RunAOTCompilation)' != 'true'" />
 

src/mono/browser/runtime/cwraps.ts

@@ -65,9 +65,10 @@ const fn_signatures: SigLine[] = [
     [false, "mono_wasm_exit", "void", ["number"]],
     [true, "mono_wasm_getenv", "number", ["string"]],
     [true, "mono_wasm_set_main_args", "void", ["number", "number"]],
-    // These two need to be lazy because they may be missing
+    // These three need to be lazy because they may be missing
     [() => !runtimeHelpers.emscriptenBuildOptions.enableAotProfiler, "mono_wasm_profiler_init_aot", "void", ["string"]],
     [() => !runtimeHelpers.emscriptenBuildOptions.enableBrowserProfiler, "mono_wasm_profiler_init_browser", "void", ["string"]],
+    [() => !runtimeHelpers.emscriptenBuildOptions.enableLogProfiler, "mono_wasm_profiler_init_log", "void", ["string"]],
     [true, "mono_wasm_profiler_init_browser", "void", ["number"]],
     [false, "mono_wasm_exec_regression", "number", ["number", "string"]],
     [false, "mono_wasm_invoke_jsexport", "void", ["number", "number"]],
@@ -165,6 +166,7 @@ export interface t_ThreadingCwraps {
 export interface t_ProfilerCwraps {
     mono_wasm_profiler_init_aot(desc: string): void;
     mono_wasm_profiler_init_browser(desc: string): void;
+    mono_wasm_profiler_init_log(desc: string): void;
 }
 
 export interface t_Cwraps {

src/mono/browser/runtime/driver.c

@@ -430,6 +430,18 @@ mono_wasm_profiler_init_browser (const char *desc)
 
 #endif
 
+#ifdef ENABLE_LOG_PROFILER
+
+void mono_profiler_init_log (const char *desc);
+
+EMSCRIPTEN_KEEPALIVE void
+mono_wasm_profiler_init_log (const char *desc)
+{
+	mono_profiler_init_log (desc);
+}
+
+#endif
+
 EMSCRIPTEN_KEEPALIVE void
 mono_wasm_init_finalizer_thread (void)
 {

src/mono/browser/runtime/es6/dotnet.es6.lib.js

@@ -11,6 +11,7 @@ const WASM_ENABLE_SIMD = process.env.WASM_ENABLE_SIMD === "1";
 const WASM_ENABLE_EH = process.env.WASM_ENABLE_EH === "1";
 const ENABLE_BROWSER_PROFILER = process.env.ENABLE_BROWSER_PROFILER === "1";
 const ENABLE_AOT_PROFILER = process.env.ENABLE_AOT_PROFILER === "1";
+const ENABLE_LOG_PROFILER = process.env.ENABLE_LOG_PROFILER === "1";
 const RUN_AOT_COMPILATION = process.env.RUN_AOT_COMPILATION === "1";
 var methodIndexByName = undefined;
 var gitHash = undefined;
@@ -88,6 +89,7 @@ function injectDependencies() {
         `wasmEnableEH: ${WASM_ENABLE_EH ? "true" : "false"},` +
         `enableAotProfiler: ${ENABLE_AOT_PROFILER ? "true" : "false"}, ` +
         `enableBrowserProfiler: ${ENABLE_BROWSER_PROFILER ? "true" : "false"}, ` +
+        `enableLogProfiler: ${ENABLE_LOG_PROFILER ? "true" : "false"}, ` +
         `runAOTCompilation: ${RUN_AOT_COMPILATION ? "true" : "false"}, ` +
         `wasmEnableThreads: ${USE_PTHREADS ? "true" : "false"}, ` +
         `gitHash: "${gitHash}", ` +

src/mono/browser/runtime/profiler.ts

@@ -2,7 +2,7 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 import { ENVIRONMENT_IS_WEB, mono_assert, runtimeHelpers } from "./globals";
-import { MonoMethod, AOTProfilerOptions, BrowserProfilerOptions } from "./types/internal";
+import { MonoMethod, AOTProfilerOptions, BrowserProfilerOptions, LogProfilerOptions } from "./types/internal";
 import { profiler_c_functions as cwraps } from "./cwraps";
 import { utf8ToString } from "./strings";
 
@@ -34,6 +34,12 @@ export function mono_wasm_init_browser_profiler (options: BrowserProfilerOptions
     cwraps.mono_wasm_profiler_init_browser(arg);
 }
 
+export function mono_wasm_init_log_profiler (options: LogProfilerOptions): void {
+    mono_assert(runtimeHelpers.emscriptenBuildOptions.enableLogProfiler, "Log profiler is not enabled, please use <WasmProfilers>log;</WasmProfilers> in your project file.");
+    mono_assert(options.takeHeapshot, "Log profiler is not enabled, the takeHeapshot method must be defined in LogProfilerOptions.takeHeapshot");
+    cwraps.mono_wasm_profiler_init_log( (options.configuration || "log:alloc,output=output.mlpd") + `,take-heapshot-method=${options.takeHeapshot}`);
+}
+
 export const enum MeasuredBlock {
     emscriptenStartup = "mono.emscriptenStartup",
     instantiateWasm = "mono.instantiateWasm",

src/mono/browser/runtime/startup.ts

@@ -9,7 +9,7 @@ import { exportedRuntimeAPI, INTERNAL, loaderHelpers, Module, runtimeHelpers, cr
 import cwraps, { init_c_exports, threads_c_functions as tcwraps } from "./cwraps";
 import { mono_wasm_raise_debug_event, mono_wasm_runtime_ready } from "./debug";
 import { toBase64StringImpl } from "./base64";
-import { mono_wasm_init_aot_profiler, mono_wasm_init_browser_profiler } from "./profiler";
+import { mono_wasm_init_aot_profiler, mono_wasm_init_browser_profiler, mono_wasm_init_log_profiler } from "./profiler";
 import { initialize_marshalers_to_cs } from "./marshal-to-cs";
 import { initialize_marshalers_to_js } from "./marshal-to-js";
 import { init_polyfills_async } from "./polyfills";
@@ -544,6 +544,9 @@ export async function start_runtime () {
         if (runtimeHelpers.config.browserProfilerOptions)
             mono_wasm_init_browser_profiler(runtimeHelpers.config.browserProfilerOptions);
 
+        if (runtimeHelpers.config.logProfilerOptions)
+            mono_wasm_init_log_profiler(runtimeHelpers.config.logProfilerOptions);
+
         if (WasmEnableThreads) {
             // this is not mono-attached thread, so we can start it earlier
             await mono_wasm_init_diagnostics();

src/mono/browser/runtime/types/internal.ts

@@ -77,6 +77,7 @@ export type MonoConfigInternal = MonoConfig & {
     assets?: AssetEntryInternal[],
     runtimeOptions?: string[], // array of runtime options as strings
     aotProfilerOptions?: AOTProfilerOptions, // dictionary-style Object. If omitted, aot profiler will not be initialized.
+    logProfilerOptions?: LogProfilerOptions, // dictionary-style Object. If omitted, log profiler will not be initialized.
     browserProfilerOptions?: BrowserProfilerOptions, // dictionary-style Object. If omitted, browser profiler will not be initialized.
     waitForDebugger?: number,
     appendElementOnExit?: boolean
@@ -274,6 +275,11 @@ export type AOTProfilerOptions = {
 export type BrowserProfilerOptions = {
 }
 
+export type LogProfilerOptions = {
+    takeHeapshot?: string,
+    configuration?: string //  log profiler options string"
+}
+
 // how we extended emscripten Module
 export type DotnetModule = EmscriptenModule & DotnetModuleConfig;
 export type DotnetModuleInternal = EmscriptenModule & DotnetModuleConfig & EmscriptenModuleInternal;
@@ -290,6 +296,7 @@ export type EmscriptenBuildOptions = {
     wasmEnableEH: boolean,
     enableAotProfiler: boolean,
     enableBrowserProfiler: boolean,
+    enableLogProfiler: boolean,
     runAOTCompilation: boolean,
     wasmEnableThreads: boolean,
     gitHash: string,

src/mono/mono.proj

@@ -1185,6 +1185,9 @@ JS_ENGINES = [NODE_JS]
       <_MonoRuntimeArtifacts Condition="'$(TargetsBrowser)' == 'true' and '$(BuildMonoAOTCrossCompilerOnly)' != 'true'" Include="$(MonoObjDir)out\lib\libmono-profiler-aot.a">
         <Destination>$(RuntimeBinDir)libmono-profiler-aot.a</Destination>
       </_MonoRuntimeArtifacts>
+      <_MonoRuntimeArtifacts Condition="'$(TargetsBrowser)' == 'true' and '$(BuildMonoAOTCrossCompilerOnly)' != 'true'" Include="$(MonoObjDir)out\lib\libmono-profiler-log.a">
+        <Destination>$(RuntimeBinDir)libmono-profiler-log.a</Destination>
+      </_MonoRuntimeArtifacts>
       <_MonoRuntimeArtifacts Condition="'$(TargetsBrowser)' == 'true' and '$(BuildMonoAOTCrossCompilerOnly)' != 'true'" Include="$(MonoObjDir)out\lib\libmono-profiler-browser.a">
         <Destination>$(RuntimeBinDir)libmono-profiler-browser.a</Destination>
       </_MonoRuntimeArtifacts>

src/mono/mono/mini/mini-wasm.c

@@ -577,7 +577,6 @@ mono_init_native_crash_info (void)
 void
 mono_runtime_setup_stat_profiler (void)
 {
-	g_error ("mono_runtime_setup_stat_profiler");
 }
 
 gboolean

src/mono/mono/profiler/CMakeLists.txt

@@ -6,6 +6,7 @@ include_directories(
   ${PROJECT_BINARY_DIR}/../../mono/eglib
   ${CMAKE_CURRENT_SOURCE_DIR}/../..
   ${PROJECT_SOURCE_DIR}/../
+  ${PROJECT_SOURCE_DIR}/../../../native/public
   ${PROJECT_SOURCE_DIR}/../eglib
   ${PROJECT_SOURCE_DIR}/../sgen)
 
@@ -47,4 +48,18 @@ if(NOT DISABLE_LIBS)
     set_target_properties(mono-profiler-browser-static PROPERTIES OUTPUT_NAME mono-profiler-browser)
     install(TARGETS mono-profiler-browser-static LIBRARY)
   endif()
+
+  if(HOST_BROWSER)
+    add_library(mono-profiler-log-static STATIC helper.c log.c log-args.c)
+    set_target_properties(mono-profiler-log-static PROPERTIES OUTPUT_NAME mono-profiler-log)
+    install(TARGETS mono-profiler-log-static LIBRARY)
+
+    if(NOT DISABLE_LOG_PROFILER_GZ)
+      if (CLR_CMAKE_USE_SYSTEM_ZLIB)
+        target_link_libraries(mono-profiler-log-static PRIVATE ${Z_LIBS})
+      else()
+        target_link_libraries(mono-profiler-log-static PRIVATE zlib)
+      endif()
+    endif()
+  endif()
 endif()

src/mono/mono/profiler/helper.c

@@ -8,7 +8,9 @@
 
 #include <config.h>
 
+#if !defined (HOST_WASM)
 #include <mono/utils/mono-logger-internals.h>
+#endif
 
 #ifdef HAVE_UNISTD_H
 #include <unistd.h>
@@ -42,6 +44,7 @@ mono_profhelper_close_socket_fd (SOCKET fd)
 void
 mono_profhelper_setup_command_server (SOCKET *server_socket, int *command_port, const char* profiler_name)
 {
+#if !defined (HOST_WASM)
 	*server_socket = socket (PF_INET, SOCK_STREAM, 0);
 
 	if (*server_socket == INVALID_SOCKET) {
@@ -77,11 +80,13 @@ mono_profhelper_setup_command_server (SOCKET *server_socket, int *command_port,
 	}
 
 	*command_port = ntohs (server_address.sin_port);
+#endif
 }
 
 void
 mono_profhelper_add_to_fd_set (fd_set *set, SOCKET fd, int *max_fd)
 {
+#if !defined (HOST_WASM)
 	/*
 	 * This should only trigger for the basic FDs (server socket, pipes) at
 	 * startup if for some mysterious reason they're too large. In this case,
@@ -99,4 +104,5 @@ mono_profhelper_add_to_fd_set (fd_set *set, SOCKET fd, int *max_fd)
 
 	if (*max_fd < GUINT64_TO_INT(fd))
 		*max_fd = (int)fd;
+#endif
 }

src/mono/mono/profiler/log-args.c

@@ -1,4 +1,5 @@
 #include <config.h>
+#include <mono/metadata/debug-helpers.h>
 #include <mono/utils/mono-logger-internals.h>
 #include <mono/utils/mono-proclib.h>
 #include <mono/utils/w32subset.h>
@@ -98,6 +99,9 @@ parse_arg (const char *arg, ProfilerConfig *config)
 	} else if (match_option (arg, "heapshot-on-shutdown", NULL)) {
 		config->hs_on_shutdown = TRUE;
 		config->enable_mask |= PROFLOG_HEAPSHOT_ALIAS;
+	} else if (match_option (arg, "take-heapshot-method", &val)) {
+		printf ("take-heapshot-method: %s\n", val);
+		set_log_profiler_take_heapshot_method(val);
 	} else if (match_option (arg, "sample", &val)) {
 		set_sample_freq (config, val);
 		config->sampling_mode = MONO_PROFILER_SAMPLE_MODE_PROCESS;

src/mono/mono/profiler/log.c

@@ -189,6 +189,8 @@ typedef struct {
 	int small_id;
 } MonoProfilerThread;
 
+static MonoMethodDesc *log_profiler_take_heapshot_method;
+
 // Default value in `profiler_tls` for new threads.
 #define MONO_PROFILER_THREAD_ZERO ((MonoProfilerThread *) NULL)
 
@@ -617,6 +619,7 @@ buffer_lock_helper (void);
 static void
 buffer_lock (void)
 {
+#if !defined (HOST_WASM)
 	/*
 	 * If the thread holding the exclusive lock tries to modify the
 	 * reader count, just make it a no-op. This way, we also avoid
@@ -657,6 +660,8 @@ buffer_lock (void)
 	}
 
 	mono_memory_barrier ();
+
+#endif // HOST_WASM
 }
 
 static void
@@ -685,6 +690,7 @@ buffer_lock_helper (void)
 static void
 buffer_unlock (void)
 {
+#if !defined (HOST_WASM)
 	mono_memory_barrier ();
 
 	gint32 state = mono_atomic_load_i32 (&log_profiler.buffer_lock_state);
@@ -697,6 +703,7 @@ buffer_unlock (void)
 	g_assert (!(state >> 16) && "Why is the exclusive lock held?");
 
 	mono_atomic_dec_i32 (&log_profiler.buffer_lock_state);
+#endif // HOST_WASM
 }
 
 static void
@@ -3499,6 +3506,7 @@ runtime_initialized (MonoProfiler *profiler)
 
 	mono_os_sem_init (&log_profiler.attach_threads_sem, 0);
 
+#if !defined (HOST_WASM)
 	/*
 	 * We must start the helper thread before the writer thread. This is
 	 * because start_helper_thread () sets up the command port which is written
@@ -3507,6 +3515,9 @@ runtime_initialized (MonoProfiler *profiler)
 	start_helper_thread ();
 	start_writer_thread ();
 	start_dumper_thread ();
+#else
+	dump_header ();
+#endif
 
 	/*
 	 * Wait for all the internal threads to be started. If we don't do this, we
@@ -3588,7 +3599,7 @@ create_profiler (const char *args, const char *filename, GPtrArray *filters)
 		}
 	}
 	if (*nf == '|') {
-#if HAVE_API_SUPPORT_WIN32_PIPE_OPEN_CLOSE && !defined (HOST_WIN32)
+#if HAVE_API_SUPPORT_WIN32_PIPE_OPEN_CLOSE && !defined (HOST_WIN32) && !defined (HOST_WASM)
 		log_profiler.file = popen (nf + 1, "w");
 		log_profiler.pipe_output = 1;
 #else
@@ -3636,6 +3647,44 @@ create_profiler (const char *args, const char *filename, GPtrArray *filters)
 	log_profiler.startup_time = current_time ();
 }
 
+void
+set_log_profiler_take_heapshot_method (const char *val)
+{
+	log_profiler_take_heapshot_method = mono_method_desc_new (val, TRUE);
+
+	if (!log_profiler_take_heapshot_method) {
+		mono_profiler_printf_err ("Could not parse method description: %s", val);
+		exit (1);
+	}
+}
+
+static void
+proflog_trigger_heapshot (void);
+
+static void
+prof_jit_done (MonoProfiler *prof, MonoMethod *method, MonoJitInfo *jinfo)
+{
+	MonoImage *image = mono_class_get_image (mono_method_get_class (method));
+
+	if (!image->assembly || method->wrapper_type || !log_profiler_take_heapshot_method)
+		return;
+
+	if (log_profiler_take_heapshot_method && mono_method_desc_match (log_profiler_take_heapshot_method, method)) {
+		printf ("log-profiler | taking heapshot\n");
+		proflog_trigger_heapshot ();
+		return;
+	}
+	else {
+		printf ("log-profiler not called (%p)\n", log_profiler_take_heapshot_method);
+	}
+}
+
+static void
+prof_inline_method (MonoProfiler *prof, MonoMethod *method, MonoMethod *inlined_method)
+{
+	prof_jit_done (prof, inlined_method, NULL);
+}
+
 MONO_API void
 mono_profiler_init_log (const char *desc);
 
@@ -3758,6 +3807,9 @@ mono_profiler_init_log (const char *desc)
 	mono_profiler_enable_allocations ();
 	mono_profiler_enable_clauses ();
 	mono_profiler_enable_sampling (handle);
+	mono_profiler_set_jit_done_callback (handle, prof_jit_done);
+	mono_profiler_set_inline_method_callback (handle, prof_inline_method);
+
 
 	/*
 	 * If no sample option was given by the user, this just leaves the sampling
@@ -3770,3 +3822,12 @@ mono_profiler_init_log (const char *desc)
 done:
 	;
 }
+
+static void
+proflog_trigger_heapshot (void)
+{
+	trigger_heapshot ();	
+
+	while (handle_writer_queue_entry ());
+	while (handle_dumper_queue_entry ());
+}