Merge pull request #1449 from jack-lascala/advisor-jupyter

Tutorial performance/02_advisor_roofline move to bash

examples/performance/resources/RoofsData.json

@@ -1 +1 @@
-{"roofs": {"memory": [[[0, 10.239147722745471], [0, 570.455405501]], [[0, 0.3359252998311069], [0, 570.455405501]], [[0, 1.3904822540864243], [0, 570.455405501]], [[0, 1.2685757209375519], [0, 570.455405501]], [[0, 4.133030552447605], [0, 570.455405501]], [[0, 2.8810328103103706], [0, 570.455405501]], [[0, 4.317105786722284], [0, 570.455405501]]], "compute": [[[0.3359252998311069, 32], [570.455405501, 570.455405501]], [[0.08382893721093002, 32], [142.355072373, 142.355072373]]]}, "overview": {"total_ai": 0.46157431392801956, "total_gflops": 41.14182651658285}}
+{"roofs": {"memory": [[[0, 9.838265740723973], [0, 556.376903422]], [[0, 0.31638359367571434], [0, 556.376903422]], [[0, 1.3484893862708176], [0, 556.376903422]], [[0, 1.2249793371231947], [0, 556.376903422]], [[0, 3.9163830500571932], [0, 556.376903422]], [[0, 2.84078599338709], [0, 556.376903422]], [[0, 4.195880853106829], [0, 556.376903422]]], "compute": [[[0.31638359367571434, 32], [556.376903422, 556.376903422]], [[0.08078938661892396, 32], [142.072312392, 142.072312392]]]}, "overview": {"total_ai": 0.4714873487327801, "total_gflops": 33.36163258720438}}

scripts/advisor/run_advisor.py

@@ -1,7 +1,9 @@
+import datetime
+import logging
 import os
-import sys
 from pathlib import Path
-from subprocess import check_call, check_output
+from subprocess import check_output, PIPE, Popen
+import sys
 from tempfile import gettempdir, mkdtemp
 from contextlib import contextmanager
 
@@ -59,8 +61,8 @@ def run_with_advisor(path, output, name, exec_args):
     os.environ['DEVITO_PROFILING'] = 'advisor'
 
     # Devito Logging is disabled unless the user asks explicitly to see it
-    logging = os.environ.get('DEVITO_LOGGING')
-    if logging is None:
+    devito_logging = os.environ.get('DEVITO_LOGGING')
+    if devito_logging is None:
         os.environ['DEVITO_LOGGING'] = 'WARNING'
 
     with progress('Set up multi-threading environment'):
@@ -119,17 +121,41 @@ def run_with_advisor(path, output, name, exec_args):
     # run to warmup the jit cache
 
     log('Starting Intel Advisor\'s `roofline` analysis for `%s`' % name)
+    dt = datetime.datetime.now()
+
+    # Set up a file logger that will track the output of the advisor profiling
+    advixe_logger = logging.getLogger('run_advisor_logger')
+    advixe_logger.setLevel(logging.INFO)
+
+    advixe_formatter = logging.Formatter('%(asctime)s: %(message)s')
+    logger_datetime = '%d.%d.%d.%d.%d.%d' % (dt.year, dt.month,
+                                             dt.day, dt.hour, dt.minute, dt.second)
+    advixe_handler = logging.FileHandler('%s/%s_%s.log' % (output, name, logger_datetime))
+    advixe_handler.setFormatter(advixe_formatter)
+    advixe_logger.addHandler(advixe_handler)
 
     with progress('Performing `cache warm-up` run'):
-        check(check_call(py_cmd) == 0, 'Failed!')
+        try:
+            p_warm_up = Popen(py_cmd, stdout=PIPE, stderr=PIPE)
+            log_process(p_warm_up, advixe_logger)
+        except OSError:
+            check(False, 'Failed!')
 
     with progress('Performing `survey` analysis'):
         cmd = numactl_cmd + ['--'] + advisor_cmd + advisor_survey + ['--'] + py_cmd
-        check(check_call(cmd) == 0, 'Failed!')
+        try:
+            p_survey = Popen(cmd, stdout=PIPE, stderr=PIPE)
+            log_process(p_survey, advixe_logger)
+        except OSError:
+            check(False, 'Failed!')
 
     with progress('Performing `tripcounts` analysis'):
         cmd = numactl_cmd + ['--'] + advisor_cmd + advisor_flops + ['--'] + py_cmd
-        check(check_call(cmd) == 0, 'Failed!')
+        try:
+            p_tripcounts = Popen(cmd, stdout=PIPE, stderr=PIPE)
+            log_process(p_tripcounts, advixe_logger)
+        except OSError:
+            check(False, 'Failed!')
 
     log('Storing `survey` and `tripcounts` data in `%s`' % str(output))
     log('To plot a roofline type: ')
@@ -158,5 +184,16 @@ def progress(msg):
     print('\033[1;37;32m%s\033[0m' % 'Done!')
 
 
+def log_process(process, logger):
+    output, errors = process.communicate()
+    for output_line in output.splitlines():
+        logger.info(output_line.decode('utf-8'))
+    for error_line in errors.splitlines():
+        logger.error(error_line.decode('utf-8'))
+
+    if process.returncode != 0:
+        check(False, 'Failed!')
+
+
 if __name__ == '__main__':
     run_with_advisor()