Add debug message for init and update duration (grep duration in log file when debug mode is on)

4 files changed, 29 insertions, 4 deletions

diff --git a/glances/__init__.py b/glances/__init__.py
index 31f4b71b..5249db99 100644
--- a/glances/__init__.py
+++ b/glances/__init__.py
@@ -43,7 +43,7 @@ except ImportError:
 from glances.logger import logger
 from glances.main import GlancesMain
 from glances.globals import WINDOWS
-
+from glances.timer import Counter
 # Check locale
 try:
     locale.setlocale(locale.LC_ALL, '')
@@ -89,6 +89,8 @@ def start(config, args):
     # Load mode
     global mode
 
+    start_duration = Counter()
+
     if core.is_standalone():
         from glances.standalone import GlancesStandalone as GlancesMode
     elif core.is_client():
@@ -106,6 +108,7 @@ def start(config, args):
     mode = GlancesMode(config=config, args=args)
 
     # Start the main loop
+    logger.debug("Glances started in {} seconds".format(start_duration.get()))
     mode.serve_forever()
 
     # Shutdown
diff --git a/glances/plugins/glances_sensors.py b/glances/plugins/glances_sensors.py
index 3fb07cf8..fed3b4de 100644
--- a/glances/plugins/glances_sensors.py
+++ b/glances/plugins/glances_sensors.py
@@ -24,6 +24,7 @@ import warnings
 
 from glances.logger import logger
 from glances.compat import iteritems
+from glances.timer import Counter
 from glances.plugins.sensors.glances_batpercent import Plugin as BatPercentPlugin
 from glances.plugins.sensors.glances_hddtemp import Plugin as HddTempPlugin
 from glances.plugins.glances_plugin import GlancesPlugin
@@ -51,16 +52,24 @@ class Plugin(GlancesPlugin):
                                      config=config,
                                      stats_init_value=[])
 
+        start_duration = Counter()
+
         # Init the sensor class
+        start_duration.reset()
         self.glancesgrabsensors = GlancesGrabSensors()
+        logger.debug("Generic sensor plugin init duration: {} seconds".format(start_duration.get()))
 
         # Instance for the HDDTemp Plugin in order to display the hard disks
         # temperatures
+        start_duration.reset()
         self.hddtemp_plugin = HddTempPlugin(args=args, config=config)
+        logger.debug("HDDTemp sensor plugin init duration: {} seconds".format(start_duration.get()))
 
         # Instance for the BatPercent in order to display the batteries
         # capacities
+        start_duration.reset()
         self.batpercent_plugin = BatPercentPlugin(args=args, config=config)
+        logger.debug("Battery sensor plugin init duration: {} seconds".format(start_duration.get()))
 
         # We want to display the stat in the curse interface
         self.display_curse = True
diff --git a/glances/standalone.py b/glances/standalone.py
index 4772a2a1..d94af6fc 100644
--- a/glances/standalone.py
+++ b/glances/standalone.py
@@ -46,7 +46,10 @@ class GlancesStandalone(object):
         self.refresh_time = args.time
 
         # Init stats
+        start_duration = Counter()
+        start_duration.reset()
         self.stats = GlancesStats(config=config, args=args)
+        logger.debug("Plugins initialisation duration: {} seconds".format(start_duration.get()))
 
         # Modules (plugins and exporters) are loaded at this point
         # Glances can display the list if asked...
@@ -71,7 +74,9 @@ class GlancesStandalone(object):
             glances_processes.disable_kernel_threads()
 
         # Initial system informations update
+        start_duration.reset()
         self.stats.update()
+        logger.debug("First stats update duration: {} seconds".format(start_duration.get()))
 
         if self.quiet:
             logger.info("Quiet mode is ON, nothing will be displayed")
@@ -117,12 +122,12 @@ class GlancesStandalone(object):
 
         # Update stats
         self.stats.update()
-        logger.debug('Stats updated in {} seconds'.format(counter.get()))
+        logger.debug('Stats updated duration: {} seconds'.format(counter.get()))
 
         # Export stats
         counter_export = Counter()
         self.stats.export(self.stats)
-        logger.debug('Stats exported in {} seconds'.format(counter_export.get()))
+        logger.debug('Stats exported duration: {} seconds'.format(counter_export.get()))
 
         # Patch for issue1326 to avoid < 0 refresh
         adapted_refresh = self.refresh_time - counter.get()
diff --git a/glances/stats.py b/glances/stats.py
index 161cd50d..896eabad 100644
--- a/glances/stats.py
+++ b/glances/stats.py
@@ -25,8 +25,9 @@ import sys
 import threading
 import traceback
 
-from glances.globals import exports_path, plugins_path, sys_path
 from glances.logger import logger
+from glances.globals import exports_path, plugins_path, sys_path
+from glances.timer import Counter
 
 
 class GlancesStats(object):
@@ -136,13 +137,17 @@ class GlancesStats(object):
 
     def load_plugins(self, args=None):
         """Load all plugins in the 'plugins' folder."""
+        start_duration = Counter()
         for item in os.listdir(plugins_path):
             if (item.startswith(self.header) and
                     item.endswith(".py") and
                     item != (self.header + "plugin.py")):
                 # Load the plugin
+                start_duration.reset()
                 self._load_plugin(os.path.basename(item),
                                   args=args, config=self.config)
+                logger.debug("Plugin {} started in {} seconds".format(item,
+                                                                      start_duration.get()))
 
         # Log plugins list
         logger.debug("Active plugins list: {}".format(self.getPluginsList()))
@@ -224,12 +229,15 @@ class GlancesStats(object):
                 # If current plugin is disable
                 # then continue to next plugin
                 continue
+            start_duration = Counter()
             # Update the stats...
             self._plugins[p].update()
             # ... the history
             self._plugins[p].update_stats_history()
             # ... and the views
             self._plugins[p].update_views()
+            # logger.debug("Plugin {} update duration: {} seconds".format(p,
+            #                                                             start_duration.get()))
 
     def export(self, input_stats=None):
         """Export all the stats.