src/misc/stats.c

   1 /*****************************************************************************
   2  * stats.c: Statistics handling
   3  *****************************************************************************
   4  * Copyright (C) 2006 the VideoLAN team
   5  * $Id$
   6  *
   7  * Authors: Clément Stenac <zorglub@videolan.org>
   8  *
   9  * This program is free software; you can redistribute it and/or modify
  10  * it under the terms of the GNU General Public License as published by
  11  * the Free Software Foundation; either version 2 of the License, or
  12  * (at your option) any later version.
  13  *
  14  * This program is distributed in the hope that it will be useful,
  15  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  16  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  17  * GNU General Public License for more details.
  18  *
  19  * You should have received a copy of the GNU General Public License
  20  * along with this program; if not, write to the Free Software
  21  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston MA 02110-1301, USA.
  22  *****************************************************************************/
  23
  24 /*****************************************************************************
  25  * Preamble
  26  *****************************************************************************/
  27
  28 #ifdef HAVE_CONFIG_H
  29 # include "config.h"
  30 #endif
  31
  32 #include <vlc_common.h>
  33 #include <stdio.h>                                               /* required */
  34
  35 #include "input/input_internal.h"
  36
  37 /*****************************************************************************
  38  * Local prototypes
  39  *****************************************************************************/
  40 static int CounterUpdate( vlc_object_t *p_this,
  41                           counter_t *p_counter,
  42                           vlc_value_t val, vlc_value_t * );
  43 static void TimerDump( vlc_object_t *p_this, counter_t *p_counter, bool);
  44
  45 /*****************************************************************************
  46  * Exported functions
  47  *****************************************************************************/
  48
  49 #undef stats_CounterCreate
  50 /**
  51  * Create a statistics counter
  52  * \param p_this a VLC object
  53  * \param i_type the type of stored data. One of VLC_VAR_STRING,
  54  * VLC_VAR_INTEGER, VLC_VAR_FLOAT
  55  * \param i_compute_type the aggregation type. One of STATS_LAST (always
  56  * keep the last value), STATS_COUNTER (increment by the passed value),
  57  * STATS_MAX (keep the maximum passed value), STATS_MIN, or STATS_DERIVATIVE
  58  * (keep a time derivative of the value)
  59  */
  60 counter_t * stats_CounterCreate( vlc_object_t *p_this,
  61                                    int i_type, int i_compute_type )
  62 {
  63     counter_t *p_counter = (counter_t*) malloc( sizeof( counter_t ) ) ;
  64     (void)p_this;
  65
  66     if( !p_counter ) return NULL;
  67     p_counter->i_compute_type = i_compute_type;
  68     p_counter->i_type = i_type;
  69     p_counter->i_samples = 0;
  70     p_counter->pp_samples = NULL;
  71     p_counter->psz_name = NULL;
  72
  73     p_counter->update_interval = 0;
  74     p_counter->last_update = 0;
  75
  76     return p_counter;
  77 }
  78
  79 /** Update a counter element with new values
  80  * \param p_this a VLC object
  81  * \param p_counter the counter to update
  82  * \param val the vlc_value union containing the new value to aggregate. For
  83  * more information on how data is aggregated, \see stats_Create
  84  * \param val_new a pointer that will be filled with new data
  85  */
  86 int stats_Update( vlc_object_t *p_this, counter_t *p_counter,
  87                   vlc_value_t val, vlc_value_t *val_new )
  88 {
  89     if( !libvlc_stats (p_this) || !p_counter ) return VLC_EGENERIC;
  90     return CounterUpdate( p_this, p_counter, val, val_new );
  91 }
  92
  93 #undef stats_Get
  94 /** Get the aggregated value for a counter
  95  * \param p_this an object
  96  * \param p_counter the counter
  97  * \param val a pointer to an initialized vlc_value union. It will contain the
  98  * retrieved value
  99  * \return an error code
 100  */
 101 int stats_Get( vlc_object_t *p_this, counter_t *p_counter, vlc_value_t *val )
 102 {
 103     if( !libvlc_stats (p_this) || !p_counter || p_counter->i_samples == 0 )
 104     {
 105         val->i_int = val->f_float = 0.0;
 106         return VLC_EGENERIC;
 107     }
 108
 109     switch( p_counter->i_compute_type )
 110     {
 111     case STATS_LAST:
 112     case STATS_MIN:
 113     case STATS_MAX:
 114     case STATS_COUNTER:
 115         *val = p_counter->pp_samples[0]->value;
 116         break;
 117     case STATS_DERIVATIVE:
 118         /* Not ready yet */
 119         if( p_counter->i_samples < 2 )
 120         {
 121             val->i_int = 0; val->f_float = 0.0;
 122             return VLC_EGENERIC;
 123         }
 124         if( p_counter->i_type == VLC_VAR_INTEGER )
 125         {
 126             float f = ( p_counter->pp_samples[0]->value.i_int -
 127                         p_counter->pp_samples[1]->value.i_int ) /
 128                     (float)(  p_counter->pp_samples[0]->date -
 129                               p_counter->pp_samples[1]->date );
 130             val->i_int = (int)f;
 131         }
 132         else
 133         {
 134             float f = (float)( p_counter->pp_samples[0]->value.f_float -
 135                                p_counter->pp_samples[1]->value.f_float ) /
 136                       (float)( p_counter->pp_samples[0]->date -
 137                                p_counter->pp_samples[1]->date );
 138             val->f_float = f;
 139         }
 140         break;
 141     }
 142     return VLC_SUCCESS;;
 143 }
 144
 145 input_stats_t *stats_NewInputStats( input_thread_t *p_input )
 146 {
 147     (void)p_input;
 148     input_stats_t *p_stats = calloc( 1, sizeof(input_stats_t) );
 149     if( !p_stats )
 150         return NULL;
 151
 152     vlc_mutex_init( &p_stats->lock );
 153     stats_ReinitInputStats( p_stats );
 154
 155     return p_stats;
 156 }
 157
 158 void stats_ComputeInputStats( input_thread_t *p_input, input_stats_t *p_stats )
 159 {
 160     if( !libvlc_stats (p_input) ) return;
 161
 162     vlc_mutex_lock( &p_input->p->counters.counters_lock );
 163     vlc_mutex_lock( &p_stats->lock );
 164
 165     /* Input */
 166     stats_GetInteger( p_input, p_input->p->counters.p_read_packets,
 167                       &p_stats->i_read_packets );
 168     stats_GetInteger( p_input, p_input->p->counters.p_read_bytes,
 169                       &p_stats->i_read_bytes );
 170     stats_GetFloat( p_input, p_input->p->counters.p_input_bitrate,
 171                     &p_stats->f_input_bitrate );
 172     stats_GetInteger( p_input, p_input->p->counters.p_demux_read,
 173                       &p_stats->i_demux_read_bytes );
 174     stats_GetFloat( p_input, p_input->p->counters.p_demux_bitrate,
 175                     &p_stats->f_demux_bitrate );
 176     stats_GetInteger( p_input, p_input->p->counters.p_demux_corrupted,
 177                       &p_stats->i_demux_corrupted );
 178     stats_GetInteger( p_input, p_input->p->counters.p_demux_discontinuity,
 179                       &p_stats->i_demux_discontinuity );
 180
 181     /* Decoders */
 182     stats_GetInteger( p_input, p_input->p->counters.p_decoded_video,
 183                       &p_stats->i_decoded_video );
 184     stats_GetInteger( p_input, p_input->p->counters.p_decoded_audio,
 185                       &p_stats->i_decoded_audio );
 186
 187     /* Sout */
 188     if( p_input->p->counters.p_sout_send_bitrate )
 189     {
 190         stats_GetInteger( p_input, p_input->p->counters.p_sout_sent_packets,
 191                           &p_stats->i_sent_packets );
 192         stats_GetInteger( p_input, p_input->p->counters.p_sout_sent_bytes,
 193                           &p_stats->i_sent_bytes );
 194         stats_GetFloat  ( p_input, p_input->p->counters.p_sout_send_bitrate,
 195                           &p_stats->f_send_bitrate );
 196     }
 197
 198     /* Aout */
 199     stats_GetInteger( p_input, p_input->p->counters.p_played_abuffers,
 200                       &p_stats->i_played_abuffers );
 201     stats_GetInteger( p_input, p_input->p->counters.p_lost_abuffers,
 202                       &p_stats->i_lost_abuffers );
 203
 204     /* Vouts */
 205     stats_GetInteger( p_input, p_input->p->counters.p_displayed_pictures,
 206                       &p_stats->i_displayed_pictures );
 207     stats_GetInteger( p_input, p_input->p->counters.p_lost_pictures,
 208                       &p_stats->i_lost_pictures );
 209
 210     vlc_mutex_unlock( &p_stats->lock );
 211     vlc_mutex_unlock( &p_input->p->counters.counters_lock );
 212 }
 213
 214 void stats_ReinitInputStats( input_stats_t *p_stats )
 215 {
 216     vlc_mutex_lock( &p_stats->lock );
 217     p_stats->i_read_packets = p_stats->i_read_bytes =
 218     p_stats->f_input_bitrate = p_stats->f_average_input_bitrate =
 219     p_stats->i_demux_read_packets = p_stats->i_demux_read_bytes =
 220     p_stats->f_demux_bitrate = p_stats->f_average_demux_bitrate =
 221     p_stats->i_demux_corrupted = p_stats->i_demux_discontinuity =
 222     p_stats->i_displayed_pictures = p_stats->i_lost_pictures =
 223     p_stats->i_played_abuffers = p_stats->i_lost_abuffers =
 224     p_stats->i_decoded_video = p_stats->i_decoded_audio =
 225     p_stats->i_sent_bytes = p_stats->i_sent_packets = p_stats->f_send_bitrate
 226      = 0;
 227     vlc_mutex_unlock( &p_stats->lock );
 228 }
 229
 230 void stats_DumpInputStats( input_stats_t *p_stats  )
 231 {
 232     vlc_mutex_lock( &p_stats->lock );
 233     /* f_bitrate is in bytes / microsecond
 234      * *1000 => bytes / millisecond => kbytes / seconds */
 235     fprintf( stderr, "Input : %i (%i bytes) - %f kB/s - "
 236                      "Demux : %i (%i bytes) - %f kB/s\n"
 237                      " - Vout : %i/%i - Aout : %i/%i - Sout : %f\n",
 238                     p_stats->i_read_packets, p_stats->i_read_bytes,
 239                     p_stats->f_input_bitrate * 1000,
 240                     p_stats->i_demux_read_packets, p_stats->i_demux_read_bytes,
 241                     p_stats->f_demux_bitrate * 1000,
 242                     p_stats->i_displayed_pictures, p_stats->i_lost_pictures,
 243                     p_stats->i_played_abuffers, p_stats->i_lost_abuffers,
 244                     p_stats->f_send_bitrate );
 245     vlc_mutex_unlock( &p_stats->lock );
 246 }
 247
 248 #undef stats_TimerStart
 249 void stats_TimerStart( vlc_object_t *p_obj, const char *psz_name,
 250                        unsigned int i_id )
 251 {
 252     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 253     counter_t *p_counter = NULL;
 254
 255     if( !priv->b_stats ) return;
 256
 257     vlc_mutex_lock( &priv->timer_lock );
 258
 259     for( int i = 0 ; i < priv->i_timers; i++ )
 260     {
 261         if( priv->pp_timers[i]->i_id == i_id
 262             && priv->pp_timers[i]->p_obj == p_obj )
 263         {
 264             p_counter = priv->pp_timers[i];
 265             break;
 266         }
 267     }
 268     if( !p_counter )
 269     {
 270         counter_sample_t *p_sample;
 271         p_counter = stats_CounterCreate( VLC_OBJECT(p_obj->p_libvlc),
 272                                          VLC_VAR_TIME, STATS_TIMER );
 273         if( !p_counter )
 274             goto out;
 275         p_counter->psz_name = strdup( psz_name );
 276         p_counter->i_id = i_id;
 277         p_counter->p_obj = p_obj;
 278         INSERT_ELEM( priv->pp_timers, priv->i_timers,
 279                      priv->i_timers, p_counter );
 280
 281         /* 1st sample : if started: start_date, else last_time, b_started */
 282         p_sample = (counter_sample_t *)malloc( sizeof( counter_sample_t ) );
 283         INSERT_ELEM( p_counter->pp_samples, p_counter->i_samples,
 284                      p_counter->i_samples, p_sample );
 285         p_sample->date = 0; p_sample->value.b_bool = 0;
 286         /* 2nd sample : global_time, i_samples */
 287         p_sample = (counter_sample_t *)malloc( sizeof( counter_sample_t ) );
 288         INSERT_ELEM( p_counter->pp_samples, p_counter->i_samples,
 289                      p_counter->i_samples, p_sample );
 290         p_sample->date = 0; p_sample->value.i_int = 0;
 291     }
 292     if( p_counter->pp_samples[0]->value.b_bool == true )
 293     {
 294         msg_Warn( p_obj, "timer '%s' was already started !", psz_name );
 295         goto out;
 296     }
 297     p_counter->pp_samples[0]->value.b_bool = true;
 298     p_counter->pp_samples[0]->date = mdate();
 299 out:
 300     vlc_mutex_unlock( &priv->timer_lock );
 301 }
 302
 303 #undef stats_TimerStop
 304 void stats_TimerStop( vlc_object_t *p_obj, unsigned int i_id )
 305 {
 306     counter_t *p_counter = NULL;
 307     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 308
 309     if( !priv->b_stats ) return;
 310     vlc_mutex_lock( &priv->timer_lock );
 311     for( int i = 0 ; i < priv->i_timers; i++ )
 312     {
 313         if( priv->pp_timers[i]->i_id == i_id
 314             && priv->pp_timers[i]->p_obj == p_obj )
 315         {
 316             p_counter = priv->pp_timers[i];
 317             break;
 318         }
 319     }
 320     if( !p_counter || p_counter->i_samples != 2 )
 321     {
 322         msg_Err( p_obj, "timer does not exist" );
 323         goto out;
 324     }
 325     p_counter->pp_samples[0]->value.b_bool = false;
 326     p_counter->pp_samples[1]->value.i_int += 1;
 327     p_counter->pp_samples[0]->date = mdate() - p_counter->pp_samples[0]->date;
 328     p_counter->pp_samples[1]->date += p_counter->pp_samples[0]->date;
 329 out:
 330     vlc_mutex_unlock( &priv->timer_lock );
 331 }
 332
 333 #undef stats_TimerDump
 334 void stats_TimerDump( vlc_object_t *p_obj, unsigned int i_id )
 335 {
 336     counter_t *p_counter = NULL;
 337     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 338
 339     if( !priv->b_stats ) return;
 340     vlc_mutex_lock( &priv->timer_lock );
 341     for( int i = 0 ; i < priv->i_timers; i++ )
 342     {
 343         if( priv->pp_timers[i]->i_id == i_id
 344             && priv->pp_timers[i]->p_obj == p_obj )
 345         {
 346             p_counter = priv->pp_timers[i];
 347             break;
 348         }
 349     }
 350     TimerDump( p_obj, p_counter, true );
 351     vlc_mutex_unlock( &priv->timer_lock );
 352 }
 353
 354 #undef stats_TimersDumpAll
 355 void stats_TimersDumpAll( vlc_object_t *p_obj )
 356 {
 357     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 358
 359     if( !priv->b_stats ) return;
 360     vlc_mutex_lock( &priv->timer_lock );
 361     for ( int i = 0 ; i < priv->i_timers ; i++ )
 362         TimerDump( p_obj, priv->pp_timers[i], false );
 363     vlc_mutex_unlock( &priv->timer_lock );
 364 }
 365
 366 #undef stats_TimerClean
 367 void stats_TimerClean( vlc_object_t *p_obj, unsigned int i_id )
 368 {
 369     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 370
 371     vlc_mutex_lock( &priv->timer_lock );
 372     for ( int i = priv->i_timers -1 ; i >= 0; i-- )
 373     {
 374         counter_t *p_counter = priv->pp_timers[i];
 375         if( p_counter->i_id == i_id && p_counter->p_obj == p_obj )
 376         {
 377             REMOVE_ELEM( priv->pp_timers, priv->i_timers, i );
 378             stats_CounterClean( p_counter );
 379         }
 380     }
 381     vlc_mutex_unlock( &priv->timer_lock );
 382 }
 383
 384 #undef stats_TimersCleanAll
 385 void stats_TimersCleanAll( vlc_object_t *p_obj )
 386 {
 387     libvlc_priv_t *priv = libvlc_priv (p_obj->p_libvlc);
 388
 389     vlc_mutex_lock( &priv->timer_lock );
 390     for ( int i = priv->i_timers -1 ; i >= 0; i-- )
 391     {
 392         counter_t *p_counter = priv->pp_timers[i];
 393         REMOVE_ELEM( priv->pp_timers, priv->i_timers, i );
 394         stats_CounterClean( p_counter );
 395     }
 396     vlc_mutex_unlock( &priv->timer_lock );
 397 }
 398
 399 void stats_CounterClean( counter_t *p_c )
 400 {
 401     if( p_c )
 402     {
 403         int i = p_c->i_samples - 1 ;
 404         while( i >= 0 )
 405         {
 406             counter_sample_t *p_s = p_c->pp_samples[i];
 407             REMOVE_ELEM( p_c->pp_samples, p_c->i_samples, i );
 408             free( p_s );
 409             i--;
 410         }
 411         free( p_c->psz_name );
 412         free( p_c );
 413     }
 414 }
 415
 416
 417 /********************************************************************
 418  * Following functions are local
 419  ********************************************************************/
 420
 421 /**
 422  * Update a statistics counter, according to its type
 423  * If needed, perform a bit of computation (derivative, mostly)
 424  * This function must be entered with stats handler lock
 425  * \param p_counter the counter to update
 426  * \param val the "new" value
 427  * \return an error code
 428  */
 429 static int CounterUpdate( vlc_object_t *p_handler,
 430                           counter_t *p_counter,
 431                           vlc_value_t val, vlc_value_t *new_val )
 432 {
 433     switch( p_counter->i_compute_type )
 434     {
 435     case STATS_LAST:
 436     case STATS_MIN:
 437     case STATS_MAX:
 438         if( p_counter->i_samples > 1)
 439         {
 440             msg_Err( p_handler, "LAST counter has several samples !" );
 441             return VLC_EGENERIC;
 442         }
 443         if( p_counter->i_type != VLC_VAR_FLOAT &&
 444             p_counter->i_type != VLC_VAR_INTEGER &&
 445             p_counter->i_compute_type != STATS_LAST )
 446         {
 447             msg_Err( p_handler, "unable to compute MIN or MAX for this type");
 448             return VLC_EGENERIC;
 449         }
 450
 451         if( p_counter->i_samples == 0 )
 452         {
 453             counter_sample_t *p_new = (counter_sample_t*)malloc(
 454                                                sizeof( counter_sample_t ) );
 455             p_new->value.psz_string = NULL;
 456
 457             INSERT_ELEM( p_counter->pp_samples, p_counter->i_samples,
 458                          p_counter->i_samples, p_new );
 459         }
 460         if( p_counter->i_samples == 1 )
 461         {
 462             /* Update if : LAST or (MAX and bigger) or (MIN and bigger) */
 463             if( p_counter->i_compute_type == STATS_LAST ||
 464                 ( p_counter->i_compute_type == STATS_MAX &&
 465                    ( ( p_counter->i_type == VLC_VAR_INTEGER &&
 466                        p_counter->pp_samples[0]->value.i_int > val.i_int ) ||
 467                      ( p_counter->i_type == VLC_VAR_FLOAT &&
 468                        p_counter->pp_samples[0]->value.f_float > val.f_float )
 469                    ) ) ||
 470                 ( p_counter->i_compute_type == STATS_MIN &&
 471                    ( ( p_counter->i_type == VLC_VAR_INTEGER &&
 472                        p_counter->pp_samples[0]->value.i_int < val.i_int ) ||
 473                      ( p_counter->i_type == VLC_VAR_FLOAT &&
 474                        p_counter->pp_samples[0]->value.f_float < val.f_float )
 475                    ) ) )
 476             {
 477                 if( p_counter->i_type == VLC_VAR_STRING &&
 478                     p_counter->pp_samples[0]->value.psz_string )
 479                 {
 480                     free( p_counter->pp_samples[0]->value.psz_string );
 481                 }
 482                 p_counter->pp_samples[0]->value = val;
 483                 *new_val = p_counter->pp_samples[0]->value;
 484             }
 485         }
 486         break;
 487     case STATS_DERIVATIVE:
 488     {
 489         counter_sample_t *p_new, *p_old;
 490         mtime_t now = mdate();
 491         if( now - p_counter->last_update < p_counter->update_interval )
 492         {
 493             return VLC_EGENERIC;
 494         }
 495         p_counter->last_update = now;
 496         if( p_counter->i_type != VLC_VAR_FLOAT &&
 497             p_counter->i_type != VLC_VAR_INTEGER )
 498         {
 499             msg_Err( p_handler, "Unable to compute DERIVATIVE for this type");
 500             return VLC_EGENERIC;
 501         }
 502         /* Insert the new one at the beginning */
 503         p_new = (counter_sample_t*)malloc( sizeof( counter_sample_t ) );
 504         p_new->value = val;
 505         p_new->date = p_counter->last_update;
 506         INSERT_ELEM( p_counter->pp_samples, p_counter->i_samples,
 507                      0, p_new );
 508
 509         if( p_counter->i_samples == 3 )
 510         {
 511             p_old = p_counter->pp_samples[2];
 512             REMOVE_ELEM( p_counter->pp_samples, p_counter->i_samples, 2 );
 513             free( p_old );
 514         }
 515         break;
 516     }
 517     case STATS_COUNTER:
 518         if( p_counter->i_samples > 1)
 519         {
 520             msg_Err( p_handler, "LAST counter has several samples !" );
 521             return VLC_EGENERIC;
 522         }
 523         if( p_counter->i_samples == 0 )
 524         {
 525             counter_sample_t *p_new = (counter_sample_t*)malloc(
 526                                                sizeof( counter_sample_t ) );
 527             p_new->value.psz_string = NULL;
 528
 529             INSERT_ELEM( p_counter->pp_samples, p_counter->i_samples,
 530                          p_counter->i_samples, p_new );
 531         }
 532         if( p_counter->i_samples == 1 )
 533         {
 534             switch( p_counter->i_type )
 535             {
 536             case VLC_VAR_INTEGER:
 537                 p_counter->pp_samples[0]->value.i_int += val.i_int;
 538                 if( new_val )
 539                     new_val->i_int = p_counter->pp_samples[0]->value.i_int;
 540                 break;
 541             case VLC_VAR_FLOAT:
 542                 p_counter->pp_samples[0]->value.f_float += val.f_float;
 543                 if( new_val )
 544                     new_val->f_float = p_counter->pp_samples[0]->value.f_float;
 545             default:
 546                 msg_Err( p_handler, "Trying to increment invalid variable %s",
 547                          p_counter->psz_name );
 548                 return VLC_EGENERIC;
 549             }
 550         }
 551         break;
 552     }
 553     return VLC_SUCCESS;
 554 }
 555
 556 static void TimerDump( vlc_object_t *p_obj, counter_t *p_counter,
 557                        bool b_total )
 558 {
 559     if( !p_counter )
 560         return;
 561
 562     mtime_t last, total;
 563     int i_total;
 564     if( p_counter->i_samples != 2 )
 565     {
 566         msg_Err( p_obj, "timer %s does not exist", p_counter->psz_name );
 567         return;
 568     }
 569     i_total = p_counter->pp_samples[1]->value.i_int;
 570     total = p_counter->pp_samples[1]->date;
 571     if( p_counter->pp_samples[0]->value.b_bool == true )
 572     {
 573         last = mdate() - p_counter->pp_samples[0]->date;
 574         i_total += 1;
 575         total += last;
 576     }
 577     else
 578     {
 579         last = p_counter->pp_samples[0]->date;
 580     }
 581     if( b_total )
 582     {
 583         msg_Dbg( p_obj,
 584              "TIMER %s : %.3f ms - Total %.3f ms / %i intvls (Avg %.3f ms)",
 585              p_counter->psz_name, (float)last/1000, (float)total/1000, i_total,
 586              (float)(total)/(1000*(float)i_total ) );
 587     }
 588     else
 589     {
 590         msg_Dbg( p_obj,
 591              "TIMER %s : Total %.3f ms / %i intvls (Avg %.3f ms)",
 592              p_counter->psz_name, (float)total/1000, i_total,
 593              (float)(total)/(1000*(float)i_total ) );
 594     }
 595 }