Line data Source code
1 0 : /*
2 :
3 : OOJSEngineTimeManagement.h
4 :
5 :
6 : Copyright (C) 2010-2013 Jens Ayton
7 :
8 : Permission is hereby granted, free of charge, to any person obtaining a copy
9 : of this software and associated documentation files (the "Software"), to deal
10 : in the Software without restriction, including without limitation the rights
11 : to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
12 : copies of the Software, and to permit persons to whom the Software is
13 : furnished to do so, subject to the following conditions:
14 :
15 : The above copyright notice and this permission notice shall be included in all
16 : copies or substantial portions of the Software.
17 :
18 : THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
19 : IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
20 : FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
21 : AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
22 : LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
23 : OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
24 : SOFTWARE.
25 :
26 : */
27 :
28 : #include <jsdbgapi.h>
29 : #import "OOJSEngineTimeManagement.h"
30 : #import "OOProfilingStopwatch.h"
31 : #import "OOJSScript.h"
32 : #import "OOCollectionExtractors.h"
33 : #import "OOLoggingExtended.h"
34 :
35 : #if OOLITE_LINUX
36 : // Workaround for clang/glibc incompatibility.
37 : #define __block __glibc_block
38 : #endif
39 : #include <unistd.h>
40 :
41 : #if OOLITE_LINUX
42 : #undef __block
43 : #endif
44 :
45 :
46 : #if OO_DEBUG
47 : #define OOJS_DEBUG_LIMITER 1
48 : #else
49 0 : #define OOJS_DEBUG_LIMITER 0
50 : #endif
51 :
52 :
53 0 : static unsigned sLimiterStartDepth;
54 0 : static int sLimiterPauseDepth;
55 0 : static OOHighResTimeValue sLimiterStart;
56 0 : static OOHighResTimeValue sLimiterPauseStart;
57 0 : static double sLimiterTimeLimit;
58 :
59 :
60 : #if OOJS_DEBUG_LIMITER
61 : #define OOJS_TIME_LIMIT (0.2) // seconds
62 : #else
63 0 : #define OOJS_TIME_LIMIT (1) // seconds
64 : #endif
65 :
66 0 : static BOOL sStop;
67 :
68 : #ifndef NDEBUG
69 0 : static const char *sLastStartedFile;
70 0 : static unsigned sLastStartedLine;
71 0 : static const char *sLastStoppedFile;
72 0 : static unsigned sLastStoppedLine;
73 : #endif
74 :
75 :
76 : #if OOJS_PROFILE && defined(MOZ_TRACE_JSCALLS)
77 : static void FunctionCallback(JSFunction *function, JSScript *script, JSContext *context, int entering);
78 : #endif
79 :
80 :
81 : #ifndef NDEBUG
82 0 : void OOJSStartTimeLimiterWithTimeLimit_(OOTimeDelta limit, const char *file, unsigned line)
83 : #else
84 : void OOJSStartTimeLimiterWithTimeLimit(OOTimeDelta limit)
85 : #endif
86 : {
87 : #if OOJS_DEBUG_LIMITER
88 : OOLog(@"script.javaScript.timeLimit.debug",@"Limiter starting: %u => %u",sLimiterStartDepth,sLimiterStartDepth+1);
89 : #endif
90 : if (sLimiterStartDepth++ == 0)
91 : {
92 : if (limit <= 0.0) limit = OOJS_TIME_LIMIT;
93 : sLimiterTimeLimit = limit;
94 : sLimiterPauseDepth = 0;
95 :
96 : OODisposeHighResTime(sLimiterStart);
97 : sLimiterStart = OOGetHighResTime();
98 : }
99 :
100 : #ifndef NDEBUG
101 : sLastStartedFile = file;
102 : sLastStartedLine = line;
103 : #endif
104 : }
105 :
106 :
107 : #ifndef NDEBUG
108 0 : void OOJSStopTimeLimiter_(const char *file, unsigned line)
109 : #else
110 : void OOJSStopTimeLimiter(void)
111 : #endif
112 : {
113 : #ifndef NDEBUG
114 : if (sLimiterStartDepth == 0)
115 : {
116 : OOLog(@"bug.javaScript.limiterDepth", @"Attempt to stop JavaScript time limiter while it is already fully stopped. This is an internal bug, please report it. (Last start: %@:%u, last valid stop: %@:%u, this stop attempt: %@:%u.)", OOLogAbbreviatedFileName(sLastStartedFile), sLastStartedLine, OOLogAbbreviatedFileName(sLastStoppedFile), sLastStoppedLine, OOLogAbbreviatedFileName(file), line);
117 : return;
118 : }
119 :
120 : sLastStoppedFile = file;
121 : sLastStoppedLine = line;
122 :
123 : #if OOJS_DEBUG_LIMITER
124 : OOLog(@"script.javaScript.timeLimit.debug",@"Limiter ending: %u <= %u",sLimiterStartDepth-1,sLimiterStartDepth);
125 : #endif
126 :
127 : #endif
128 :
129 : if (--sLimiterStartDepth == 0) sLimiterTimeLimit = 0.0;
130 : }
131 :
132 :
133 0 : void OOJSPauseTimeLimiter(void)
134 : {
135 : if (sLimiterPauseDepth++ == 0)
136 : {
137 : OODisposeHighResTime(sLimiterPauseStart);
138 : sLimiterPauseStart = OOGetHighResTime();
139 : }
140 : }
141 :
142 :
143 0 : void OOJSResumeTimeLimiter(void)
144 : {
145 : if (--sLimiterPauseDepth == 0)
146 :
147 : {
148 : OOHighResTimeValue now = OOGetHighResTime();
149 : OOTimeDelta elapsed = OOHighResTimeDeltaInSeconds(sLimiterPauseStart, now);
150 : OODisposeHighResTime(now);
151 :
152 : sLimiterTimeLimit += elapsed;
153 : }
154 : }
155 :
156 :
157 : #ifndef NDEBUG
158 0 : OOHighResTimeValue OOJSCopyTimeLimiterNominalStartTime(void)
159 : {
160 : return sLimiterStart;
161 : }
162 :
163 :
164 0 : void OOJSResetTimeLimiter(void)
165 : {
166 : OODisposeHighResTime(sLimiterStart);
167 : sLimiterStart = OOGetHighResTime();
168 :
169 : sStop = NO;
170 : }
171 :
172 :
173 0 : OOTimeDelta OOJSGetTimeLimiterLimit(void)
174 : {
175 : return sLimiterTimeLimit;
176 : }
177 :
178 :
179 0 : void OOJSSetTimeLimiterLimit(OOTimeDelta limit)
180 : {
181 : sLimiterTimeLimit = limit;
182 : }
183 : #endif
184 :
185 :
186 : @implementation OOJavaScriptEngine (WatchdogTimer)
187 :
188 0 : - (void) watchdogTimerThread
189 : {
190 : for (;;)
191 : {
192 : #if OOLITE_WINDOWS
193 : Sleep(OOJS_TIME_LIMIT * 1000);
194 : #else
195 : usleep(OOJS_TIME_LIMIT * 1000000);
196 : #endif
197 :
198 : if (EXPECT(sLimiterStartDepth == 0 || sLimiterPauseDepth > 0)) continue; // Most of the time, a script isn't running.
199 :
200 : // Note: if you add logging here, you need a manual autorelease pool.
201 :
202 : OOHighResTimeValue now = OOGetHighResTime();
203 : OOTimeDelta elapsed = OOHighResTimeDeltaInSeconds(sLimiterStart, now);
204 : OODisposeHighResTime(now);
205 :
206 : if (EXPECT_NOT(elapsed > sLimiterTimeLimit))
207 : {
208 : sStop = YES;
209 : JS_TriggerAllOperationCallbacks(_runtime);
210 : }
211 : }
212 : }
213 :
214 : @end
215 :
216 :
217 0 : static JSBool OperationCallback(JSContext *context)
218 : {
219 : if (!sStop) return YES;
220 :
221 : JS_ClearPendingException(context);
222 :
223 : OOHighResTimeValue now = OOGetHighResTime();
224 : OOTimeDelta elapsed = OOHighResTimeDeltaInSeconds(sLimiterStart, now);
225 : OODisposeHighResTime(now);
226 :
227 : if (elapsed <= sLimiterTimeLimit) return YES;
228 :
229 : OOLogERR(@"script.javaScript.timeLimit", @"Script \"%@\" ran for %g seconds and has been terminated.", [[OOJSScript currentlyRunningScript] name], elapsed);
230 : #ifndef NDEBUG
231 : OOJSDumpStack(context);
232 : #endif
233 :
234 : // FIXME: we really should put something in the JS log here, but since that's implemented in JS there are complications.
235 :
236 : return NO;
237 : }
238 :
239 :
240 0 : static JSBool ContextCallback(JSContext *context, uintN contextOp)
241 : {
242 : if (contextOp == JSCONTEXT_NEW)
243 : {
244 : JS_SetOperationCallback(context, OperationCallback);
245 :
246 : #if OOJS_PROFILE && defined(MOZ_TRACE_JSCALLS)
247 : JS_SetFunctionCallback(context, (JSFunctionCallback)FunctionCallback); // Naughtily casts away consts, because const JSContexts and JSFunctions are useless.
248 : #endif
249 : }
250 : return YES;
251 : }
252 :
253 :
254 0 : void OOJSTimeManagementInit(OOJavaScriptEngine *engine, JSRuntime *runtime)
255 : {
256 : [NSThread detachNewThreadSelector:@selector(watchdogTimerThread)
257 : toTarget:engine
258 : withObject:nil];
259 :
260 : JS_SetContextCallback(runtime, ContextCallback);
261 : }
262 :
263 :
264 : #if OOJS_PROFILE
265 :
266 : #ifndef MOZ_TRACE_JSCALLS
267 : #warning Profiling is enabled, but MOZ_TRACE_JSCALLS is disabled, so only native functions will be profiled.
268 : #endif
269 :
270 0 : static BOOL sProfiling = NO;
271 0 : static BOOL sTracing = NO;
272 0 : static OOJSProfileStackFrame *sProfileStack = NULL;
273 0 : static NSMapTable *sProfileInfo;
274 0 : static double sProfilerOverhead;
275 0 : static double sProfilerTotalNativeTime;
276 0 : static double sProfilerTotalJavaScriptTime;
277 0 : static double sProfilerEntryTimeLimit;
278 0 : static OOHighResTimeValue sProfilerStartTime;
279 :
280 :
281 : @interface OOTimeProfile (Private)
282 :
283 0 : - (void) setTotalTime:(double)value;
284 0 : - (void) setNativeTime:(double)value;
285 : #ifdef MOZ_TRACE_JSCALLS
286 : - (void) setJavaScriptTime:(double)value;
287 : #endif
288 0 : - (void) setProfilerOverhead:(double)value;
289 0 : - (void) setExtensionTime:(double)value;
290 0 : - (void) setProfileEntries:(NSArray *)value;
291 :
292 0 : - (NSDictionary *) propertyListRepresentation;
293 :
294 : @end
295 :
296 :
297 : @interface OOTimeProfileEntry (Private)
298 :
299 0 : - (id) initWithCName:(const char *)name;
300 : #ifdef MOZ_TRACE_JSCALLS
301 : - (id) initWithJSFunction:(JSFunction *)function context:(JSContext *)context;
302 : #endif
303 :
304 0 : - (void) addSampleWithTotalTime:(OOTimeDelta)totalTime selfTime:(OOTimeDelta)selfTime;
305 :
306 0 : - (NSDictionary *) propertyListRepresentation;
307 :
308 : @end
309 :
310 :
311 0 : void OOJSBeginProfiling(BOOL trace)
312 : {
313 : assert(sProfiling == NO);
314 : sProfiling = YES;
315 : sTracing = trace;
316 : sProfileInfo = NSCreateMapTable(NSNonOwnedPointerMapKeyCallBacks, NSObjectMapValueCallBacks, 100);
317 : sProfilerOverhead = 0.0;
318 : sProfilerTotalNativeTime = 0.0;
319 : sProfilerTotalJavaScriptTime = 0.0;
320 : sProfilerEntryTimeLimit = OOJSGetTimeLimiterLimit();
321 :
322 : // This should be last for precision.
323 : sProfilerStartTime = OOGetHighResTime();
324 :
325 : if (trace)
326 : {
327 : OOLog(@"script.javaScript.trace", @"%@", @">>>> Beginning trace.");
328 : OOLogIndent();
329 : }
330 : }
331 :
332 :
333 0 : OOTimeProfile *OOJSEndProfiling(void)
334 : {
335 : // This should be at the top for precision.
336 : OOHighResTimeValue now = OOGetHighResTime();
337 : // Time limiter should be as close to outermost as practical.
338 : OOJSPauseTimeLimiter();
339 :
340 : assert(sProfiling && sProfileStack == NULL);
341 :
342 : sProfiling = NO;
343 :
344 : OOTimeProfile *result = [[OOTimeProfile alloc] init];
345 :
346 : [result setTotalTime:OOHighResTimeDeltaInSeconds(sProfilerStartTime, now)];
347 : [result setNativeTime:sProfilerTotalNativeTime];
348 : #ifdef MOZ_TRACE_JSCALLS
349 : [result setJavaScriptTime:sProfilerTotalJavaScriptTime];
350 : #endif
351 : [result setProfilerOverhead:sProfilerOverhead];
352 :
353 : double currentTimeLimit = OOJSGetTimeLimiterLimit();
354 : [result setExtensionTime:currentTimeLimit - sProfilerEntryTimeLimit];
355 :
356 : [result setProfileEntries:[NSAllMapTableValues(sProfileInfo) sortedArrayUsingSelector:@selector(compareBySelfTimeReverse:)]];
357 :
358 : if (sTracing)
359 : {
360 : OOLogOutdent();
361 : OOLog(@"script.javaScript.trace", @"%@", @"<<<< End of trace.");
362 : sTracing = NO;
363 : }
364 :
365 : // Clean up.
366 : NSFreeMapTable(sProfileInfo);
367 : OODisposeHighResTime(sProfilerStartTime);
368 :
369 : OODisposeHighResTime(now);
370 :
371 : OOJSResumeTimeLimiter();
372 : return result;
373 : }
374 :
375 :
376 0 : BOOL OOJSIsProfiling(void)
377 : {
378 : return sProfiling;
379 : }
380 :
381 0 : void OOJSBeginTracing(void);
382 0 : void OOJSEndTracing(void);
383 0 : BOOL OOJSIsTracing(void);
384 :
385 :
386 : static void UpdateProfileForFrame(OOHighResTimeValue now, OOJSProfileStackFrame *frame);
387 :
388 :
389 : #ifdef MOZ_TRACE_JSCALLS
390 : static void CleanUpJSFrame(OOJSProfileStackFrame *frame)
391 : {
392 : free(frame);
393 : }
394 :
395 :
396 : static void TraceEnterJSFunction(JSContext *context, JSFunction *function, OOTimeProfileEntry *profileEntry)
397 : {
398 : NSMutableString *name = [NSMutableString stringWithFormat:@"%@(", [profileEntry function]];
399 : BOOL isNative = JS_GetFunctionNative(context, function) != NULL;
400 : NSString *frameTag = nil;
401 : NSString *logMsgClass = nil;
402 :
403 : if (!isNative)
404 : {
405 : // Get stack frame and find arguments.
406 : JSStackFrame *frame = NULL;
407 : BOOL first = YES;
408 : jsval this;
409 : JSObject *scope;
410 : JSPropertyDescArray properties = { 0 , NULL };
411 : unsigned i;
412 :
413 : // Temporarily disable profiling as we'll call out to profiled functions to get value descriptions.
414 : sProfiling = NO;
415 :
416 : if (JS_FrameIterator(context, &frame) != NULL)
417 : {
418 : if (JS_IsConstructorFrame(context, frame))
419 : {
420 : [name insertString:@"new " atIndex:0];
421 : }
422 :
423 : if (JS_GetFrameThis(context, frame, &this))
424 : {
425 : [name appendFormat:@"this: %@", OOJSDescribeValue(context, this, YES)];
426 : first = NO;
427 : }
428 :
429 : scope = JS_GetFrameScopeChain(context, frame);
430 : if (scope != NULL && JS_GetPropertyDescArray(context, scope, &properties))
431 : {
432 : for (i = 0; i < properties.length; i++)
433 : {
434 : JSPropertyDesc *prop = &properties.array[i];
435 : if (prop->flags & JSPD_ARGUMENT)
436 : {
437 : if (!first) [name appendFormat:@", "];
438 : else first = NO;
439 :
440 : [name appendFormat:@"%@: %@", OOStringFromJSValueEvenIfNull(context, prop->id), OOJSDescribeValue(context, prop->value, YES)];
441 : }
442 : }
443 : }
444 : }
445 :
446 : sProfiling = YES;
447 :
448 : frameTag = @"JS"; // JavaScript
449 : logMsgClass = @"script.javaScript.trace.JS";
450 : }
451 : else
452 : {
453 : frameTag = @"NW"; // Native Wrapper
454 : logMsgClass = @"script.javaScript.trace.NW";
455 : }
456 :
457 : [name appendString:@")"];
458 : OOLog(logMsgClass, @">> %@ [%@]", name, frameTag);
459 : OOLogIndent();
460 : }
461 :
462 :
463 : static void FunctionCallback(JSFunction *function, JSScript *script, JSContext *context, int entering)
464 : {
465 : if (EXPECT(!sProfiling)) return;
466 : if (EXPECT_NOT(function == NULL)) return;
467 :
468 : // Ignore native functions. Ours get their own entries anyway, SpiderMonkey's are elided.
469 : if (!sTracing && JS_GetFunctionNative(context, function) != NULL) return;
470 :
471 : OOHighResTimeValue start = OOGetHighResTime();
472 :
473 : NSAutoreleasePool *pool = [NSAutoreleasePool new];
474 :
475 : if (entering > 0)
476 : {
477 : // Create profile entry up front so we can shove the JS function in it.
478 : OOTimeProfileEntry *entry = NSMapGet(sProfileInfo, function);
479 : if (entry == nil)
480 : {
481 : entry = [[OOTimeProfileEntry alloc] initWithJSFunction:function context:context];
482 : NSMapInsertKnownAbsent(sProfileInfo, function, entry);
483 : [entry release];
484 : }
485 :
486 : if (EXPECT_NOT(sTracing))
487 : {
488 : // We use EXPECT_NOT here because profiles are time-critical and traces are not.
489 : TraceEnterJSFunction(context, function, entry);
490 : }
491 :
492 : // Make a stack frame on the heap.
493 : OOJSProfileStackFrame *frame = malloc(sizeof(OOJSProfileStackFrame));
494 : assert(frame != NULL);
495 :
496 : *frame = (OOJSProfileStackFrame)
497 : {
498 : .back = sProfileStack,
499 : .key = function,
500 : .startTime = start,
501 : .subTime = 0.0,
502 : .total = &sProfilerTotalJavaScriptTime,
503 : .cleanup = CleanUpJSFrame
504 : };
505 :
506 : sProfileStack = frame;
507 : }
508 : else
509 : {
510 : // Exiting.
511 : assert(sProfileStack != NULL && sProfileStack->cleanup == CleanUpJSFrame);
512 :
513 : UpdateProfileForFrame(start, sProfileStack);
514 : }
515 :
516 : [pool release];
517 :
518 : OOHighResTimeValue end = OOGetHighResTime();
519 : double currentOverhead = OOHighResTimeDeltaInSeconds(start, end);
520 : sProfilerOverhead += currentOverhead;
521 : OODisposeHighResTime(start);
522 : OODisposeHighResTime(end);
523 : }
524 : #endif
525 :
526 :
527 0 : void OOJSProfileEnter(OOJSProfileStackFrame *frame, const char *function)
528 : {
529 : if (EXPECT(!sProfiling)) return;
530 : if (EXPECT_NOT(sTracing))
531 : {
532 : // We use EXPECT_NOT here because profiles are time-critical and traces are not.
533 : OOLog(@"script.javaScript.trace.ON", @">> %s [ON]", function);
534 : OOLogIndent();
535 : }
536 :
537 : *frame = (OOJSProfileStackFrame)
538 : {
539 : .back = sProfileStack,
540 : .key = function,
541 : .function = function,
542 : .startTime = OOGetHighResTime(),
543 : .total = &sProfilerTotalNativeTime
544 : };
545 : sProfileStack = frame;
546 : }
547 :
548 :
549 0 : void OOJSProfileExit(OOJSProfileStackFrame *frame)
550 : {
551 : if (EXPECT(!sProfiling)) return;
552 :
553 : OOHighResTimeValue now = OOGetHighResTime();
554 : NSAutoreleasePool *pool = [NSAutoreleasePool new];
555 : BOOL done = NO;
556 :
557 : /*
558 : It's possible there could be JavaScript frames on top of this frame if
559 : a JS native returned false. Or possibly not. The semantics of
560 : JS_SetFunctionCallback() aren't specified in detail.
561 : -- Ahruman 2011-01-16
562 : */
563 : for (;;)
564 : {
565 : assert(sProfileStack != NULL);
566 :
567 : done = (sProfileStack == frame);
568 : UpdateProfileForFrame(now, sProfileStack);
569 : if (EXPECT(done)) break;
570 : }
571 :
572 : [pool release];
573 :
574 : OODisposeHighResTime(frame->startTime);
575 :
576 : OOHighResTimeValue end = OOGetHighResTime();
577 : double currentOverhead = OOHighResTimeDeltaInSeconds(now, end);
578 : sProfilerOverhead += currentOverhead;
579 :
580 : /* Equivalent of pausing/resuming time limiter, except that it guarantees
581 : excluded time will match profiler overhead if there are no other
582 : pauses happening.
583 : */
584 : if (sLimiterPauseDepth == 0) sLimiterTimeLimit += currentOverhead;
585 :
586 : OODisposeHighResTime(now);
587 : OODisposeHighResTime(end);
588 : }
589 :
590 :
591 0 : static void UpdateProfileForFrame(OOHighResTimeValue now, OOJSProfileStackFrame *frame)
592 : {
593 : sProfileStack = frame->back;
594 :
595 : OOTimeProfileEntry *entry = NSMapGet(sProfileInfo, frame->key);
596 : if (entry == nil)
597 : {
598 : entry = [[OOTimeProfileEntry alloc] initWithCName:frame->function];
599 : NSMapInsertKnownAbsent(sProfileInfo, frame->key, entry);
600 : [entry release];
601 : }
602 :
603 : OOTimeDelta time = OOHighResTimeDeltaInSeconds(frame->startTime, now);
604 : OOTimeDelta selfTime = time - frame->subTime;
605 : [entry addSampleWithTotalTime:time selfTime:selfTime];
606 :
607 : *(frame->total) += selfTime;
608 : if (sProfileStack != NULL) sProfileStack->subTime += time;
609 :
610 : if (frame->cleanup != NULL) frame->cleanup(frame);
611 :
612 : if (EXPECT_NOT(sTracing)) OOLogOutdent();
613 : }
614 :
615 :
616 : @implementation OOTimeProfile
617 :
618 0 : - (void) dealloc
619 : {
620 : DESTROY(_profileEntries);
621 :
622 : [super dealloc];
623 : }
624 :
625 :
626 0 : - (NSString *) description
627 : {
628 : double totalTime = [self totalTime];
629 :
630 : NSMutableString *result = [NSMutableString stringWithFormat:
631 : @"Total time: %g ms\n"
632 : "JavaScript: %g ms, native: %g ms\n"
633 : "Counted towards limit: %g ms, excluded: %g ms\n"
634 : "Profiler overhead: %g ms",
635 : totalTime * 1000.0,
636 : [self javaScriptTime] * 1000.0, [self nativeTime] * 1000.0,
637 : [self nonExtensionTime] * 1000.0, [self extensionTime] * 1000.0,
638 : [self profilerOverhead] * 1000.0];
639 :
640 : NSArray *profileEntries = [self profileEntries];
641 : NSUInteger i, count = [profileEntries count];
642 : if (count != 0)
643 : {
644 : [result appendString:@"\n NAME T COUNT TOTAL SELF TOTAL% SELF% SELFMAX"];
645 : for (i = 0; i < count; i++)
646 : {
647 : // [result appendFormat:@"\n %@", [_profileEntries objectAtIndex:i]];
648 :
649 : OOTimeProfileEntry *entry = [profileEntries objectAtIndex:i];
650 :
651 : double totalPc = [entry totalTimeSum] * 100.0 / totalTime;
652 : double selfPc = [entry selfTimeSum] * 100.0 / totalTime;
653 :
654 : [result appendFormat:@"\n%60s %c%7lu %8.2f %8.2f %5.1f %5.1f %8.2f",
655 : [[entry function] UTF8String],
656 : [entry isJavaScriptFrame] ? 'J' : 'N',
657 : (unsigned long)[entry hitCount], [entry totalTimeSum] * 1000.0, [entry selfTimeSum] * 1000.0, totalPc, selfPc, [entry selfTimeMax] * 1000.0];
658 : }
659 : }
660 :
661 : return result;
662 : }
663 :
664 :
665 : - (double) totalTime
666 : {
667 : return _totalTime;
668 : }
669 :
670 :
671 0 : - (void) setTotalTime:(double)value
672 : {
673 : _totalTime = value;
674 : }
675 :
676 :
677 : - (double) javaScriptTime
678 : {
679 : #ifdef MOZ_TRACE_JSCALLS
680 : return _javaScriptTime;
681 : #else
682 : return _totalTime - _nativeTime;
683 : #endif
684 : }
685 :
686 :
687 : #ifdef MOZ_TRACE_JSCALLS
688 : - (void) setJavaScriptTime:(double)value
689 : {
690 : _javaScriptTime = value;
691 : }
692 : #endif
693 :
694 :
695 : - (double) nativeTime
696 : {
697 : return _nativeTime;
698 : }
699 :
700 :
701 0 : - (void) setNativeTime:(double)value
702 : {
703 : _nativeTime = value;
704 : }
705 :
706 :
707 : - (double) extensionTime
708 : {
709 : return _extensionTime;
710 : }
711 :
712 :
713 0 : - (void) setExtensionTime:(double)value
714 : {
715 : _extensionTime = value;
716 : }
717 :
718 :
719 : - (double) nonExtensionTime
720 : {
721 : return _totalTime - _extensionTime;
722 : }
723 :
724 :
725 : - (double) profilerOverhead
726 : {
727 : return _profilerOverhead;
728 : }
729 :
730 :
731 0 : - (void) setProfilerOverhead:(double)value
732 : {
733 : _profilerOverhead = value;
734 : }
735 :
736 :
737 : - (NSArray *) profileEntries
738 : {
739 : return _profileEntries;
740 : }
741 :
742 :
743 0 : - (void) setProfileEntries:(NSArray *)value
744 : {
745 : if (_profileEntries != value)
746 : {
747 : [_profileEntries release];
748 : _profileEntries = [value retain];
749 : }
750 : }
751 :
752 :
753 0 : - (jsval) oo_jsValueInContext:(JSContext *)context
754 : {
755 : return OOJSValueFromNativeObject(context, [self propertyListRepresentation]);
756 : }
757 :
758 :
759 0 : - (NSDictionary *) propertyListRepresentation
760 : {
761 : NSArray *profileEntries = [self profileEntries];
762 : NSMutableArray *convertedEntries = [NSMutableArray arrayWithCapacity:[profileEntries count]];
763 : NSEnumerator *entryEnum = nil;
764 : OOTimeProfileEntry *entry = nil;
765 : for (entryEnum = [profileEntries objectEnumerator]; (entry = [entryEnum nextObject]); )
766 : {
767 : [convertedEntries addObject:[entry propertyListRepresentation]];
768 : }
769 :
770 : return [NSDictionary dictionaryWithObjectsAndKeys:
771 : profileEntries, @"profiles",
772 : [NSNumber numberWithDouble:[self totalTime]], @"totalTime",
773 : [NSNumber numberWithDouble:[self javaScriptTime]], @"javaScriptTime",
774 : [NSNumber numberWithDouble:[self nativeTime]], @"nativeTime",
775 : [NSNumber numberWithDouble:[self extensionTime]], @"extensionTime",
776 : [NSNumber numberWithDouble:[self nonExtensionTime]], @"nonExtensionTime",
777 : [NSNumber numberWithDouble:[self profilerOverhead]], @"profilerOverhead",
778 : nil];
779 : }
780 :
781 : @end
782 :
783 :
784 : @implementation OOTimeProfileEntry
785 :
786 0 : - (id) initWithCName:(const char *)name
787 : {
788 : NSAssert(sProfiling, @"Can't create profile entries while not profiling.");
789 :
790 : if ((self = [super init]))
791 : {
792 : if (name != NULL)
793 : {
794 : _function = [[NSString stringWithUTF8String:name] retain];
795 : }
796 : }
797 :
798 : return self;
799 : }
800 :
801 :
802 : #if MOZ_TRACE_JSCALLS
803 : - (id) initWithJSFunction:(JSFunction *)function context:(JSContext *)context
804 : {
805 : if ((self = [self initWithCName:NULL]))
806 : {
807 : // Temporarily disable profiling so we don't profile the profiler while it's profiling the profilee.
808 : sProfiling = NO;
809 : _jsFunction = function;
810 :
811 : NSString *funcName = nil;
812 : JSString *jsName = JS_GetFunctionId(_jsFunction);
813 : if (jsName != NULL) funcName = [OOStringFromJSString(context, jsName) retain];
814 : else funcName = @"<anonymous>";
815 :
816 : // If it's a non-native function, get its source location.
817 : NSString *location = nil;
818 : if (JS_GetFunctionNative(context, function) == NULL)
819 : {
820 : JSStackFrame *frame = NULL;
821 : if (JS_FrameIterator(context, &frame) != NULL)
822 : {
823 : location = OOJSDescribeLocation(context, frame);
824 : }
825 : }
826 :
827 : if (location != nil)
828 : {
829 : _function = [[NSString alloc] initWithFormat:@"(%@) %@", location, funcName];
830 : }
831 : else _function = [funcName retain];
832 :
833 : sProfiling = YES;
834 : }
835 :
836 : return self;
837 : }
838 : #endif
839 :
840 :
841 0 : - (void) dealloc
842 : {
843 : DESTROY(_function);
844 :
845 : [super dealloc];
846 : }
847 :
848 :
849 0 : - (void) addSampleWithTotalTime:(OOTimeDelta)totalTime selfTime:(OOTimeDelta)selfTime
850 : {
851 : _hitCount++;
852 : _totalTimeSum += totalTime;
853 : _selfTimeSum += selfTime;
854 : _totalTimeMax = fmax(_totalTimeMax, totalTime);
855 : _selfTimeMax = fmax(_selfTimeMax, selfTime);
856 : }
857 :
858 :
859 : - (NSString *) description
860 : {
861 : if (_hitCount == 0) return [NSString stringWithFormat:@"%@: --", _function];
862 :
863 : // Convert everything to milliseconds.
864 : float totalTimeSum = _totalTimeSum * 1000.0;
865 : float selfTimeSum = _selfTimeSum * 1000.0;
866 : float totalTimeMax = _totalTimeMax * 1000.0;
867 : float selfTimeMax = _selfTimeMax * 1000.0;
868 :
869 : if (totalTimeSum == selfTimeSum && totalTimeMax == selfTimeMax)
870 : {
871 : if (_hitCount == 1)
872 : {
873 : return [NSString stringWithFormat:@"%@: 1 time, %g ms", _function, totalTimeSum];
874 : }
875 : else
876 : {
877 : return [NSString stringWithFormat:@"%@: %lu times, total %g ms, avg %g ms, max %g ms", _function, _hitCount, totalTimeSum, totalTimeSum / _hitCount, totalTimeMax];
878 : }
879 : }
880 : else
881 : {
882 : if (_hitCount == 1)
883 : {
884 : return [NSString stringWithFormat:@"%@: 1 time, %g ms (self %g ms)", _function, totalTimeSum, selfTimeSum];
885 : }
886 : else
887 : {
888 : return [NSString stringWithFormat:@"%@: %lu times, total %g ms (self %g ms), avg %g ms (self %g ms), max %g ms, max self %g ms", _function, _hitCount, totalTimeSum, selfTimeSum, totalTimeSum / _hitCount, selfTimeSum / _hitCount, totalTimeMax, selfTimeMax];
889 : }
890 : }
891 : }
892 :
893 :
894 : - (NSString *) function
895 : {
896 : return _function;
897 : }
898 :
899 :
900 : - (NSUInteger) hitCount
901 : {
902 : return _hitCount;
903 : }
904 :
905 :
906 : - (double) totalTimeSum
907 : {
908 : return _totalTimeSum;
909 : }
910 :
911 :
912 : - (double) selfTimeSum
913 : {
914 : return _selfTimeSum;
915 : }
916 :
917 :
918 : - (double) totalTimeAverage
919 : {
920 : return _hitCount ? (_totalTimeSum / _hitCount) : 0.0;
921 : }
922 :
923 :
924 : - (double) selfTimeAverage
925 : {
926 : return _hitCount ? (_selfTimeSum / _hitCount) : 0.0;
927 : }
928 :
929 :
930 : - (double) totalTimeMax
931 : {
932 : return _totalTimeMax;
933 : }
934 :
935 :
936 : - (double) selfTimeMax
937 : {
938 : return _selfTimeMax;
939 : }
940 :
941 :
942 : - (BOOL) isJavaScriptFrame
943 : {
944 : #if MOZ_TRACE_JSCALLS
945 : return _jsFunction != NULL;
946 : #else
947 : return NO;
948 : #endif
949 : }
950 :
951 :
952 : - (NSComparisonResult) compareByTotalTime:(OOTimeProfileEntry *)other
953 : {
954 : return -[self compareByTotalTimeReverse:other];
955 : }
956 :
957 :
958 : - (NSComparisonResult) compareByTotalTimeReverse:(OOTimeProfileEntry *)other
959 : {
960 : double selfTotal = [self totalTimeSum];
961 : double otherTotal = [other totalTimeSum];
962 :
963 : if (selfTotal < otherTotal) return NSOrderedDescending;
964 : if (selfTotal > otherTotal) return NSOrderedAscending;
965 : return NSOrderedSame;
966 : }
967 :
968 :
969 : - (NSComparisonResult) compareBySelfTime:(OOTimeProfileEntry *)other
970 : {
971 : return -[self compareBySelfTimeReverse:other];
972 : }
973 :
974 :
975 : - (NSComparisonResult) compareBySelfTimeReverse:(OOTimeProfileEntry *)other
976 : {
977 : double selfTotal = [self selfTimeSum];
978 : double otherTotal = [other selfTimeSum];
979 :
980 : if (selfTotal < otherTotal) return NSOrderedDescending;
981 : if (selfTotal > otherTotal) return NSOrderedAscending;
982 : return NSOrderedSame;
983 : }
984 :
985 :
986 0 : - (jsval) oo_jsValueInContext:(JSContext *)context
987 : {
988 : return OOJSValueFromNativeObject(context, [self propertyListRepresentation]);
989 : }
990 :
991 :
992 0 : - (NSDictionary *) propertyListRepresentation
993 : {
994 : return [NSDictionary dictionaryWithObjectsAndKeys:
995 : _function, @"name",
996 : [NSNumber numberWithUnsignedInteger:[self hitCount]], @"hitCount",
997 : [NSNumber numberWithDouble:[self totalTimeSum]], @"totalTimeSum",
998 : [NSNumber numberWithDouble:[self selfTimeSum]], @"selfTimeSum",
999 : [NSNumber numberWithDouble:[self totalTimeAverage]], @"totalTimeAverage",
1000 : [NSNumber numberWithDouble:[self selfTimeAverage]], @"selfTimeAverage",
1001 : [NSNumber numberWithDouble:[self totalTimeMax]], @"totalTimeMax",
1002 : [NSNumber numberWithDouble:[self selfTimeMax]], @"selfTimeMax",
1003 : [NSNumber numberWithBool:[self isJavaScriptFrame]], @"isJavaScriptFrame",
1004 : nil];
1005 : }
1006 :
1007 : @end
1008 :
1009 : #endif
|
