Simplify the use of emprofile and fix issue with empty generated profiles.

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" "$@"

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" %*

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.
 

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)
 

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()

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():

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;
+}
 </style>
 </head><body>
 
@@ -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 += '<br>';
+      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);
 
 </script>
 </body>