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..3058e137850ef 100644 --- a/site/source/docs/optimizing/Profiling-Toolchain.rst +++ b/site/source/docs/optimizing/Profiling-Toolchain.rst @@ -14,32 +14,30 @@ 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 + export EMPROFILE=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. 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 --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 ``EMPROFILE=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 + 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 ``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/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 cf0cb80c1cd52..f714a1b02ca12 100755 --- a/tools/emprofile.py +++ b/tools/emprofile.py @@ -13,13 +13,15 @@ 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='): +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. @@ -52,6 +54,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,44 +67,42 @@ 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 EMPROFILE=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 (or -c) 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: - --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: +if '--reset' in sys.argv or '--clear' in sys.argv or '-c' 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..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 @@ -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..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,20 +663,17 @@ .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(); } } -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);