From f30feafde6dce6b4db29fb15f26d704f68773f95 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jukka=20Jyl=C3=A4nki?= Date: Wed, 10 Feb 2021 14:18:56 +0200 Subject: [PATCH 1/4] Simplify the use of emprofile and fix issue with empty generated profiles. --- emprofile | 29 +++++++++++++++ emprofile.bat | 11 ++++++ .../docs/optimizing/Profiling-Toolchain.rst | 16 ++++---- tools/emprofile.py | 37 +++++++++---------- tools/toolchain_profiler.py | 8 +++- .../toolchain_profiler.results_template.html | 10 +---- 6 files changed, 72 insertions(+), 39 deletions(-) create mode 100644 emprofile create mode 100644 emprofile.bat diff --git a/emprofile b/emprofile new file mode 100644 index 0000000000000..c85fb4dd4b900 --- /dev/null +++ b/emprofile @@ -0,0 +1,29 @@ +#!/bin/sh +# Copyright 2020 The Emscripten Authors. All rights reserved. +# Emscripten is available under two separate licenses, the MIT license and the +# University of Illinois/NCSA Open Source License. Both these licenses can be +# found in the LICENSE file. +# +# Entry point for running python scripts on UNIX systems. +# +# To modify this file, edit `tools/run_python.sh` and then run +# `tools/create_entry_points.py` + +if [ -z "$PYTHON" ]; then + PYTHON=$EMSDK_PYTHON +fi + +if [ -z "$PYTHON" ]; then + PYTHON=$(which python3 2> /dev/null) +fi + +if [ -z "$PYTHON" ]; then + PYTHON=$(which python 2> /dev/null) +fi + +if [ -z "$PYTHON" ]; then + echo 'unable to find python in $PATH' + exit 1 +fi + +exec "$PYTHON" "tools/$0.py" "$@" diff --git a/emprofile.bat b/emprofile.bat new file mode 100644 index 0000000000000..72043adae9b22 --- /dev/null +++ b/emprofile.bat @@ -0,0 +1,11 @@ +:: Entry point for running python scripts on windows systems. +:: To modify this file, edit `tools/run_python.bat` and then run +:: `tools/create_entry_points.py` + +@setlocal +@set EM_PY=%EMSDK_PYTHON% +@if "%EM_PY%"=="" ( + set EM_PY=python +) + +@"%EM_PY%" "%~dp0\tools\%~n0.py" %* diff --git a/site/source/docs/optimizing/Profiling-Toolchain.rst b/site/source/docs/optimizing/Profiling-Toolchain.rst index 3ec48b4793cc5..0acd80f72280f 100644 --- a/site/source/docs/optimizing/Profiling-Toolchain.rst +++ b/site/source/docs/optimizing/Profiling-Toolchain.rst @@ -14,10 +14,9 @@ To try out the toolchain profiler, run the following set of commands: .. code-block:: bash cd path/to/emscripten - tools/emprofile.py --reset export EM_PROFILE_TOOLCHAIN=1 emcc tests/hello_world.c -O3 -o a.html - tools/emprofile.py --graph + emprofile On Windows, replace the ``export`` keyword with ``set`` instead. The last command should generate a HTML file of form ``toolchain_profiler.results_yyyymmdd_hhmm.html`` that can be opened in the web browser to view the results. @@ -29,17 +28,16 @@ The toolchain profiler is active whenever the toolchain is invoked with the envi Profiling Tool Commands ----------------------- -The command ``tools/emprofile.py --reset`` deletes all previously stored profiling data. Call this command to erase the profiling session to a fresh empty state. To start profiling, call Emscripten tool commands with the environment variable ``EM_PROFILE_TOOLCHAIN=1`` set either system-wide as shown in the example, or on a per command basis, like this: +The command ``tools/emprofile.py --clear`` deletes all previously stored profiling data. Call this command to erase the profiling session to a fresh empty state. To start profiling, call Emscripten tool commands with the environment variable ``EM_PROFILE_TOOLCHAIN=1`` set either system-wide as shown in the example, or on a per command basis, like this: .. code-block:: bash - cd path/to/emscripten - tools/emprofile.py --reset - EM_PROFILE_TOOLCHAIN=1 emcc tests/hello_world.c -o a.bc - EM_PROFILE_TOOLCHAIN=1 emcc a.bc -O3 -o a.html - tools/emprofile.py --graph --outfile=myresults.html + emprofile --clear + EM_PROFILE_TOOLCHAIN=1 emcc -c foo.c a.o + EM_PROFILE_TOOLCHAIN=1 emcc a.o -O3 -o a.html + emprofile --outfile=myresults.html -Any number of commands can be profiled within one session, and when ``tools/emprofile.py --graph`` is finally called, it will pick up records from all Emscripten tool invocations up to that point. Calling ``--graph`` also clears the recorded profiling data. +Any number of commands can be profiled within one session, and when ``emprofile`` is finally called, it will pick up records from all Emscripten tool invocations up to that point, graph them, and clear the recorded profiling data for the next run. The output HTML filename can be chosen with the optional ``--outfile=myresults.html`` parameter. diff --git a/tools/emprofile.py b/tools/emprofile.py index cf0cb80c1cd52..cf8028af4980e 100755 --- a/tools/emprofile.py +++ b/tools/emprofile.py @@ -13,9 +13,6 @@ profiler_logs_path = os.path.join(tempfile.gettempdir(), 'emscripten_toolchain_profiler_logs') -# If set to 1, always generates the output file under the same filename and doesn't delete the temp data. -DEBUG_EMPROFILE_PY = 0 - OUTFILE = 'toolchain_profiler.results_' + time.strftime('%Y%m%d_%H%M') for arg in sys.argv: if arg.startswith('--outfile='): @@ -52,6 +49,8 @@ def create_profiling_graph(): for f in log_files: try: json_data = open(f, 'r').read() + if len(json_data.strip()) == 0: + continue lines = json_data.split('\n') lines = [x for x in lines if x != '[' and x != ']' and x != ',' and len(x.strip())] lines = [(x + ',') if not x.endswith(',') else x for x in lines] @@ -63,31 +62,30 @@ def create_profiling_graph(): print('Failed to parse JSON file "' + f + '"!', file=sys.stderr) sys.exit(1) if len(all_results) == 0: - print('No profiler logs were found in path "' + profiler_logs_path + '". Try setting the environment variable EM_PROFILE_TOOLCHAIN=1 and run some emcc commands, and then rerun "python emprofile.py --graph" again.') + print('No profiler logs were found in path "' + profiler_logs_path + '". Try setting the environment variable EM_PROFILE_TOOLCHAIN=1 and run some emcc commands, and then rerun "emprofile" again.') return all_results.sort(key=lambda x: x['time']) - json_file = OUTFILE + '.json' - open(json_file, 'w').write(json.dumps(all_results, indent=2)) - print('Wrote "' + json_file + '"') + emprofile_json_data = json.dumps(all_results, indent=2) html_file = OUTFILE + '.html' - html_contents = open(os.path.join(os.path.dirname(os.path.realpath(__file__)), 'toolchain_profiler.results_template.html'), 'r').read().replace('{{{results_log_file}}}', '"' + json_file + '"') + html_contents = open(os.path.join(os.path.dirname(os.path.realpath(__file__)), 'toolchain_profiler.results_template.html'), 'r').read().replace('{{{ emprofile_json_data }}}', emprofile_json_data) open(html_file, 'w').write(html_contents) print('Wrote "' + html_file + '"') - if not DEBUG_EMPROFILE_PY: - delete_profiler_logs() - -if len(sys.argv) < 2: +if '--help' in sys.argv: print('''Usage: - emprofile.py --reset + emprofile.py --clear Deletes all previously recorded profiling log files. + Use this to abort/drop any previously collected + profiling data for a new profiling run. - emprofile.py --graph - Draws a graph from all recorded profiling log files. + emprofile.py [--no-clear] + Draws a graph from all recorded profiling log files, + and deletes the recorded profiling files, unless + --no-clear is also passed. Optional parameters: @@ -97,10 +95,9 @@ def create_profiling_graph(): sys.exit(1) -if '--reset' in sys.argv: +if '--reset' in sys.argv or '--clear' in sys.argv: delete_profiler_logs() -elif '--graph' in sys.argv: - create_profiling_graph() else: - print('Unknown command "' + sys.argv[1] + '"!') - sys.exit(1) + create_profiling_graph() + if '--no-clear' not in sys.argv: + delete_profiler_logs() diff --git a/tools/toolchain_profiler.py b/tools/toolchain_profiler.py index 2e2514e0eed3e..7ca0560fd0c6b 100644 --- a/tools/toolchain_profiler.py +++ b/tools/toolchain_profiler.py @@ -105,9 +105,13 @@ def log_access(): # children generate are virtually treated as if they were performed by the parent PID. return open(os.path.join(ToolchainProfiler.profiler_logs_path, 'toolchain_profiler.pid_' + str(os.getpid()) + '.json'), 'a') + @staticmethod + def escape_string(arg): + return arg.replace('\\', '\\\\').replace('"', '\\"') + @staticmethod def escape_args(args): - return map(lambda arg: arg.replace('\\', '\\\\').replace('"', '\\"'), args) + return map(lambda arg: ToolchainProfiler.escape_string(arg), args) @staticmethod def record_process_start(write_log_entry=True): @@ -197,7 +201,7 @@ def __exit__(self, type, value, traceback): @staticmethod def profile_block(block_name): - return ToolchainProfiler.ProfileBlock(block_name) + return ToolchainProfiler.ProfileBlock(ToolchainProfiler.escape_string(block_name)) @staticmethod def imaginary_pid(): diff --git a/tools/toolchain_profiler.results_template.html b/tools/toolchain_profiler.results_template.html index 38bc58791f301..ba71b124388c6 100644 --- a/tools/toolchain_profiler.results_template.html +++ b/tools/toolchain_profiler.results_template.html @@ -602,14 +602,8 @@ } } -var xhr = new XMLHttpRequest(); -xhr.onreadystatechange = function() { - if (xhr.readyState == 4 && (xhr.status == 200 || xhr.status == 0)) { - createSwimlaneChart(JSON.parse(xhr.responseText)); - } -}; -xhr.open("GET", {{{results_log_file}}}, true); -xhr.send(); +var emProfileJsonData = {{{ emprofile_json_data }}}; +createSwimlaneChart(emProfileJsonData); From e2678acc1992d4f90300d230898592336bb6831c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jukka=20Jyl=C3=A4nki?= Date: Thu, 11 Feb 2021 13:17:17 +0200 Subject: [PATCH 2/4] Change EM_PROFILE_TOOLCHAIN environment variable to simpler "EMPROFILE", so that users only need to remember one word "EMPROFILE" to use the toolchain profiler. --- site/source/docs/optimizing/Profiling-Toolchain.rst | 10 +++++----- tests/test_other.py | 2 +- tools/emprofile.py | 2 +- tools/toolchain_profiler.py | 4 ++-- 4 files changed, 9 insertions(+), 9 deletions(-) diff --git a/site/source/docs/optimizing/Profiling-Toolchain.rst b/site/source/docs/optimizing/Profiling-Toolchain.rst index 0acd80f72280f..3058e137850ef 100644 --- a/site/source/docs/optimizing/Profiling-Toolchain.rst +++ b/site/source/docs/optimizing/Profiling-Toolchain.rst @@ -14,7 +14,7 @@ To try out the toolchain profiler, run the following set of commands: .. code-block:: bash cd path/to/emscripten - export EM_PROFILE_TOOLCHAIN=1 + export EMPROFILE=1 emcc tests/hello_world.c -O3 -o a.html emprofile @@ -23,18 +23,18 @@ On Windows, replace the ``export`` keyword with ``set`` instead. The last comman Details ======= -The toolchain profiler is active whenever the toolchain is invoked with the environment variable ``EM_PROFILE_TOOLCHAIN=1`` being set. In this mode, each called tool will accumulate profiling instrumentation data to a set of .json files under the Emscripten temp directory. +The toolchain profiler is active whenever the toolchain is invoked with the environment variable ``EMPROFILE=1`` being set. In this mode, each called tool will accumulate profiling instrumentation data to a set of .json files under the Emscripten temp directory. Profiling Tool Commands ----------------------- -The command ``tools/emprofile.py --clear`` deletes all previously stored profiling data. Call this command to erase the profiling session to a fresh empty state. To start profiling, call Emscripten tool commands with the environment variable ``EM_PROFILE_TOOLCHAIN=1`` set either system-wide as shown in the example, or on a per command basis, like this: +The command ``tools/emprofile.py --clear`` deletes all previously stored profiling data. Call this command to erase the profiling session to a fresh empty state. To start profiling, call Emscripten tool commands with the environment variable ``EMPROFILE=1`` set either system-wide as shown in the example, or on a per command basis, like this: .. code-block:: bash emprofile --clear - EM_PROFILE_TOOLCHAIN=1 emcc -c foo.c a.o - EM_PROFILE_TOOLCHAIN=1 emcc a.o -O3 -o a.html + EMPROFILE=1 emcc -c foo.c a.o + EMPROFILE=1 emcc a.o -O3 -o a.html emprofile --outfile=myresults.html Any number of commands can be profiled within one session, and when ``emprofile`` is finally called, it will pick up records from all Emscripten tool invocations up to that point, graph them, and clear the recorded profiling data for the next run. diff --git a/tests/test_other.py b/tests/test_other.py index 19340ee825a30..1ecfe025bf6fb 100644 --- a/tests/test_other.py +++ b/tests/test_other.py @@ -7420,7 +7420,7 @@ def test_closure_externs(self): def test_toolchain_profiler(self): environ = os.environ.copy() - environ['EM_PROFILE_TOOLCHAIN'] = '1' + environ['EMPROFILE'] = '1' # replaced subprocess functions should not cause errors self.run_process([EMCC, path_from_root('tests', 'hello_world.c')], env=environ) diff --git a/tools/emprofile.py b/tools/emprofile.py index cf8028af4980e..d33c42a956a1f 100755 --- a/tools/emprofile.py +++ b/tools/emprofile.py @@ -62,7 +62,7 @@ def create_profiling_graph(): print('Failed to parse JSON file "' + f + '"!', file=sys.stderr) sys.exit(1) if len(all_results) == 0: - print('No profiler logs were found in path "' + profiler_logs_path + '". Try setting the environment variable EM_PROFILE_TOOLCHAIN=1 and run some emcc commands, and then rerun "emprofile" again.') + print('No profiler logs were found in path "' + profiler_logs_path + '". Try setting the environment variable EMPROFILE=1 and run some emcc commands, and then rerun "emprofile" again.') return all_results.sort(key=lambda x: x['time']) diff --git a/tools/toolchain_profiler.py b/tools/toolchain_profiler.py index 7ca0560fd0c6b..2a33120fa80f6 100644 --- a/tools/toolchain_profiler.py +++ b/tools/toolchain_profiler.py @@ -13,9 +13,9 @@ from tools import response_file -EM_PROFILE_TOOLCHAIN = int(os.getenv('EM_PROFILE_TOOLCHAIN', '0')) +EMPROFILE = int(os.getenv('EMPROFILE', '0')) -if EM_PROFILE_TOOLCHAIN: +if EMPROFILE: original_sys_exit = sys.exit original_subprocess_call = subprocess.call original_subprocess_check_call = subprocess.check_call From 25d06e84c06493f3d793ac5b40bc817a5b9879f9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jukka=20Jyl=C3=A4nki?= Date: Sun, 14 Feb 2021 10:49:10 +0200 Subject: [PATCH 3/4] Add -c and -o flags and simplify generated profile filename --- tools/emprofile.py | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/tools/emprofile.py b/tools/emprofile.py index d33c42a956a1f..f714a1b02ca12 100755 --- a/tools/emprofile.py +++ b/tools/emprofile.py @@ -13,10 +13,15 @@ profiler_logs_path = os.path.join(tempfile.gettempdir(), 'emscripten_toolchain_profiler_logs') -OUTFILE = 'toolchain_profiler.results_' + time.strftime('%Y%m%d_%H%M') -for arg in sys.argv: - if arg.startswith('--outfile='): +OUTFILE = 'emprofile.' + time.strftime('%Y%m%d_%H%M') +for i in range(len(sys.argv)): + arg = sys.argv[i] + if arg.startswith('--outfile=') or arg.startswith('-o='): OUTFILE = arg.split('=', 1)[1].strip().replace('.html', '') + sys.argv[i] = '' + elif arg == '-o': + OUTFILE = sys.argv[i + 1].strip().replace('.html', '') + sys.argv[i] = sys.argv[i + 1] = '' # Deletes all previously captured log files to make room for a new clean run. @@ -77,7 +82,7 @@ def create_profiling_graph(): if '--help' in sys.argv: print('''Usage: - emprofile.py --clear + emprofile.py --clear (or -c) Deletes all previously recorded profiling log files. Use this to abort/drop any previously collected profiling data for a new profiling run. @@ -89,13 +94,13 @@ def create_profiling_graph(): Optional parameters: - --outfile=x.html + --outfile=x.html (or -o=x.html) Specifies the name of the results file to generate. ''') sys.exit(1) -if '--reset' in sys.argv or '--clear' in sys.argv: +if '--reset' in sys.argv or '--clear' in sys.argv or '-c' in sys.argv: delete_profiler_logs() else: create_profiling_graph() From 5ea463ec5c71286e33d7a2868e700a1296bed13e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jukka=20Jyl=C3=A4nki?= Date: Sun, 14 Feb 2021 13:04:35 +0200 Subject: [PATCH 4/4] Add mouse hover tooltips to emprofile results. --- .../toolchain_profiler.results_template.html | 78 ++++++++++++++++++- 1 file changed, 74 insertions(+), 4 deletions(-) diff --git a/tools/toolchain_profiler.results_template.html b/tools/toolchain_profiler.results_template.html index ba71b124388c6..d5295d7a22538 100644 --- a/tools/toolchain_profiler.results_template.html +++ b/tools/toolchain_profiler.results_template.html @@ -43,6 +43,16 @@ .future { stroke: gray; fill: #ddd; } .past { stroke: green; } .brush .extent { stroke: gray; fill: blue; fill-opacity: .165; } +div.tooltip { + position: absolute; + text-align: center; + padding: 2px; + font: 12px sans-serif; + background: lightsteelblue; + border: 0px; + border-radius: 8px; + pointer-events: none; +} @@ -97,11 +107,44 @@ // we want to return 'run' as the interesting command that was executed if (cmdname.indexOf('node') == 0 || cmdname.indexOf('python') == 0) { var positionalParams = findPositionalParams(cmdLine, []); - if (positionalParams.length > 0) cmdLineBasename(positionalParams); + if (positionalParams.length > 0) return cmdLineBasename(positionalParams); } return cmdname; } +function shortenRidiculouslyLongCmdLine(cmdLine) { + var cmdLine2 = []; + for(var l of cmdLine) { + if (l.length > 100) { + cmdLine2.push(l.substr(0, 50) + ' ... ' + l.substr(l.length - 50)); + } else { + cmdLine2.push(l); + } + } + return cmdLine2; +} + +function htmlFormatCmdLine(cmdLine) { + cmdLine = shortenRidiculouslyLongCmdLine(cmdLine); + var html = ''; + var prev = ''; + var lineLength = 0; + for(var l of cmdLine) { + if (prev.length > 3 && (prev[0] != '-' || lineLength >= 100)) { + html += '
'; + lineLength = 0; + } + else { + html += ' '; + ++lineLength; + } + html += l; + prev = l; + lineLength += l.length; + } + return html.trim(); +} + function findValueOfParam(cmdLine, key) { var i = cmdLine.indexOf(key); if (i != -1) return cmdLine[i+1]; @@ -451,6 +494,11 @@ .attr('height', mainHeight) .attr('class', 'main'); + // Define the div for the tooltip + var div = d3.select("body").append("div") + .attr("class", "tooltip") + .style("opacity", 0); + // draw the lanes for the main chart main.append('g').selectAll('.laneLines') .data(lanes) @@ -570,6 +618,23 @@ x1.domain([minExtent, maxExtent]); main.select('.main.axis').call(x1DateAxis); + function mouseoverTooltip(d) { + var text = d.cmdLine ? htmlFormatCmdLine(d.cmdLine) : d.cmd; + div.transition() + .duration(50) + .style("opacity", 1.0); + div.html(text) + mousemoveTooltip(d); + } + function mousemoveTooltip(d) { + div.style("left", (d3.event.pageX) + "px") + .style("top", (d3.event.pageY - 28) + "px"); + } + function mouseoutTooltip(d) { + div.transition() + .duration(500) + .style("opacity", 0); + } // upate the item rects var rects = itemRects.selectAll('rect') .data(visItems, function (d) { return d.id; }) @@ -582,8 +647,10 @@ .attr('width', function(d) { return x1(d.end) - x1(d.start); }) .attr('height', function(d) { return .8 * y1(1); }) .attr('class', function(d) { return 'mainItem ' + d.class; }) - .attr('fill', function(d) { return d.color; }); - + .attr('fill', function(d) { return d.color; }) + .on("mouseover", mouseoverTooltip) + .on("mousemove", mousemoveTooltip) + .on("mouseout", mouseoutTooltip); rects.exit().remove(); // update the item labels @@ -596,7 +663,10 @@ .attr('x', function(d) { return x1(Math.max(d.start, minExtent)) + 2; }) .attr('y', function(d) { return y1(d.lane) + .4 * y1(1) + 6.5; }) .attr('text-anchor', 'start') - .attr('class', 'itemLabel'); + .attr('class', 'itemLabel') + .on("mouseover", mouseoverTooltip) + .on("mousemove", mousemoveTooltip) + .on("mouseout", mouseoutTooltip); labels.exit().remove(); }