Added debug::Measure: Tool to measure elapsed real and process times.

diff --git a/zypp/base/Makefile.am b/zypp/base/Makefile.am
index e77d42d..990475a 100644 (file)
--- a/zypp/base/Makefile.am
+++ b/zypp/base/Makefile.am
@@ -12,6 +12,8 @@ baseincludedir = $(pkgincludedir)/base
 
 baseinclude_HEADERS =  \
        Debug.h         \
+       Measure.h       \
+       \
        Deprecated.h    \
        DefaultFalseBool.h      \
        DefaultIntegral.h       \
@@ -51,6 +53,7 @@ noinst_LTLIBRARIES =  lib@PACKAGE@_base.la
 ## ##################################################
 
 lib@PACKAGE@_base_la_SOURCES = \
+       Measure.cc              \
        Fd.cc                   \
        Gettext.cc              \
        GzStream.cc             \
@@ -63,10 +66,11 @@ lib@PACKAGE@_base_la_SOURCES =      \
        \
        Exception.cc            \
        Sysconfig.cc            \
-       LogControl.cc \
-       ProfilingFormater.cc
-# NO entries below LogControl.cc
-# The static LogControlImpl singleton musr be initialized first!
+       ProfilingFormater.cc    \
+       \
+       LogControl.cc
+### NO entries below LogControl.cc !!!
+### The static LogControlImpl singleton must be initialized first!
 
 lib@PACKAGE@_base_la_LIBADD = -lboost_regex
 

diff --git a/zypp/base/Measure.cc b/zypp/base/Measure.cc
new file mode 100644 (file)
index 0000000..b203a73
--- /dev/null
+++ b/zypp/base/Measure.cc
@@ -0,0 +1,261 @@
+/*---------------------------------------------------------------------\
+|                          ____ _   __ __ ___                          |
+|                         |__  / \ / / . \ . \                         |
+|                           / / \ V /|  _/  _/                         |
+|                          / /__ | | | | | |                           |
+|                         /_____||_| |_| |_|                           |
+|                                                                      |
+\---------------------------------------------------------------------*/
+/** \file      zypp/base/Measure.cc
+ *
+*/
+extern "C"
+{
+#include <sys/times.h>
+#include <unistd.h>
+}
+#include <iostream>
+
+#include "zypp/base/Logger.h"
+#include "zypp/base/Measure.h"
+#include "zypp/base/String.h"
+
+using std::endl;
+
+#undef ZYPP_BASE_LOGGER_LOGGROUP
+#define ZYPP_BASE_LOGGER_LOGGROUP "Measure"
+
+///////////////////////////////////////////////////////////////////
+namespace zypp
+{ /////////////////////////////////////////////////////////////////
+  ///////////////////////////////////////////////////////////////////
+  namespace debug
+  { /////////////////////////////////////////////////////////////////
+
+    ///////////////////////////////////////////////////////////////////
+    namespace
+    { /////////////////////////////////////////////////////////////////
+
+      /** Times measured by \ref Measure. */
+      struct Tm
+      {
+        Tm()
+        : _real( 0 )
+        , _proc( tmsEmpty )
+        {}
+
+        void get()
+        {
+          _real = ::time(NULL);
+          ::times( &_proc );
+        }
+
+        Tm operator-( const Tm & rhs ) const
+        {
+          Tm ret( *this );
+          ret._real -= rhs._real;
+          ret._proc.tms_utime -= rhs._proc.tms_utime;
+          ret._proc.tms_stime -= rhs._proc.tms_stime;
+          ret._proc.tms_cutime -= rhs._proc.tms_cutime;
+          ret._proc.tms_cstime -= rhs._proc.tms_cstime;
+          return ret;
+        }
+
+        std::string asString() const
+        {
+          std::string ret( timeStr( _real ) );
+          ret += " (u ";
+          ret += timeStr( asSec( _proc.tms_utime ) );
+          ret += " s ";
+          ret += timeStr( asSec( _proc.tms_stime ) );
+          ret += " c ";
+          ret += timeStr( asSec( _proc.tms_cutime + _proc.tms_cstime ) );
+          ret += ")";
+          return ret;
+        }
+
+        std::string stringIf( clock_t ticks_r, const std::string & tag_r ) const
+        {
+          std::string ret;
+          if ( ticks_r )
+            {
+              ret += tag_r;
+              ret += timeStr( asSec( ticks_r ) );
+            }
+          return ret;
+        }
+
+        double asSec( clock_t ticks_r ) const
+        { return double(ticks_r) / ticks; }
+
+        std::string timeStr( time_t sec_r ) const
+        {
+          time_t h = sec_r/3600;
+          sec_r -= h*3600;
+          time_t m = sec_r/60;
+          sec_r -= m*60;
+          if ( h )
+            return str::form( "%lu:%02lu:%02lu", h, m, sec_r );
+          if ( m )
+            return str::form( "%lu:%02lu", m, sec_r );
+          return str::form( "%lu", sec_r );
+        }
+
+        std::string timeStr( double sec_r ) const
+        {
+          time_t h = time_t(sec_r)/3600;
+          sec_r -= h*3600;
+          time_t m = time_t(sec_r)/60;
+          sec_r -= m*60;
+          if ( h )
+            return str::form( "%lu:%02lu:%05.2lf", h, m, sec_r );
+          if ( m )
+            return str::form( "%lu:%05.2lf", m, sec_r );
+          return str::form( "%.2lf", sec_r );
+        }
+
+        /** Systems ticks per second. */
+        static const long ticks;
+        /** Empty struct tms. */
+        static const struct tms tmsEmpty;
+        /** Real time via \c ::time. */
+        time_t      _real;
+        /** Process times via \c ::times. */
+        struct tms  _proc;
+      };
+
+      const struct tms Tm::tmsEmpty = { 0, 0, 0, 0 };
+      const long Tm::ticks = sysconf(_SC_CLK_TCK);
+
+      /** \refers Tm Stream output. */
+      std::ostream & operator<<( std::ostream & str, const Tm & obj )
+      {
+        return str << obj.asString();
+      }
+
+      /////////////////////////////////////////////////////////////////
+    } // namespace
+    ///////////////////////////////////////////////////////////////////
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // CLASS NAME : Measure::Impl
+    //
+    /** Measure implementation. */
+    class Measure::Impl
+    {
+    public:
+      Impl( const std::string & ident_r )
+      : _ident  ( ident_r )
+      , _seq    ( 0 )
+      {
+        INT << "START MEASURE(" << _ident << ")" << endl;
+        _start.get();
+      }
+
+      ~Impl()
+      {
+        _stop.get();
+        ++_seq;
+        std::ostream & str( INT << "MEASURE(" << _ident << ") " );
+        dumpMeasure( str );
+      }
+
+      void elapsed() const
+      {
+        _stop.get();
+        ++_seq;
+        std::ostream & str( INT << "ELAPSED(" << _ident << ") " );
+        dumpMeasure( str );
+        _elapsed = _stop;
+      }
+
+    private:
+      std::ostream & dumpMeasure( std::ostream & str_r ) const
+      {
+        str_r << ( _stop - _start );
+        if ( _seq > 1 ) // diff to previous _elapsed
+          {
+            str_r << " [" << ( _stop - _elapsed ) << "]";
+          }
+        return str_r << endl;
+      }
+
+    private:
+      std::string       _ident;
+      Tm               _start;
+      mutable unsigned _seq;
+      mutable Tm       _elapsed;
+      mutable Tm       _stop;
+    };
+    ///////////////////////////////////////////////////////////////////
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // CLASS NAME : Measure
+    //
+    ///////////////////////////////////////////////////////////////////
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::Measure
+    // METHOD TYPE : Ctor
+    //
+    Measure::Measure()
+    {}
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::Measure
+    // METHOD TYPE : Ctor
+    //
+    Measure::Measure( const std::string & ident_r )
+    : _pimpl( new Impl( ident_r ) )
+    {}
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::~Measure
+    // METHOD TYPE : Dtor
+    //
+    Measure::~Measure()
+    {}
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::start
+    // METHOD TYPE : void
+    //
+    void Measure::start( const std::string & ident_r )
+    {
+      stop();
+      _pimpl.reset( new Impl( ident_r ) );
+    }
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::
+    // METHOD TYPE : void
+    //
+    void Measure::elapsed() const
+    {
+      if ( _pimpl )
+        _pimpl->elapsed();
+    }
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // METHOD NAME : Measure::
+    // METHOD TYPE : void
+    //
+    void Measure::stop()
+    {
+      _pimpl.reset();
+    }
+
+    /////////////////////////////////////////////////////////////////
+  } // namespace debug
+  ///////////////////////////////////////////////////////////////////
+  /////////////////////////////////////////////////////////////////
+} // namespace zypp
+///////////////////////////////////////////////////////////////////

diff --git a/zypp/base/Measure.h b/zypp/base/Measure.h
new file mode 100644 (file)
index 0000000..ead9731
--- /dev/null
+++ b/zypp/base/Measure.h
@@ -0,0 +1,108 @@
+/*---------------------------------------------------------------------\
+|                          ____ _   __ __ ___                          |
+|                         |__  / \ / / . \ . \                         |
+|                           / / \ V /|  _/  _/                         |
+|                          / /__ | | | | | |                           |
+|                         /_____||_| |_| |_|                           |
+|                                                                      |
+\---------------------------------------------------------------------*/
+/** \file      zypp/base/Measure.h
+ *
+*/
+#ifndef ZYPP_BASE_MEASURE_H
+#define ZYPP_BASE_MEASURE_H
+
+#include <iosfwd>
+#include <string>
+
+#include "zypp/base/PtrTypes.h"
+
+///////////////////////////////////////////////////////////////////
+namespace zypp
+{ /////////////////////////////////////////////////////////////////
+  ///////////////////////////////////////////////////////////////////
+  namespace debug
+  { /////////////////////////////////////////////////////////////////
+
+    ///////////////////////////////////////////////////////////////////
+    //
+    // CLASS NAME : Measure
+    //
+    /** Tool to measure elapsed real and process times.
+     *
+     * Timer is started by either passing a string to the ctor,
+     * or callign \ref start. The string passed is printed on
+     * all messages to help identifying the timer.
+     *
+     * Elapsed time is printed on calling \ref elapsed (timer
+     * keeps running) or \ref stop.
+     *
+     * Calling \ref stop, stops the timer. The same, if the timer
+     * goes out of scope.
+     *
+     * Elapsed time is printed as:
+     * \code
+     * 'REAL TIME' (u 'USER TIME' s 'SYSTEM TIME' c 'TIME OF CHILDREN')
+     * \endcode
+     * In brackets the time elapsed since a previous call to \ref elapsed.
+     * All units are seconds.
+     *
+     * \code
+     * Measure m( "Parse" );
+     * ...
+     * m.elapsed();
+     * ...
+     * m.elapsed();
+     * ...
+     * m.elapsed();
+     * ...
+     * m.stop();
+     *
+     * // START MEASURE(Parse)
+     * // ELAPSED(Parse)  0 (u 0.13 s 0.00 c 0.00)
+     * // ELAPSED(Parse)  0 (u 0.15 s 0.02 c 0.00) [ 0 (u 0.02 s 0.02 c 0.00)]
+     * // ELAPSED(Parse)  0 (u 0.17 s 0.02 c 0.00) [ 0 (u 0.02 s 0.00 c 0.00)]
+     * // MEASURE(Parse)  0 (u 0.17 s 0.02 c 0.00) [ 0 (u 0.00 s 0.00 c 0.00)]
+     * \endcode
+    */
+    class Measure
+    {
+    public:
+      /** Default Ctor does nothing. */
+      Measure();
+
+      /** Ctor taking \a ident_r string and auto starts timer. */
+      explicit
+      Measure( const std::string & ident_r );
+
+      /** Dtor. */
+      ~Measure();
+
+      /** Start timer for \a ident_r string.
+       * Implies stoping a running timer.
+      */
+      void start( const std::string & ident_r = std::string() );
+
+      /** Print elapsed time for a running timer.
+       * Timer keeps on running.
+      */
+      void elapsed() const;
+
+      /** Stop a running timer. */
+      void stop();
+
+    private:
+      /** Implementation. */
+      class Impl;
+      /** Pointer to implementation. */
+      RW_pointer<Impl> _pimpl;
+    };
+    ///////////////////////////////////////////////////////////////////
+
+    /////////////////////////////////////////////////////////////////
+  } // namespace debug
+  ///////////////////////////////////////////////////////////////////
+  /////////////////////////////////////////////////////////////////
+} // namespace zypp
+///////////////////////////////////////////////////////////////////
+#endif // ZYPP_BASE_MEASURE_H