Back to index

lightning-sunbird  0.9+nobinonly
nsTimelineService.cpp
Go to the documentation of this file.
00001 /* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
00002 /* ***** BEGIN LICENSE BLOCK *****
00003  * Version: MPL 1.1/GPL 2.0/LGPL 2.1
00004  *
00005  * The contents of this file are subject to the Mozilla Public License Version
00006  * 1.1 (the "License"); you may not use this file except in compliance with
00007  * the License. You may obtain a copy of the License at
00008  * http://www.mozilla.org/MPL/
00009  *
00010  * Software distributed under the License is distributed on an "AS IS" basis,
00011  * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
00012  * for the specific language governing rights and limitations under the
00013  * License.
00014  *
00015  * The Original Code is mozilla.org code.
00016  *
00017  * The Initial Developer of the Original Code is
00018  * Netscape Communications Corporation.
00019  * Portions created by the Initial Developer are Copyright (C) 1998
00020  * the Initial Developer. All Rights Reserved.
00021  *
00022  * Contributor(s):
00023  *
00024  * Alternatively, the contents of this file may be used under the terms of
00025  * either of the GNU General Public License Version 2 or later (the "GPL"),
00026  * or the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
00027  * in which case the provisions of the GPL or the LGPL are applicable instead
00028  * of those above. If you wish to allow use of your version of this file only
00029  * under the terms of either the GPL or the LGPL, and not to allow others to
00030  * use your version of this file under the terms of the MPL, indicate your
00031  * decision by deleting the provisions above and replace them with the notice
00032  * and other provisions required by the GPL or the LGPL. If you do not delete
00033  * the provisions above, a recipient may use your version of this file under
00034  * the terms of any one of the MPL, the GPL or the LGPL.
00035  *
00036  * ***** END LICENSE BLOCK ***** */
00037 
00038 #include "nsTimelineService.h"
00039 #include "prlong.h"
00040 #include "prprf.h"
00041 #include "prenv.h"
00042 #include "plhash.h"
00043 #include "prlock.h"
00044 #include "prinit.h"
00045 #include "prinrval.h"
00046 #include "prthread.h"
00047 
00048 #ifdef MOZ_TIMELINE
00049 
00050 #define MAXINDENT 20
00051 
00052 static PRFileDesc *timelineFD = PR_STDERR;
00053 static PRBool gTimelineDisabled = PR_TRUE;
00054 
00055 // Notes about threading:
00056 // We avoid locks as we always use thread-local-storage.
00057 // This means every other thread has its own private copy of
00058 // data, and this thread can't re-enter (as our implemenation
00059 // doesn't call back out anywhere).  Thus, we can avoid locks!
00060 // TLS index
00061 static const PRUintn BAD_TLS_INDEX = (PRUintn) -1;
00062 static PRUintn gTLSIndex = BAD_TLS_INDEX;
00063 
00064 class TimelineThreadData {
00065 public:
00066     TimelineThreadData() : initTime(0), indent(0),
00067                            disabled(PR_TRUE), timers(nsnull) {}
00068     ~TimelineThreadData() {if (timers) PL_HashTableDestroy(timers);}
00069     PRTime initTime;
00070     PRHashTable *timers;
00071     int indent;
00072     PRBool disabled;
00073 };
00074 
00075 /* Implementation file */
00076 NS_IMPL_THREADSAFE_ISUPPORTS1(nsTimelineService, nsITimelineService)
00077 
00078 /*
00079  * Timer structure stored in a hash table to keep track of named
00080  * timers.
00081  */
00082 class nsTimelineServiceTimer {
00083   public:
00084     nsTimelineServiceTimer();
00085     ~nsTimelineServiceTimer();
00086     void start();
00087     
00088     /*
00089      * Caller passes in "now" rather than having us calculate it so
00090      * that we can avoid including timer overhead in the time being
00091      * measured.
00092      */
00093     void stop(PRTime now);
00094     void reset();
00095     PRTime getAccum();
00096     PRTime getAccum(PRTime now);
00097 
00098   private:
00099     PRTime mAccum;
00100     PRTime mStart;
00101     PRInt32 mRunning;
00102     PRThread *mOwnerThread; // only used for asserts - could be #if MOZ_DEBUG
00103 };
00104 
00105 #define TIMER_CHECK_OWNER() \
00106     NS_ABORT_IF_FALSE(PR_GetCurrentThread() == mOwnerThread, \
00107                       "Timer used by non-owning thread")
00108 
00109 
00110 nsTimelineServiceTimer::nsTimelineServiceTimer()
00111 : mAccum(LL_ZERO), mStart(LL_ZERO), mRunning(0),
00112   mOwnerThread(PR_GetCurrentThread())
00113 {
00114 }
00115 
00116 nsTimelineServiceTimer::~nsTimelineServiceTimer()
00117 {
00118 }
00119 
00120 void nsTimelineServiceTimer::start()
00121 {
00122     TIMER_CHECK_OWNER();
00123     if (!mRunning) {
00124         mStart = PR_Now();
00125     }
00126     mRunning++;
00127 }
00128 
00129 void nsTimelineServiceTimer::stop(PRTime now)
00130 {
00131     TIMER_CHECK_OWNER();
00132     mRunning--;
00133     if (mRunning == 0) {
00134         PRTime delta, accum;
00135         LL_SUB(delta, now, mStart);
00136         LL_ADD(accum, mAccum, delta);
00137         mAccum = accum;
00138     }
00139 }
00140 
00141 void nsTimelineServiceTimer::reset()
00142 {
00143   TIMER_CHECK_OWNER();
00144   mStart = 0;
00145   mAccum = 0;
00146 }
00147 
00148 PRTime nsTimelineServiceTimer::getAccum()
00149 {
00150     TIMER_CHECK_OWNER();
00151     PRTime accum;
00152 
00153     if (!mRunning) {
00154         accum = mAccum;
00155     } else {
00156         PRTime delta;
00157         LL_SUB(delta, PR_Now(), mStart);
00158         LL_ADD(accum, mAccum, delta);
00159     }
00160     return accum;
00161 }
00162 
00163 PRTime nsTimelineServiceTimer::getAccum(PRTime now)
00164 {
00165     TIMER_CHECK_OWNER();
00166     PRTime accum;
00167 
00168     if (!mRunning) {
00169         accum = mAccum;
00170     } else {
00171         PRTime delta;
00172         LL_SUB(delta, now, mStart);
00173         LL_ADD(accum, mAccum, delta);
00174     }
00175     return accum;
00176 }
00177 
00178 static TimelineThreadData *GetThisThreadData()
00179 {
00180     NS_ABORT_IF_FALSE(gTLSIndex!=BAD_TLS_INDEX, "Our TLS not initialized");
00181     TimelineThreadData *new_data = nsnull;
00182     TimelineThreadData *data = (TimelineThreadData *)PR_GetThreadPrivate(gTLSIndex);
00183     if (data == nsnull) {
00184         // First request for this thread - allocate it.
00185         new_data = new TimelineThreadData();
00186         if (!new_data)
00187             goto done;
00188 
00189         // Fill it
00190         new_data->timers = PL_NewHashTable(100, PL_HashString, PL_CompareStrings,
00191                                  PL_CompareValues, NULL, NULL);
00192         if (new_data->timers==NULL)
00193             goto done;
00194         new_data->initTime = PR_Now();
00195         NS_WARN_IF_FALSE(!gTimelineDisabled,
00196                          "Why are we creating new state when disabled?");
00197         new_data->disabled = PR_FALSE;
00198         data = new_data;
00199         new_data = nsnull;
00200         PR_SetThreadPrivate(gTLSIndex, data);
00201     }
00202 done:
00203     if (new_data) // eeek - error during creation!
00204         delete new_data;
00205     NS_WARN_IF_FALSE(data, "TimelineService could not get thread-local data");
00206     return data;
00207 }
00208 
00209 extern "C" {
00210   static void ThreadDestruct (void *data);
00211   static PRStatus TimelineInit(void);
00212 }
00213 
00214 void ThreadDestruct( void *data )
00215 {
00216     if (data)
00217         delete (TimelineThreadData *)data;
00218 }
00219 
00220 /*
00221 * PRCallOnceFN that initializes stuff for the timing service.
00222 */
00223 static PRCallOnceType initonce;
00224 
00225 PRStatus TimelineInit(void)
00226 {
00227     char *timeStr;
00228     char *fileName;
00229     PRInt32 secs, msecs;
00230     PRFileDesc *fd;
00231     PRInt64 tmp1, tmp2;
00232 
00233     PRStatus status = PR_NewThreadPrivateIndex( &gTLSIndex, ThreadDestruct );
00234     NS_WARN_IF_FALSE(status==0, "TimelineService could not allocate TLS storage.");
00235 
00236     timeStr = PR_GetEnv("NS_TIMELINE_INIT_TIME");
00237 
00238     // NS_TIMELINE_INIT_TIME only makes sense for the main thread, so if it
00239     // exists, set it there.  If not, let normal thread management code take
00240     // care of setting the init time.
00241     if (timeStr != NULL && 2 == PR_sscanf(timeStr, "%d.%d", &secs, &msecs)) {
00242         PRTime &initTime = GetThisThreadData()->initTime;
00243         LL_MUL(tmp1, (PRInt64)secs, 1000000);
00244         LL_MUL(tmp2, (PRInt64)msecs, 1000);
00245         LL_ADD(initTime, tmp1, tmp2);
00246     }
00247     // Get the log file.
00248     fileName = PR_GetEnv("NS_TIMELINE_LOG_FILE");
00249     if (fileName != NULL
00250         && (fd = PR_Open(fileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
00251                          0666)) != NULL) {
00252         timelineFD = fd;
00253         PR_fprintf(fd,
00254                    "NOTE: due to asynchrony, the indentation that you see does"
00255                    " not necessarily correspond to nesting in the code.\n\n");
00256     }
00257 
00258     // Runtime disable of timeline
00259     if (PR_GetEnv("NS_TIMELINE_ENABLE"))
00260         gTimelineDisabled = PR_FALSE;
00261     return PR_SUCCESS;
00262 }
00263 
00264 static void ParseTime(PRTime tm, PRInt32& secs, PRInt32& msecs)
00265 {
00266     PRTime llsecs, llmsecs, tmp;
00267 
00268     LL_DIV(llsecs, tm, 1000000);
00269     LL_MOD(tmp, tm, 1000000);
00270     LL_DIV(llmsecs, tmp, 1000);
00271 
00272     LL_L2I(secs, llsecs);
00273     LL_L2I(msecs, llmsecs);
00274 }
00275 
00276 static char *Indent(char *buf)
00277 {
00278     int &indent = GetThisThreadData()->indent;
00279     int amount = indent;
00280     if (amount > MAXINDENT) {
00281         amount = MAXINDENT;
00282     }
00283     if (amount < 0) {
00284         amount = 0;
00285         indent = 0;
00286         PR_Write(timelineFD, "indent underflow!\n", 18);
00287     }
00288     while (amount--) {
00289         *buf++ = ' ';
00290     }
00291     return buf;
00292 }
00293 
00294 static void PrintTime(PRTime tm, const char *text, va_list args)
00295 {
00296     PRInt32 secs, msecs;
00297     char pbuf[550], *pc, tbuf[550];
00298 
00299     ParseTime(tm, secs, msecs);
00300 
00301     // snprintf/write rather than fprintf because we don't want
00302     // messages from multiple threads to garble one another.
00303     pc = Indent(pbuf);
00304     PR_vsnprintf(pc, sizeof pbuf - (pc - pbuf), text, args);
00305     PR_snprintf(tbuf, sizeof tbuf, "%05d.%03d (%08p): %s\n",
00306                 secs, msecs, PR_GetCurrentThread(), pbuf);
00307     PR_Write(timelineFD, tbuf, strlen(tbuf));
00308 }
00309 
00310 /*
00311  * Make this public if we need it.
00312  */
00313 static nsresult NS_TimelineMarkV(const char *text, va_list args)
00314 {
00315     PRTime elapsed,tmp;
00316 
00317     PR_CallOnce(&initonce, TimelineInit);
00318 
00319     TimelineThreadData *thread = GetThisThreadData();
00320 
00321     tmp = PR_Now();
00322     LL_SUB(elapsed, tmp, thread->initTime);
00323 
00324     PrintTime(elapsed, text, args);
00325 
00326     return NS_OK;
00327 }
00328 
00329 PR_IMPLEMENT(nsresult) NS_TimelineForceMark(const char *text, ...)
00330 {
00331     va_list args;
00332     va_start(args, text);
00333     NS_TimelineMarkV(text, args);
00334 
00335     return NS_OK;
00336 }
00337 
00338 PR_IMPLEMENT(nsresult) NS_TimelineMark(const char *text, ...)
00339 {
00340     va_list args;
00341     va_start(args, text);
00342 
00343     PR_CallOnce(&initonce, TimelineInit);
00344 
00345     if (gTimelineDisabled)
00346         return NS_ERROR_NOT_AVAILABLE;
00347 
00348     TimelineThreadData *thread = GetThisThreadData();
00349 
00350     if (thread->disabled)
00351         return NS_ERROR_NOT_AVAILABLE;
00352 
00353     NS_TimelineMarkV(text, args);
00354 
00355     return NS_OK;
00356 }
00357 
00358 PR_IMPLEMENT(nsresult) NS_TimelineStartTimer(const char *timerName)
00359 {
00360     PR_CallOnce(&initonce, TimelineInit);
00361 
00362     if (gTimelineDisabled)
00363         return NS_ERROR_NOT_AVAILABLE;
00364 
00365     TimelineThreadData *thread = GetThisThreadData();
00366 
00367     if (thread->timers == NULL)
00368         return NS_ERROR_FAILURE;
00369     if (thread->disabled)
00370         return NS_ERROR_NOT_AVAILABLE;
00371 
00372     nsTimelineServiceTimer *timer
00373         = (nsTimelineServiceTimer *)PL_HashTableLookup(thread->timers, timerName);
00374     if (timer == NULL) {
00375         timer = new nsTimelineServiceTimer;
00376         if (!timer)
00377             return NS_ERROR_OUT_OF_MEMORY;
00378 
00379         PL_HashTableAdd(thread->timers, timerName, timer);
00380     }
00381     timer->start();
00382     return NS_OK;
00383 }
00384 
00385 PR_IMPLEMENT(nsresult) NS_TimelineStopTimer(const char *timerName)
00386 {
00387     if (gTimelineDisabled)
00388         return NS_ERROR_NOT_AVAILABLE;
00389     /*
00390      * Strange-looking now/timer->stop() interaction is to avoid
00391      * including time spent in TLS and PL_HashTableLookup in the
00392      * timer.
00393      */
00394     PRTime now = PR_Now();
00395 
00396     TimelineThreadData *thread = GetThisThreadData();
00397     if (thread->timers == NULL)
00398         return NS_ERROR_FAILURE;
00399     if (thread->disabled)
00400         return NS_ERROR_NOT_AVAILABLE;
00401     nsTimelineServiceTimer *timer
00402         = (nsTimelineServiceTimer *)PL_HashTableLookup(thread->timers, timerName);
00403     if (timer == NULL) {
00404         return NS_ERROR_FAILURE;
00405     }
00406 
00407     timer->stop(now);
00408 
00409     return NS_OK;
00410 }
00411 
00412 PR_IMPLEMENT(nsresult) NS_TimelineMarkTimer(const char *timerName, const char *str)
00413 {
00414     PR_CallOnce(&initonce, TimelineInit);
00415 
00416     if (gTimelineDisabled)
00417         return NS_ERROR_NOT_AVAILABLE;
00418 
00419     TimelineThreadData *thread = GetThisThreadData();
00420     if (thread->timers == NULL)
00421         return NS_ERROR_FAILURE;
00422     if (thread->disabled)
00423         return NS_ERROR_NOT_AVAILABLE;
00424     nsTimelineServiceTimer *timer
00425         = (nsTimelineServiceTimer *)PL_HashTableLookup(thread->timers, timerName);
00426     if (timer == NULL) {
00427         return NS_ERROR_FAILURE;
00428     }
00429     PRTime accum = timer->getAccum();
00430 
00431     char buf[500];
00432     PRInt32 sec, msec;
00433     ParseTime(accum, sec, msec);
00434     if (!str)
00435         PR_snprintf(buf, sizeof buf, "%s total: %d.%03d",
00436                     timerName, sec, msec);
00437     else
00438         PR_snprintf(buf, sizeof buf, "%s total: %d.%03d (%s)",
00439                     timerName, sec, msec, str);
00440     NS_TimelineMark(buf);
00441 
00442     return NS_OK;
00443 }
00444 
00445 PR_IMPLEMENT(nsresult) NS_TimelineResetTimer(const char *timerName)
00446 {
00447     if (gTimelineDisabled)
00448         return NS_ERROR_NOT_AVAILABLE;
00449 
00450     TimelineThreadData *thread = GetThisThreadData();
00451     if (thread->timers == NULL)
00452         return NS_ERROR_FAILURE;
00453     if (thread->disabled)
00454         return NS_ERROR_NOT_AVAILABLE;
00455     nsTimelineServiceTimer *timer
00456         = (nsTimelineServiceTimer *)PL_HashTableLookup(thread->timers, timerName);
00457     if (timer == NULL) {
00458         return NS_ERROR_FAILURE;
00459     }
00460 
00461     timer->reset();
00462     return NS_OK;
00463 }
00464 
00465 PR_IMPLEMENT(nsresult) NS_TimelineIndent()
00466 {
00467     if (gTimelineDisabled)
00468         return NS_ERROR_NOT_AVAILABLE;
00469 
00470     TimelineThreadData *thread = GetThisThreadData();
00471     if (thread->disabled)
00472         return NS_ERROR_NOT_AVAILABLE;
00473     thread->indent++;
00474     return NS_OK;
00475 }
00476 
00477 PR_IMPLEMENT(nsresult) NS_TimelineOutdent()
00478 {
00479     if (gTimelineDisabled)
00480         return NS_ERROR_NOT_AVAILABLE;
00481 
00482     TimelineThreadData *thread = GetThisThreadData();
00483     if (thread->disabled)
00484         return NS_ERROR_NOT_AVAILABLE;
00485     thread->indent--;
00486     return NS_OK;
00487 }
00488 
00489 PR_IMPLEMENT(nsresult) NS_TimelineEnter(const char *text)
00490 {
00491     nsresult rv = NS_TimelineMark("%s...", text);
00492     if (NS_FAILED(rv)) {
00493         return rv;
00494     }
00495     return NS_TimelineIndent();
00496 }
00497 
00498 PR_IMPLEMENT(nsresult) NS_TimelineLeave(const char *text)
00499 {
00500     nsresult rv = NS_TimelineOutdent();
00501     if (NS_FAILED(rv)) {
00502         return rv;
00503     }
00504     return NS_TimelineMark("...%s", text);
00505 }
00506 
00507 nsTimelineService::nsTimelineService()
00508 {
00509   /* member initializers and constructor code */
00510 }
00511 
00512 /* void mark (in string text); */
00513 NS_IMETHODIMP nsTimelineService::Mark(const char *text)
00514 {
00515     return NS_TimelineMark(text);
00516 }
00517 
00518 /* void startTimer (in string timerName); */
00519 NS_IMETHODIMP nsTimelineService::StartTimer(const char *timerName)
00520 {
00521     return NS_TimelineStartTimer(timerName);
00522 }
00523 
00524 /* void stopTimer (in string timerName); */
00525 NS_IMETHODIMP nsTimelineService::StopTimer(const char *timerName)
00526 {
00527     return NS_TimelineStopTimer(timerName);
00528 }
00529 
00530 /* void markTimer (in string timerName); */
00531 NS_IMETHODIMP nsTimelineService::MarkTimer(const char *timerName)
00532 {
00533     return NS_TimelineMarkTimer(timerName);
00534 }
00535 
00536 /* void markTimerWithComment(in string timerName, in string comment); */
00537 NS_IMETHODIMP nsTimelineService::MarkTimerWithComment(const char *timerName, const char *comment)
00538 {
00539     return NS_TimelineMarkTimer(timerName, comment);
00540 }
00541 
00542 /* void resetTimer (in string timerName); */
00543 NS_IMETHODIMP nsTimelineService::ResetTimer(const char *timerName)
00544 {
00545     return NS_TimelineResetTimer(timerName);
00546 }
00547 
00548 /* void indent (); */
00549 NS_IMETHODIMP nsTimelineService::Indent()
00550 {
00551     return NS_TimelineIndent();
00552 }
00553 
00554 /* void outdent (); */
00555 NS_IMETHODIMP nsTimelineService::Outdent()
00556 {
00557     return NS_TimelineOutdent();
00558 }
00559 
00560 /* void enter (in string text); */
00561 NS_IMETHODIMP nsTimelineService::Enter(const char *text)
00562 {
00563     return NS_TimelineEnter(text);
00564 }
00565 
00566 /* void leave (in string text); */
00567 NS_IMETHODIMP nsTimelineService::Leave(const char *text)
00568 {
00569     return NS_TimelineLeave(text);
00570 }
00571 
00572 #endif /* MOZ_TIMELINE */