ACE/ace/Timeprobe_T.cpp

   1 #ifndef ACE_TIMEPROBE_T_CPP
   2 #define ACE_TIMEPROBE_T_CPP
   3
   4 #include "ace/config-all.h"
   5
   6 #if !defined (ACE_LACKS_PRAGMA_ONCE)
   7 # pragma once
   8 #endif /* ACE_LACKS_PRAGMA_ONCE */
   9
  10 #if defined (ACE_COMPILE_TIMEPROBES)
  11
  12 #include "ace/Timeprobe.h"
  13 #include "ace/High_Res_Timer.h"
  14 #include "ace/OS_NS_string.h"
  15
  16 ACE_BEGIN_VERSIONED_NAMESPACE_DECL
  17
  18 template <class ACE_LOCK, class ALLOCATOR>
  19 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::ACE_Timeprobe_Ex (u_long size)
  20   : timeprobes_ (0),
  21     lock_ (),
  22     max_size_ (size),
  23     current_size_ (0),
  24     report_buffer_full_ (0),
  25     allocator_ (0)
  26 {
  27   ACE_timeprobe_t *temp;
  28   //FUZZ: disable check_for_lack_ACE_OS
  29   ACE_NEW_MALLOC_ARRAY (temp,
  30                         (ACE_timeprobe_t *) this->allocator ()->
  31                         malloc (this->max_size_*sizeof(ACE_timeprobe_t)),
  32                         ACE_timeprobe_t,
  33                         this->max_size_);
  34   //FUZZ: enable check_for_lack_ACE_OS
  35   this->timeprobes_ = temp;
  36 }
  37
  38 template <class ACE_LOCK, class ALLOCATOR>
  39 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::
  40 ACE_Timeprobe_Ex (ALLOCATOR *allocator,
  41                u_long size)
  42   : timeprobes_ (0),
  43     lock_ (),
  44     max_size_ (size),
  45     current_size_ (0),
  46     report_buffer_full_ (0),
  47     allocator_ (allocator)
  48 {
  49   ACE_timeprobe_t *temp = 0;
  50   //FUZZ: disable check_for_lack_ACE_OS
  51   ACE_NEW_MALLOC_ARRAY (temp,
  52                         (ACE_timeprobe_t *) this->allocator ()->
  53                         malloc (this->max_size_*sizeof(ACE_timeprobe_t)),
  54                         ACE_timeprobe_t,
  55                         this->max_size_);
  56   //FUZZ: enable check_for_lack_ACE_OS
  57   this->timeprobes_ = temp;
  58 }
  59
  60 template <class ACE_LOCK, class ALLOCATOR>
  61 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::ACE_Timeprobe_Ex (const ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR> &)
  62 {
  63   //
  64   // Stupid MSVC is forcing me to define this; please don't use it.
  65   //
  66
  67   ACELIB_ERROR ((LM_ERROR,
  68               ACE_TEXT ("ACE_NOTSUP: %N, line %l\n")));
  69   errno = ENOTSUP;
  70 }
  71
  72 template <class ACE_LOCK, class ALLOCATOR>
  73 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::~ACE_Timeprobe_Ex ()
  74 {
  75   ACE_DES_ARRAY_FREE ((ACE_timeprobe_t *) (this->timeprobes_),
  76                       this->max_size_,
  77                       this->allocator ()->free,
  78                       ACE_timeprobe_t);
  79 }
  80
  81 template <class ACE_LOCK, class ALLOCATOR> void
  82 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::timeprobe (u_long event)
  83 {
  84   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
  85
  86   this->timeprobes_[this->current_size_].event_.event_number_ = event;
  87   this->timeprobes_[this->current_size_].event_type_ = ACE_timeprobe_t::NUMBER;
  88   this->timeprobes_[this->current_size_].time_ = ACE_OS::gethrtime ();
  89   this->timeprobes_[this->current_size_].thread_ = ACE_OS::thr_self ();
  90
  91   ++this->current_size_;
  92
  93 #if !defined (ACE_TIMEPROBE_ASSERTS_FIXED_SIZE)
  94   // wrap around to the beginning on overflow
  95   if (this->current_size_ >= this->max_size_)
  96     {
  97       this->current_size_ = 0;
  98       this->report_buffer_full_ = 1;
  99     }
 100 #endif /* ACE_TIMEPROBE_ASSERTS_FIXED_SIZE */
 101
 102   ACE_ASSERT (this->current_size_ < this->max_size_);
 103 }
 104
 105 template <class ACE_LOCK, class ALLOCATOR> void
 106 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::timeprobe (const char *event)
 107 {
 108   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
 109
 110   this->timeprobes_[this->current_size_].event_.event_description_ = event;
 111   this->timeprobes_[this->current_size_].event_type_ = ACE_timeprobe_t::STRING;
 112   this->timeprobes_[this->current_size_].time_ = ACE_OS::gethrtime ();
 113   this->timeprobes_[this->current_size_].thread_ = ACE_OS::thr_self ();
 114
 115   ++this->current_size_;
 116
 117 #if !defined (ACE_TIMEPROBE_ASSERTS_FIXED_SIZE)
 118   // wrap around to the beginning on overflow
 119   if (this->current_size_ >= this->max_size_)
 120     {
 121       this->current_size_ = 0;
 122       this->report_buffer_full_ = 1;
 123     }
 124 #endif /* ACE_TIMEPROBE_ASSERTS_FIXED_SIZE */
 125
 126   ACE_ASSERT (this->current_size_ < this->max_size_);
 127 }
 128
 129 template <class ACE_LOCK, class ALLOCATOR> void
 130 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::reset ()
 131 {
 132   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
 133
 134   this->current_size_ = 0;
 135   this->report_buffer_full_ = 0;
 136 }
 137
 138 template <class ACE_LOCK, class ALLOCATOR> void
 139 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::increase_size (u_long size)
 140 {
 141   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
 142
 143   if (size > this->max_size_)
 144     {
 145       ACE_timeprobe_t *temp = 0;
 146       //FUZZ: disable check_for_lack_ACE_OS
 147       ACE_NEW_MALLOC_ARRAY (temp,
 148                             (ACE_timeprobe_t *) this->allocator ()->
 149                             malloc (this->max_size_
 150                                     * sizeof (ACE_timeprobe_t)),
 151                             ACE_timeprobe_t,
 152                             size);
 153       //FUZZ: enable check_for_lack_ACE_OS
 154
 155       if (this->max_size_ > 0)
 156         {
 157           ACE_OS::memcpy (temp,
 158                           this->timeprobes_,
 159                           this->max_size_ * sizeof (ACE_timeprobe_t));
 160
 161           // Iterates over the array explicitly calling the destructor for
 162           // each probe instance, then deallocates the memory
 163
 164           ACE_DES_ARRAY_FREE ((ACE_timeprobe_t *)(this->timeprobes_),
 165                               this->max_size_,
 166                               this->allocator ()->free,
 167                               ACE_timeprobe_t);
 168         }
 169       this->timeprobes_ = temp;
 170       this->max_size_ = size;
 171     }
 172 }
 173
 174 template <class ACE_LOCK, class ALLOCATOR> ACE_Unbounded_Set<ACE_Event_Descriptions> &
 175 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::event_descriptions ()
 176 {
 177   return this->event_descriptions_;
 178 }
 179
 180 template <class ACE_LOCK, class ALLOCATOR> ACE_Unbounded_Set<ACE_Event_Descriptions> &
 181 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::sorted_event_descriptions ()
 182 {
 183   return this->sorted_event_descriptions_;
 184 }
 185
 186 template <class ACE_LOCK, class ALLOCATOR> ACE_timeprobe_t *
 187 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::timeprobes ()
 188 {
 189   return this->timeprobes_;
 190 }
 191
 192 template <class ACE_LOCK, class ALLOCATOR> ACE_LOCK &
 193 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::lock ()
 194 {
 195   return this->lock_;
 196 }
 197
 198 template <class ACE_LOCK, class ALLOCATOR> u_long
 199 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::max_size ()
 200 {
 201   return this->max_size_;
 202 }
 203
 204 template <class ACE_LOCK, class ALLOCATOR> u_long
 205 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::current_size ()
 206 {
 207   return this->current_size_;
 208 }
 209
 210 template <class ACE_LOCK, class ALLOCATOR> int
 211 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::event_descriptions (const char **descriptions,
 212                                              u_long minimum_id)
 213 {
 214   ACE_GUARD_RETURN (ACE_LOCK, ace_mon, this->lock_, -1);
 215
 216   ACE_Event_Descriptions events;
 217   events.descriptions_ = descriptions;
 218   events.minimum_id_ = minimum_id;
 219
 220   this->event_descriptions_.insert (events);
 221
 222   return 0;
 223 }
 224
 225 template <class ACE_LOCK, class ALLOCATOR> void
 226 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::print_times ()
 227 {
 228   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
 229
 230   // Sort the event descriptions
 231   this->sort_event_descriptions_i ();
 232
 233   u_long size = this->report_buffer_full_ ? this->max_size_
 234                                           : this->current_size_;
 235
 236   ACELIB_DEBUG ((LM_DEBUG,
 237               "\nACE_Timeprobe_Ex; %u timestamps were recorded:\n",
 238               size));
 239
 240   if (size == 0)
 241     return;
 242
 243   ACELIB_DEBUG ((LM_DEBUG,
 244               "\n%-50.50s %8.8s %13.13s\n\n",
 245               "Event",
 246               "thread",
 247               "usec"));
 248
 249   ACE_High_Res_Timer::global_scale_factor_type gsf =
 250     ACE_High_Res_Timer::global_scale_factor ();
 251   u_long i, j;
 252
 253   // First element
 254   i = this->report_buffer_full_ ? this->current_size_ : 0;
 255
 256   ACELIB_DEBUG ((LM_DEBUG,
 257               "%-50.50s %8.8x %13.13s\n",
 258               this->find_description_i (i),
 259               this->timeprobes_[i].thread_,
 260               "START"));
 261
 262   if (size == 1)
 263     return;
 264
 265   bool has_timestamp_inversion = false;
 266
 267   j = i;
 268   i = (i + 1) % this->max_size_;
 269
 270   do
 271     {
 272       // When reusing the same ACE_Timeprobe from multiple threads
 273       // with Linux on Intel SMP, it sometimes happens that the
 274       // recorded times go backward in time if they are recorded from
 275       // different threads (see bugzilla #2342).  To obtain the
 276       // correct signed difference between consecutive recorded times,
 277       // one has to cast the time difference to an intermediate signed
 278       // integral type of the same size as ACE_hrtime_t.
 279
 280       double time_difference =
 281         (ACE_INT64) (this->timeprobes_[i].time_ - this->timeprobes_[j].time_);
 282
 283       if (time_difference < 0)
 284         has_timestamp_inversion = true;
 285
 286       // Convert to microseconds.
 287       time_difference /= gsf;
 288
 289       ACELIB_DEBUG ((LM_DEBUG,
 290                   "%-50.50s %8.8x %14.3f\n",
 291                   this->find_description_i (i),
 292                   this->timeprobes_[i].thread_,
 293                   time_difference));
 294
 295       j = i;
 296       i = (i + 1) % this->max_size_;
 297     }
 298   while (i != this->current_size_);
 299
 300   static bool inversion_warning_printed = false;
 301   if (!inversion_warning_printed && has_timestamp_inversion)
 302     {
 303       inversion_warning_printed = true;
 304       ACELIB_DEBUG ((LM_DEBUG,
 305                   "\nWARNING: The timestamps recorded by gethrtime() on"
 306                   " this platform are\n"
 307                   "not monotonic across different threads.\n"));
 308     }
 309 }
 310
 311 template <class ACE_LOCK, class ALLOCATOR> void
 312 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::print_absolute_times ()
 313 {
 314   ACE_GUARD (ACE_LOCK, ace_mon, this->lock_);
 315
 316   // Sort the event descriptions
 317   this->sort_event_descriptions_i ();
 318
 319   u_long size = this->report_buffer_full_ ? this->max_size_
 320                                           : this->current_size_;
 321
 322   ACELIB_DEBUG ((LM_DEBUG,
 323               "\nACE_Timeprobe_Ex; %u timestamps were recorded:\n",
 324               size));
 325
 326   if (size == 0)
 327     return;
 328
 329   ACELIB_DEBUG ((LM_DEBUG,
 330               "\n%-50.50s %8.8s %13.13s\n\n",
 331               "Event",
 332               "thread",
 333               "stamp"));
 334
 335   u_long i = this->report_buffer_full_ ? this->current_size_ : 0;
 336
 337   ACE_Time_Value tv; // to convert ACE_hrtime_t
 338   do
 339     {
 340       ACE_High_Res_Timer::hrtime_to_tv (tv, this->timeprobes_ [i].time_);
 341
 342       ACELIB_DEBUG ((LM_DEBUG,
 343                   "%-50.50s %8.8x %12.12u\n",
 344                   this->find_description_i (i),
 345                   this->timeprobes_ [i].thread_,
 346                   tv.sec () * 1000000
 347                    + tv.usec ()));
 348
 349       // Modulus increment: loops around at the end.
 350       i = (i + 1) % this->max_size_;
 351     }
 352   while (i != this->current_size_);
 353 }
 354
 355 template <class ACE_LOCK, class ALLOCATOR> const char *
 356 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::find_description_i (u_long i)
 357 {
 358   if (this->timeprobes_[i].event_type_ == ACE_timeprobe_t::STRING)
 359     return this->timeprobes_[i].event_.event_description_;
 360   else
 361     {
 362       EVENT_DESCRIPTIONS::iterator iterator = this->sorted_event_descriptions_.begin ();
 363       for (u_long j = 0;
 364            j < this->sorted_event_descriptions_.size () - 1;
 365            iterator++, j++)
 366         {
 367           EVENT_DESCRIPTIONS::iterator next_event_descriptions = iterator;
 368           ++next_event_descriptions;
 369
 370           if (this->timeprobes_[i].event_.event_number_ < (*next_event_descriptions).minimum_id_)
 371             break;
 372         }
 373       return (*iterator).descriptions_[this->timeprobes_[i].event_.event_number_ - (*iterator).minimum_id_];
 374     }
 375 }
 376
 377 template <class ACE_LOCK, class ALLOCATOR> void
 378 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::sort_event_descriptions_i ()
 379 {
 380   size_t total_elements = this->event_descriptions_.size ();
 381
 382   for (size_t i = 0;
 383        i < total_elements;
 384        i++)
 385     {
 386       EVENT_DESCRIPTIONS::iterator iterator = this->event_descriptions_.begin ();
 387       ACE_Event_Descriptions min_entry = *iterator;
 388
 389       for (;
 390            iterator != this->event_descriptions_.end ();
 391            iterator++)
 392         if ((*iterator).minimum_id_ < min_entry.minimum_id_)
 393           min_entry = *iterator;
 394
 395       this->sorted_event_descriptions_.insert (min_entry);
 396       this->event_descriptions_.remove (min_entry);
 397     }
 398 }
 399
 400 template <class ACE_LOCK, class ALLOCATOR> ALLOCATOR *
 401 ACE_Timeprobe_Ex<ACE_LOCK, ALLOCATOR>::allocator ()
 402 {
 403   return allocator_ ? allocator_ : ACE_Singleton<ALLOCATOR, ACE_LOCK>::instance ();
 404 }
 405
 406 template <class Timeprobe>
 407 ACE_Function_Timeprobe<Timeprobe>::ACE_Function_Timeprobe (Timeprobe &timeprobe,
 408                                                            u_long event)
 409   : timeprobe_ (timeprobe),
 410     event_ (event)
 411 {
 412   this->timeprobe_.timeprobe (this->event_);
 413 }
 414
 415 template <class Timeprobe>
 416 ACE_Function_Timeprobe<Timeprobe>::~ACE_Function_Timeprobe ()
 417 {
 418   this->timeprobe_.timeprobe (this->event_ + 1);
 419 }
 420
 421 ACE_END_VERSIONED_NAMESPACE_DECL
 422
 423 #endif /* ACE_COMPILE_TIMEPROBES */
 424 #endif /* ACE_TIMEPROBE_T_CPP */