openfisca · sandcha · Aug 22, 2019 · Jul 24, 2019 · Jul 1, 2019 · Jul 1, 2019
diff --git a/.gitignore b/.gitignore
@@ -17,3 +17,4 @@ dist/
 .noseids
 .pytest_cache
 .mypy_cache
+performance.json
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -1,5 +1,46 @@
 # Changelog
 
+## 34.4.0 [#895](https://github.com/openfisca/openfisca-core/pull/895)
+
+#### New features
+
+- Introduce the time performance flame graph
+  - Generates a flame graph in a web page to view the time taken by every calculation in a simulation
+  - Introduces `--performance` option to `openfisca test` command to generate a YAML test graph
+
+#### Usage notes
+
+1. To generate the flame graph:
+  * For a Python simulation:
+
+    ```py
+    tax_benefit_system = CountryTaxBenefitSystem()
+    simulation = SimulationBuilder().build_default_simulation(tax_benefit_system)
+
+    simulation.trace = True  # set the full tracer
+    [... simulation.calculate(...) ...]
+    simulation.tracer.performance_log.generate_graph(".")  # generate graph in chosen directory
+    ```
+
+  * For a YAML test, execute the test with the `--performance` option. 
+
+      For example, to run the `irpp.yaml` test in `openfisca-france/` run:
+      ```sh
+      openfisca test tests/formulas/irpp.yaml --performance -c openfisca_france
+      ```
+      This generates an `index.html` file in the current directory.    
+
+2. From the current directory, run a Python web server (here on port `5000`):
+
+    `python -m http.server 5000`
+
+
+3. See the flame graph result in your browser at `http://localhost:5000`.  
+  This interprets the generated `index.html`.
+
+When your yaml file contains multiple tests, only the last one is displayed in the flame chart.
+You can use [openfisca test --name_filter option](https://openfisca.org/doc/openfisca-python-api/openfisca-run-test.html) to choose a specific test case.
+
 ### 34.3.3 [#902](https://github.com/openfisca/openfisca-core/pull/902)
 
 #### Technical change

diff --git a/openfisca_core/scripts/assets/__init__.py b/openfisca_core/scripts/assets/__init__.py
diff --git a/openfisca_core/scripts/assets/index.html b/openfisca_core/scripts/assets/index.html
@@ -0,0 +1,140 @@
+<!DOCTYPE html>
+<html lang="en">
+  <head>
+    <!-- source: https://github.com/spiermar/d3-flame-graph/blob/4603adf4a0ed788dc1d9d51e198bd5d21c48fd77/index.html -->
+    <!-- BSD 3 Clause - Copyright Mike Bostock -->
+    <meta charset="utf-8">
+    <meta http-equiv="X-UA-Compatible" content="IE=edge">
+    <meta name="viewport" content="width=device-width, initial-scale=1">
+
+    <link rel="stylesheet" href="https://maxcdn.bootstrapcdn.com/bootstrap/3.3.7/css/bootstrap.min.css">
+    <link rel="stylesheet" type="text/css" href="https://cdn.jsdelivr.net/gh/spiermar/d3-flame-graph@2.0.3/dist/d3-flamegraph.css">
+
+    <style>
+
+    /* Space out content a bit */
+    body {
+      padding-top: 20px;
+      padding-bottom: 20px;
+    }
+
+    /* Custom page header */
+    .header {
+      padding-bottom: 20px;
+      padding-right: 15px;
+      padding-left: 15px;
+      border-bottom: 1px solid #e5e5e5;
+    }
+
+    /* Make the masthead heading the same height as the navigation */
+    .header h3 {
+      margin-top: 0;
+      margin-bottom: 0;
+      line-height: 40px;
+    }
+
+    /* Customize container */
+    .container {
+      max-width: 990px;
+    }
+    </style>
+
+    <title>Performance log</title>
+
+    <!-- HTML5 shim and Respond.js for IE8 support of HTML5 elements and media queries -->
+    <!--[if lt IE 9]>
+      <script src="https://oss.maxcdn.com/html5shiv/3.7.2/html5shiv.min.js"></script>
+      <script src="https://oss.maxcdn.com/respond/1.4.2/respond.min.js"></script>
+    <![endif]-->
+  </head>
+  <body>
+    <div class="container">
+      <div class="header clearfix">
+        <nav>
+          <div class="pull-right">
+            <form class="form-inline" id="form">
+              <a class="btn" href="javascript: resetZoom();">Reset zoom</a>
+              <a class="btn" href="javascript: clear();">Clear</a>
+              <div class="form-group">
+                <input type="text" class="form-control" id="term">
+              </div>
+              <a class="btn btn-primary" href="javascript: search();">Search</a>
+            </form>
+          </div>
+        </nav>
+        <h3 class="text-muted">Performance log</h3>
+      </div>
+      <div id="chart">
+      </div>
+      <hr>
+      <div id="details">
+      </div>
+    </div>
+
+    <!-- D3.js -->
+    <script src="https://d3js.org/d3.v4.min.js" charset="utf-8"></script>
+
+    <!-- d3-tip -->
+    <script type="text/javascript" src=https://cdnjs.cloudflare.com/ajax/libs/d3-tip/0.9.1/d3-tip.min.js></script>
+
+    <!-- d3-flamegraph -->
+    <script type="text/javascript" src="https://cdn.jsdelivr.net/gh/spiermar/d3-flame-graph@2.0.3/dist/d3-flamegraph.min.js"></script>
+
+    <script type="text/javascript">
+    var flameGraph = d3.flamegraph()
+      .width(960)
+      .cellHeight(18)
+      .transitionDuration(750)
+      .minFrameSize(5)
+      .transitionEase(d3.easeCubic)
+      .sort(true)
+      .title("")
+      .onClick(onClick)
+      .differential(false)
+      .selfValue(false);
+
+    var details = document.getElementById("details");
+    flameGraph.setDetailsElement(details);
+
+    flameGraph.label(function(d) {
+      var timeInSec = d.data.value.toPrecision(3) + "s"
+      var label = d.data.name + ": " + timeInSec
+      if (d.parent) {
+        var percentageOfParent = (d.data.value / d.parent.value) * 100
+        label += " (" + percentageOfParent.toPrecision(3) +  "%)"
+      }
+      return label
+    });
+
+    d3.json("performance.json", function(error, data) {
+      if (error) return console.warn(error);
+      d3.select("#chart")
+          .datum(data)
+          .call(flameGraph);
+    });
+
+    document.getElementById("form").addEventListener("submit", function(event){
+      event.preventDefault();
+      search();
+    });
+
+    function search() {
+      var term = document.getElementById("term").value;
+      flameGraph.search(term);
+    }
+
+    function clear() {
+      document.getElementById('term').value = '';
+      flameGraph.clear();
+    }
+
+    function resetZoom() {
+      flameGraph.resetZoom();
+    }
+
+    function onClick(d) {
+      console.info("Clicked on " + d.data.name);
+    }
+    </script>
+  </body>
+</html>
diff --git a/openfisca_core/scripts/openfisca_command.py b/openfisca_core/scripts/openfisca_command.py
@@ -36,6 +36,7 @@ def build_test_parser(parser):
         parser = add_tax_benefit_system_arguments(parser)
         parser.add_argument('-n', '--name_filter', default = None, help = "partial name of tests to execute. Only tests with the given name_filter in their name, file name, or keywords will be run.")
         parser.add_argument('-p', '--pdb', action = 'store_true', default = False, help = "drop into debugger on failures or errors")
+        parser.add_argument('--performance', action = 'store_true', default = False, help = "output performance data in an 'index.html' file (to load with a web server)")
         parser.add_argument('-v', '--verbose', action = 'store_true', default = False, help = "increase output verbosity")
         parser.add_argument('-o', '--only-variables', nargs = '*', default = None, help = "variables to test. If specified, only test the given variables.")
         parser.add_argument('-i', '--ignore-variables', nargs = '*', default = None, help = "variables to ignore. If specified, do not test the given variables.")

diff --git a/openfisca_core/scripts/run_test.py b/openfisca_core/scripts/run_test.py
@@ -16,6 +16,7 @@ def main(parser):
 
     options = {
         'pdb': args.pdb,
+        'performance': args.performance,
         'verbose': args.verbose,
         'name_filter': args.name_filter,
         'only_variables': args.only_variables,

diff --git a/openfisca_core/simulations.py b/openfisca_core/simulations.py
@@ -1,6 +1,5 @@
 # -*- coding: utf-8 -*-
 
-
 import tempfile
 import logging
 
@@ -105,15 +104,15 @@ def calculate(self, variable_name, period):
         if period is not None and not isinstance(period, periods.Period):
             period = periods.period(period)
 
-        self.tracer.enter_calculation(variable_name, period)
+        self.tracer.record_calculation_start(variable_name, period)
 
         try:
             result = self._calculate(variable_name, period)
             self.tracer.record_calculation_result(result)
             return result
 
         finally:
-            self.tracer.exit_calculation()
+            self.tracer.record_calculation_end()
             self.purge_cache_of_invalid_values()
 
     def _calculate(self, variable_name, period: periods.Period):

diff --git a/openfisca_core/tools/test_runner.py b/openfisca_core/tools/test_runner.py
@@ -112,6 +112,7 @@ def should_ignore(self, test):
 
 
 class YamlItem(pytest.Item):
+
     def __init__(self, name, parent, baseline_tax_benefit_system, test, options):
         super(YamlItem, self).__init__(name, parent)
         self.baseline_tax_benefit_system = baseline_tax_benefit_system
@@ -120,7 +121,7 @@ def __init__(self, name, parent, baseline_tax_benefit_system, test, options):
         self.simulation = None
         self.tax_benefit_system = None
 
-    def parse_test(self):
+    def runtest(self):
         self.name = self.test.get('name', '')
         if not self.test.get('output'):
             raise ValueError("Missing key 'output' in test '{}' in file '{}'".format(self.name, self.fspath))
@@ -131,38 +132,45 @@ def parse_test(self):
 
         self.tax_benefit_system = _get_tax_benefit_system(self.baseline_tax_benefit_system, self.test.get('reforms', []), self.test.get('extensions', []))
 
+        builder = SimulationBuilder()
+        input = self.test.get('input', {})
+        period = self.test.get('period')
+        verbose = self.options.get('verbose')
+        performance = self.options.get('performance')
+
         try:
-            builder = SimulationBuilder()
-            input = self.test.get('input', {})
-            period = self.test.get('period')
-            verbose = self.options.get('verbose')
             builder.set_default_period(period)
             self.simulation = builder.build_from_dict(self.tax_benefit_system, input)
-            self.simulation.trace = verbose
         except (VariableNotFound, SituationParsingError):
             raise
         except Exception as e:
             error_message = os.linesep.join([str(e), '', f"Unexpected error raised while parsing '{self.fspath}'"])
             raise ValueError(error_message).with_traceback(sys.exc_info()[2]) from e  # Keep the stack trace from the root error
 
-    def runtest(self):
-        self.parse_test()
-        verbose = self.options.get('verbose')
         try:
+            self.simulation.trace = verbose or performance
             self.check_output()
         finally:
+            tracer = self.simulation.tracer
             if verbose:
-                print("Computation log:")  # noqa T001
-                self.simulation.tracer.print_computation_log()
+                self.print_computation_log(tracer)
+            if performance:
+                self.generate_performance_graph(tracer)
+
+    def print_computation_log(self, tracer):
+        print("Computation log:")  # noqa T001
+        tracer.print_computation_log()
+
+    def generate_performance_graph(self, tracer):
+        tracer.generate_performance_graph('.')
 
     def check_output(self):
-        tax_benefit_system = self.tax_benefit_system
         output = self.test.get('output')
 
         if output is None:
             return
         for key, expected_value in output.items():
-            if tax_benefit_system.variables.get(key):  # If key is a variable
+            if self.tax_benefit_system.get_variable(key):  # If key is a variable
                 self.check_variable(key, expected_value, self.test.get('period'))
             elif self.simulation.populations.get(key):  # If key is an entity singular
                 for variable_name, value in expected_value.items():
@@ -175,7 +183,7 @@ def check_output(self):
                             entity_index = population.get_index(instance_id)
                             self.check_variable(variable_name, value, self.test.get('period'), entity_index)
                 else:
-                    raise VariableNotFound(key, tax_benefit_system)
+                    raise VariableNotFound(key, self.tax_benefit_system)
 
     def check_variable(self, variable_name, expected_value, period, entity_index = None):
         if self.should_ignore_variable(variable_name):
@@ -184,7 +192,9 @@ def check_variable(self, variable_name, expected_value, period, entity_index = N
             for requested_period, expected_value_at_period in expected_value.items():
                 self.check_variable(variable_name, expected_value_at_period, requested_period, entity_index)
             return
+
         actual_value = self.simulation.calculate(variable_name, period)
+
         if entity_index is not None:
             actual_value = actual_value[entity_index]
         return assert_near(