xpcom/base/FunctionTimer.h

   1 /* -*- Mode: C++; tab-width: 40; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
   2 /* ***** BEGIN LICENSE BLOCK *****
   3  * Version: MPL 1.1/GPL 2.0/LGPL 2.1
   4  *
   5  * The contents of this file are subject to the Mozilla Public License Version
   6  * 1.1 (the "License"); you may not use this file except in compliance with
   7  * the License. You may obtain a copy of the License at
   8  * http://www.mozilla.org/MPL/
   9  *
  10  * Software distributed under the License is distributed on an "AS IS" basis,
  11  * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
  12  * for the specific language governing rights and limitations under the
  13  * License.
  14  *
  15  * The Original Code is Mozilla code.
  16  *
  17  * The Initial Developer of the Original Code is
  18  * Mozilla Corporation.
  19  * Portions created by the Initial Developer are Copyright (C) 2009
  20  * the Initial Developer. All Rights Reserved.
  21  *
  22  * Contributor(s):
  23  *   Vladimir Vukicevic <vladimir@pobox.com>
  24  *
  25  * Alternatively, the contents of this file may be used under the terms of
  26  * either the GNU General Public License Version 2 or later (the "GPL"), or
  27  * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
  28  * in which case the provisions of the GPL or the LGPL are applicable instead
  29  * of those above. If you wish to allow use of your version of this file only
  30  * under the terms of either the GPL or the LGPL, and not to allow others to
  31  * use your version of this file under the terms of the MPL, indicate your
  32  * decision by deleting the provisions above and replace them with the notice
  33  * and other provisions required by the GPL or the LGPL. If you do not delete
  34  * the provisions above, a recipient may use your version of this file under
  35  * the terms of any one of the MPL, the GPL or the LGPL.
  36  *
  37  * ***** END LICENSE BLOCK ***** */
  38
  39 #ifndef mozilla_FunctionTimer_h
  40 #define mozilla_FunctionTimer_h
  41
  42 #include <stdarg.h>
  43
  44 #include "mozilla/TimeStamp.h"
  45 #include "nscore.h"
  46 #include "nsAutoPtr.h"
  47
  48 #if defined(NS_FORCE_FUNCTION_TIMER) && !defined(NS_FUNCTION_TIMER)
  49 #define NS_FUNCTION_TIMER
  50 #endif
  51
  52 /*
  53  * Shortcut macros
  54  */
  55
  56 #ifdef NS_FUNCTION_TIMER
  57
  58 #ifdef __GNUC__
  59 #define MOZ_FUNCTION_NAME __PRETTY_FUNCTION__
  60 #elif defined(_MSC_VER)
  61 #define MOZ_FUNCTION_NAME __FUNCTION__
  62 #else
  63 #warning "Define a suitable MOZ_FUNCTION_NAME for this platform"
  64 #define MOZ_FUNCTION_NAME ""
  65 #endif
  66
  67 // Add a timer for this function, from this declaration until the
  68 // function returns.  The function name will be used as the
  69 // log string, and both function entry and exit will be printed.
  70 #define NS_TIME_FUNCTION                                                \
  71     mozilla::FunctionTimer ft__autogen("%s (line %d)", MOZ_FUNCTION_NAME, __LINE__)
  72
  73 // Add a timer for this block, but print only a) if the exit time is
  74 // greater than the given number of milliseconds; or b) if the
  75 // mark-to-mark time is greater than the given number of milliseconds.
  76 // No function entry will be printed.  If the value given is negative,
  77 // no function entry or exit will ever be printed, but all marks will.
  78 #define NS_TIME_FUNCTION_MIN(_ms)                                       \
  79     mozilla::FunctionTimer ft__autogen((_ms), "%s (line %d)", MOZ_FUNCTION_NAME, __LINE__)
  80
  81 // Add a timer for this block, but print only marks, not function
  82 // entry and exit.  The same as calling the above macro with a negative value.
  83 #define NS_TIME_FUNCTION_MARK_ONLY                                    \
  84     mozilla::FunctionTimer ft__autogen((-1), "%s (line %d)", MOZ_FUNCTION_NAME, __LINE__)
  85
  86 // Add a timer for this block, using the printf-style format.
  87 // Both function entry and exit will be printed.
  88 #define NS_TIME_FUNCTION_FMT(...)                                       \
  89     mozilla::FunctionTimer ft__autogen(__VA_ARGS__)
  90
  91 // Add a timer for this block, using the given minimum number of
  92 // milliseconds and the given printf-style format.  No function entry
  93 // will be printed.
  94 #define NS_TIME_FUNCTION_MIN_FMT(_ms, ...)                              \
  95     mozilla::FunctionTimer ft__autogen((_ms), __VA_ARGS__)
  96
  97 // Add a midway mark for the current timer; an existing timer must
  98 // have already been created using one of the above macros.  The
  99 // string given by the printf-style format will be logged, as well as
 100 // the total elapsed time since the creation of the timer, and the
 101 // time since the last mark.
 102 #define NS_TIME_FUNCTION_MARK(...)              \
 103     ft__autogen.Mark(__VA_ARGS__)
 104
 105 // A double value representing the time elapsed since NS_TIME_FUNCTION
 106 // initialization, in ms.
 107 #define NS_TIME_FUNCTION_ELAPSED              \
 108     ft__autogen.Elapsed()
 109
 110 // A double value representing the time elapsed since the last
 111 // NS_TIME_FUNCTION_MARK, in ms.
 112 #define NS_TIME_FUNCTION_ELAPSED_SINCE_MARK                             \
 113     ft__autogen.ElapsedSinceMark
 114
 115 // A TimeDuration value representing the elapsed time between the
 116 // last logged event of any sort and the app startup.
 117 #define NS_TIME_FUNCTION_LATEST \
 118     mozilla::FunctionTimer::LatestSinceStartup()
 119
 120 #else
 121
 122 #define NS_TIME_FUNCTION do { } while (0)
 123 #define NS_TIME_FUNCTION_MIN(_ms) do { } while (0)
 124 #define NS_TIME_FUNCTION_MARK_ONLY do { } while (0)
 125 #define NS_TIME_FUNCTION_FMT(...) do { } while (0)
 126 #define NS_TIME_FUNCTION_MIN_FMT(_ms, ...) do { } while (0)
 127 #define NS_TIME_FUNCTION_MARK(...) do { } while (0)
 128 #define NS_TIME_FUNCTION_ELAPSED (0)
 129 #define NS_TIME_FUNCTION_ELAPSED_SINCE_MARK (0)
 130 #define NS_TIME_FUNCTION_LATEST (mozilla::TimeDuration(0))
 131
 132 #endif
 133
 134 namespace mozilla {
 135
 136 class NS_COM FunctionTimerLog
 137 {
 138 public:
 139     FunctionTimerLog(const char *fname);
 140     ~FunctionTimerLog();
 141
 142     void LogString(const char *str);
 143
 144     TimeDuration LatestSinceStartup() const;
 145
 146 private:
 147     void *mFile;
 148     TimeStamp mLatest;
 149 };
 150
 151 class NS_COM FunctionTimer
 152 {
 153     static nsAutoPtr<FunctionTimerLog> sLog;
 154     static char *sBuf1;
 155     static char *sBuf2;
 156     static int sBufSize;
 157     static unsigned sDepth;
 158
 159     enum { BUF_LOG_LENGTH = 1024 };
 160
 161 public:
 162     static int InitTimers();
 163
 164     static int ft_vsnprintf(char *str, int maxlen, const char *fmt, va_list args);
 165     static int ft_snprintf(char *str, int maxlen, const char *fmt, ...);
 166
 167     static void LogMessage(const char *s, ...) {
 168         va_list ap;
 169         va_start(ap, s);
 170
 171         if (sLog) {
 172             ft_vsnprintf(sBuf1, sBufSize, s, ap);
 173             sLog->LogString(sBuf1);
 174         }
 175
 176         va_end(ap);
 177     }
 178
 179 private:
 180     void Init(const char *s, va_list ap) {
 181         if (mEnabled) {
 182             TimeInit();
 183
 184             ft_vsnprintf(mString, BUF_LOG_LENGTH, s, ap);
 185
 186             ft_snprintf(sBuf1, sBufSize, "> (% 3d)%*s|%s%s", mDepth, mDepth, " ", mHasMinMs ? "?MINMS " : "", mString);
 187             sLog->LogString(sBuf1);
 188         }
 189     }
 190
 191 public:
 192     inline void TimeInit() {
 193         if (mEnabled) {
 194             mStart = TimeStamp::Now();
 195             mLastMark = mStart;
 196         }
 197     }
 198
 199     inline double Elapsed() {
 200         if (mEnabled)
 201             return (TimeStamp::Now() - mStart).ToSeconds() * 1000.0;
 202         return 0.0;
 203     }
 204
 205     inline double ElapsedSinceMark() {
 206         if (mEnabled)
 207             return (TimeStamp::Now() - mLastMark).ToSeconds() * 1000.0;
 208         return 0.0;
 209     }
 210
 211     static inline TimeDuration LatestSinceStartup() {
 212         return sLog ? sLog->LatestSinceStartup() : TimeDuration(0);
 213     }
 214
 215     FunctionTimer(double minms, const char *s, ...)
 216         : mMinMs(minms), mHasMinMs(PR_TRUE),
 217           mEnabled(sLog && s && *s), mDepth(++sDepth)
 218     {
 219         va_list ap;
 220         va_start(ap, s);
 221
 222         Init(s, ap);
 223
 224         va_end(ap);
 225     }
 226
 227     FunctionTimer(const char *s, ...)
 228         : mMinMs(0.0), mHasMinMs(PR_FALSE),
 229           mEnabled(sLog && s && *s), mDepth(++sDepth)
 230     {
 231         va_list ap;
 232         va_start(ap, s);
 233
 234         Init(s, ap);
 235
 236         va_end(ap);
 237     }
 238
 239     void Mark(const char *s, ...)
 240     {
 241         va_list ap;
 242         va_start(ap, s);
 243
 244         if (mEnabled) {
 245             ft_vsnprintf(sBuf1, sBufSize, s, ap);
 246
 247             TimeStamp now(TimeStamp::Now());
 248             double ms = (now - mStart).ToSeconds() * 1000.0;
 249             double msl = (now - mLastMark).ToSeconds() * 1000.0;
 250             mLastMark = now;
 251
 252             ft_snprintf(sBuf2, sBufSize, "* (% 3d)%*s|%s%9.2f ms (%9.2f ms total) - %s [%s]", mDepth, mDepth, " ",
 253                 (!mHasMinMs || mMinMs < 0.0 || msl > mMinMs) ? "<MINMS " : "", msl, ms, mString, sBuf1);
 254             sLog->LogString(sBuf2);
 255         }
 256
 257         va_end(ap);
 258     }
 259
 260     ~FunctionTimer() {
 261         if (mEnabled) {
 262             TimeStamp now(TimeStamp::Now());
 263             double ms = (now - mStart).ToSeconds() * 1000.0;
 264             double msl = (now - mLastMark).ToSeconds() * 1000.0;
 265
 266             ft_snprintf(sBuf1, sBufSize, "< (% 3d)%*s|%s%9.2f ms (%9.2f ms total) - %s", mDepth, mDepth, " ",
 267                 (!mHasMinMs || (mMinMs >= 0.0 && msl > mMinMs)) ? "" : "<MINMS ", msl, ms, mString);
 268             sLog->LogString(sBuf1);
 269         }
 270
 271         --sDepth;
 272     }
 273
 274     TimeStamp mStart, mLastMark;
 275     const double mMinMs;
 276     char mString[BUF_LOG_LENGTH+1];
 277     const PRBool mHasMinMs;
 278     const PRBool mEnabled;
 279     const unsigned mDepth;
 280 };
 281
 282 } // namespace mozilla
 283
 284 #endif // mozilla_FunctionTimer_h
 285
 286