Time report2

spynnaker/pyNN/models/populations/population.py

@@ -21,6 +21,8 @@
 from spinn_utilities.log import FormatAdapter
 from spinn_utilities.logger_utils import warn_once
 from spinn_utilities.overrides import overrides
+from spinn_front_end_common.interface.provenance import (
+    FecTimer, TimerCategory)
 from spinn_front_end_common.utilities.exceptions import ConfigurationException
 from spynnaker.pyNN.data import SpynnakerDataView
 from spynnaker.pyNN.exceptions import SpynnakerException
@@ -190,8 +192,10 @@ def record(self, variables, to_file=None, sampling_interval=None):
         :param int sampling_interval: a value in milliseconds, and an integer
             multiple of the simulation timestep.
         """
+        FecTimer.start_category(TimerCategory.POP_RECORD)
         self.__recorder.record(
             variables, to_file, sampling_interval, indexes=None)
+        FecTimer.end_category(TimerCategory.POP_RECORD)
 
     def sample(self, n, rng=None):
         """
@@ -241,6 +245,7 @@ def write_data(self, io, variables='all', gather=True, clear=False,
             record.
         """
         # pylint: disable=too-many-arguments
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         self._check_params(gather, annotations)
 
         if isinstance(io, str):
@@ -253,8 +258,11 @@ def write_data(self, io, variables='all', gather=True, clear=False,
 
         data = self.__recorder.extract_neo_block(
             variables, None, clear, annotations)
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
+        FecTimer.start_category(TimerCategory.POP_WRITE_DATA)
         # write the neo block to the file
         io.write(data)
+        FecTimer.end_category(TimerCategory.POP_WRITE_DATA)
 
     def describe(self, template='population_default.txt', engine='default'):
         """
@@ -335,9 +343,12 @@ def get_data(
             If the variable or variables have not been previously set to
             record.
         """
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         self._check_params(gather, annotations)
-        return self.__recorder.extract_neo_block(
+        neo_data = self.__recorder.extract_neo_block(
             variables, None, clear, annotations)
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
+        return neo_data
 
     def spinnaker_get_data(self, variable, as_matrix=False, view_indexes=None):
         """
@@ -352,12 +363,14 @@ def spinnaker_get_data(self, variable, as_matrix=False, view_indexes=None):
         :return: array of the data
         :rtype: ~numpy.ndarray
         """
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         warn_once(
             logger, "spinnaker_get_data is non-standard PyNN and therefore "
             "will not be portable to other simulators.")
         with NeoBufferDatabase() as db:
             return db.spinnaker_get_data(self.__recorder.recording_label,
                                          variable, as_matrix, view_indexes)
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
 
     @overrides(PopulationBase.get_spike_counts, extend_doc=False)
     def get_spike_counts(self, gather=True):
@@ -366,9 +379,11 @@ def get_spike_counts(self, gather=True):
 
         :rtype: ~numpy.ndarray
         """
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         self._check_params(gather)
         with NeoBufferDatabase() as db:
             return db.get_spike_counts(self.__recorder.recording_label)
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
 
     def find_units(self, variable):
         """

spynnaker/pyNN/models/populations/population_view.py

@@ -22,6 +22,8 @@
 from spinn_utilities.ranged.abstract_sized import AbstractSized
 from .population_base import PopulationBase
 from spinn_utilities.overrides import overrides
+from spinn_front_end_common.interface.provenance import (
+    FecTimer, TimerCategory)
 from spynnaker.pyNN.utilities.neo_buffer_database import NeoBufferDatabase
 from spynnaker.pyNN.utilities.utility_calls import get_neo_io
 
@@ -353,13 +355,15 @@ def get_data(
             If the variable or variables have not been previously set to
             record.
         """
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         if not gather:
             logger.warning("SpiNNaker only supports gather=True. We will run "
                            "as if gather was set to True.")
         if annotations is not None:
             warn_once(
                 logger, "Annotations parameter is not standard PyNN so may "
                 "not be supported by all platforms.")
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
 
         return self.__recorder.extract_neo_block(
             variables, self.__indexes, clear, annotations)
@@ -517,8 +521,10 @@ def record(self, variables,  to_file=None, sampling_interval=None):
             should be a value in milliseconds, and an integer multiple of the
             simulation timestep.
         """
+        FecTimer.start_category(TimerCategory.POP_RECORD)
         self.__recorder.record(
             variables, to_file, sampling_interval, self.__indexes)
+        FecTimer.end_category(TimerCategory.POP_RECORD)
 
     def sample(self, n, rng=None):
         """
@@ -596,6 +602,7 @@ def write_data(self, io, variables='all', gather=True, clear=False,
             If the variable or variables have not been previously set to
             record.
         """
+        FecTimer.start_category(TimerCategory.POP_WRITE_DATA)
         if not gather:
             logger.warning("SpiNNaker only supports gather=True. We will run "
                            "as if gather was set to True.")
@@ -608,11 +615,14 @@ def write_data(self, io, variables='all', gather=True, clear=False,
                 return
             io = get_neo_io(io)
 
+        FecTimer.start_category(TimerCategory.POP_GET_DATA)
         data = self.__recorder.extract_neo_block(
             variables, self.__indexes, clear, annotations)
+        FecTimer.end_category(TimerCategory.POP_GET_DATA)
 
         # write the neo block to the file
         io.write(data)
+        FecTimer.end_category(TimerCategory.POP_WRITE_DATA)
 
     @property
     @overrides(PopulationBase._vertex)

spynnaker_integration_tests/test_debug_mode/check_debug.py

@@ -30,6 +30,8 @@
 #    import EnergyReport
 from spinn_front_end_common.utilities.report_functions.board_chip_report \
     import AREA_CODE_REPORT_NAME
+from spinn_front_end_common.utilities.report_functions.timer_report import (
+    TIMER_FILENAME)
 from spinn_front_end_common.utility_models import \
      DataSpeedUpPacketGatherMachineVertex
 from spinnaker_testbase import BaseTestCase
@@ -142,3 +144,5 @@ def debug(self):
         self.assertIn("ds3.sqlite3", found)
 
         sim.end()
+        found = os.listdir(SpynnakerDataView.get_timestamp_dir_path())
+        self.assertIn(TIMER_FILENAME, found)

unittests/test_using_virtual_board/test_debug_mode/test_debug.py

@@ -18,6 +18,8 @@
     reports_names
 from spinn_front_end_common.utilities.report_functions.network_specification \
     import _FILENAME as network_specification_file_name
+from spinn_front_end_common.utilities.report_functions.timer_report import (
+    TIMER_FILENAME)
 from spinnaker_testbase import BaseTestCase
 from spynnaker.pyNN.data import SpynnakerDataView
 from spynnaker.pyNN.extra_algorithms.\
@@ -90,6 +92,8 @@ def debug(self):
         for report in reports:
             self.assertIn(report, found)
         self.assertIn("ds.sqlite3", found)
+        found = os.listdir(SpynnakerDataView.get_timestamp_dir_path())
+        self.assertIn(TIMER_FILENAME, found)
 
     def test_debug(self):
         self.runsafe(self.debug)