1 // Copyright Ferdinand Majerech 2014. 2 // Distributed under the Boost Software License, Version 1.0. 3 // (See accompanying file LICENSE_1_0.txt or copy at 4 // http://www.boost.org/LICENSE_1_0.txt) 5 6 7 /** Ranges used to process and analyze profiling results. 8 * 9 * Code examples can be found below. 10 */ 11 module tharsis.prof.ranges; 12 13 import std.algorithm; 14 import std.array; 15 import std.range; 16 import std.traits; 17 18 import tharsis.prof.event; 19 import tharsis.prof.profiler; 20 21 public import tharsis.prof.accumulatedzonerange; 22 23 24 /// Data about a zone generated by ZoneRange. 25 struct ZoneData 26 { 27 /// ID of this zone. 28 uint id; 29 /// ID of the parent zone. 0 if the zone has no parent. 30 uint parentID; 31 /// Nesting level of the zone. 1 is top-level, 2 children of top-level, etc. 0 is invalid. 32 ushort nestLevel = 0; 33 /// Start time of the zone since recording started in hectonanoseconds. 34 ulong startTime; 35 /// Duration of the zone in hectonanoseconds. 36 ulong duration; 37 /// Zone _info (passed to the Zone constructor); e.g. it's name. 38 const(char)[] info; 39 40 /// Get the end time of the zone since recording started in hectonanoseconds. 41 ulong endTime() @safe pure nothrow const @nogc { return startTime + duration; } 42 } 43 44 45 /** Construct a ZoneRange directly from profile data. 46 * 47 * Params: 48 * 49 * profileData = Profile data recorded by a Profiler. Note that modifying or concatenating 50 * raw profile data is unsafe unless you know what you're doing. 51 * 52 * Example: 53 * -------------------- 54 * // Profiler profiler; 55 * 56 * // Create a ZoneRange from profile data with UFCS syntax. 57 * auto zones = profiler.profileData.zoneRange; 58 * foreach(zone; zones) 59 * { 60 * import std.stdio; 61 * writeln(zone); 62 * } 63 * -------------------- 64 */ 65 ZoneRange!EventRange zoneRange(const(ubyte)[] profileData) @safe pure nothrow @nogc 66 { 67 return ZoneRange!EventRange(profileData.eventRange); 68 } 69 70 // Maximum stack depth of the zone stack. 640 nesting levels should be enough for everyone. 71 package enum maxStackDepth = 640; 72 73 // Information about a parent zone in ZoneRange's zone stack. 74 package struct ZoneInfo 75 { 76 // Zone ID of the zone (to set parentID). 77 uint id; 78 // Start time of the zone since the recording started. 79 ulong startTime; 80 // Info string about the zone as passed to the Zone constructor. 81 const(char)[] info; 82 } 83 84 /** Creates ZoneData from a parent zone info stack and end time. 85 * 86 * The ZInfo type must have all ZoneInfo members (e.g. by wrapping ZoneInfo with alias this). 87 */ 88 package ZoneData buildZoneData(ZInfo)(const(ZInfo)[] stack, ulong endTime) 89 @safe pure nothrow @nogc 90 { 91 const info = stack.back; 92 ZoneData result; 93 result.id = info.id; 94 result.parentID = stack.length == 1 ? 0 : stack[$ - 2].id; 95 // stack.length, not stack.length - 1. Top-level zones have a stack level of 1. 96 result.nestLevel = cast(ushort)stack.length; 97 result.startTime = info.startTime; 98 result.duration = endTime - result.startTime; 99 result.info = info.info; 100 return result; 101 } 102 103 104 /** Variable together with its name and time of the variable event. 105 * 106 * Variable Event itself only stores variable type/value. It is followed by an info event 107 * specifying variable name. VariableRange can be used to get NamedVariables from 108 * profiling data. 109 */ 110 struct NamedVariable 111 { 112 /// Variable name. 113 const(char)[] name; 114 /// Time when the variable event has occured. 115 ulong time; 116 117 /// Variable type and value (members directly accessible with alias this). 118 Variable variable; 119 alias variable this; 120 } 121 122 /** Construct a VariableRange directly from profile data. 123 * 124 * Params: 125 * 126 * profileData = Profile data recorded by a Profiler. Note that modifying or concatenating 127 * raw profile data is unsafe unless you know what you're doing. 128 * 129 * Example: 130 * -------------------- 131 * // Profiler profiler; 132 * 133 * // Create a VariableRange from profile data with UFCS syntax. 134 * auto variables = profiler.profileData.variableRange; 135 * foreach(variable; variables) 136 * { 137 * import std.stdio; 138 * writeln(variable); 139 * } 140 * -------------------- 141 */ 142 VariableRange!EventRange variableRange(const(ubyte)[] profileData) @safe pure nothrow @nogc 143 { 144 return VariableRange!EventRange(profileData.eventRange); 145 } 146 147 /** Light-weight range that iterates over variables in profile data. 148 * 149 * Constructed from a ForwardRange of Event (e.g. EventRange or a std.algorithm wrapper 150 * around an EventRange). Can also be constructed from raw profile data using 151 * variableRange(). 152 * 153 * 154 * ForwardRange of NamedVariable ordered by $(I time). Doesn't allocate any heap memory. 155 * 156 * If profile data is incomplete (e.g. because the Profiler ran out of assigned memory in 157 * the middle of profiling), the last recorded variable may be ignored. 158 * 159 * Ignores any variable events not followed by an info event (this may happen e.g. if a 160 * Profiler runs out of memory when recording a variable event). 161 */ 162 struct VariableRange(ERange) 163 { 164 static assert(isForwardRange!ERange && is(Unqual!(ElementType!ERange) == Event), 165 "ERange parameter of VariableRange must be a forward range of Event, " 166 " e.g. EventRange"); 167 private: 168 // Range to read profiling events from. 169 ERange events_; 170 171 // Time of the last encountered variable event. ulong.max means "uninitialized value". 172 ulong variableTime_ = ulong.max; 173 // Info (name) of the last encontered variable. 174 const(char)[] variableInfo_; 175 // Value of the last encountered variable. 176 Variable variable_; 177 178 static assert(isForwardRange!VariableRange, "VariableRange must be a forward range"); 179 static assert(is(Unqual!(ElementType!VariableRange) == NamedVariable), 180 "VariableRange must be a range of NamedVariable"); 181 182 public: 183 /** Construct a VariableRange processing events from a range of Events. 184 * 185 * Params: 186 * 187 * events = The event range to read from. VariableRange will create a (shallow) copy, 188 * and will not consume this range. 189 */ 190 this(ERange events) @safe pure nothrow @nogc 191 { 192 events_ = events.save; 193 getToNextVariableEnd(); 194 } 195 196 /// Get the current variable. 197 NamedVariable front() @safe pure nothrow @nogc 198 { 199 assert(!empty, "Can't get front of an empty range"); 200 201 // Handling the case where we've run out of events_, but haven't popped the last 202 // variable off the front yet. 203 if(events_.empty) 204 { 205 assert(variableTime_ != ulong.max, "Non-empty VariableRange with empty " 206 "events_ must have non-default variableTime_"); 207 return NamedVariable(variableInfo_, variableTime_, variable_); 208 } 209 210 return NamedVariable(variableInfo_, variableTime_, variable_); 211 } 212 213 /// Go to the next variable. 214 void popFront() @safe pure nothrow @nogc 215 { 216 assert(!empty, "Can't pop front of an empty range"); 217 // Pop the Info event reached by the last getToNextVariableEnd() call. 218 assert(events_.front.id == EventID.Info, "Current event is not expected Info"); 219 events_.popFront(); 220 getToNextVariableEnd(); 221 } 222 223 /// Are there no more variables? 224 bool empty() @safe pure nothrow @nogc { return events_.empty; } 225 226 // Must be a property, isForwardRange won't work otherwise. 227 /// Get a copy of the range in its current state. 228 @property VariableRange save() @safe pure nothrow const @nogc { return this; } 229 230 private: 231 /* Processes events_ until an Info event after a VariableEvent, or the end of events_, 232 * is reached. 233 * 234 * If we already are at such an Info event, stays there. 235 * 236 * Initializes variable_ with any read variable event, but only exits after reaching 237 * an info event; any variable event not followed by an info event will be ignored. 238 */ 239 void getToNextVariableEnd() @safe pure nothrow @nogc 240 { 241 for(; !events_.empty; events_.popFront()) 242 { 243 const event = events_.front; 244 245 with(EventID) final switch(event.id) 246 { 247 case Checkpoint, ZoneStart, ZoneEnd: break; 248 case Variable: 249 variable_ = event.var; 250 variableTime_ = event.time; 251 variableInfo_ = null; 252 break; 253 // If an info event has the same start time as the last variable, it's 254 // info about that variable. 255 case Info: 256 // The variableInfo_ == null check is necessary because we want 257 // the *first* info event that follows a variable event (there may be 258 // more info events with the same startTime). 259 if(variableInfo_ == null && event.time == variableTime_) 260 { 261 variableInfo_ = event.info; 262 return; 263 } 264 break; 265 } 266 } 267 } 268 } 269 /// 270 unittest 271 { 272 // Print names and values of all recorded variables (once for each time they were 273 // recorded). 274 275 import tharsis.prof; 276 277 auto storage = new ubyte[Profiler.maxEventBytes + 2048]; 278 auto profiler = new Profiler(storage); 279 280 // Simulate 16 'frames' 281 foreach(frame; 0 .. 16) 282 { 283 Zone topLevel = Zone(profiler, "frame"); 284 285 topLevel.variableEvent!"frame"(cast(uint)frame); 286 topLevel.variableEvent!"frame2"(cast(uint)frame); 287 // Simulate frame overhead. Replace this with your frame code. 288 { 289 import std.random; 290 const random = uniform(1.0f, 5.0f); 291 import std.stdio; 292 writeln(random); 293 topLevel.variableEvent!"somethingRandom"(random); 294 Zone nested1 = Zone(profiler, "frameStart"); 295 foreach(i; 0 .. 1000) { continue; } 296 } 297 { 298 Zone nested2 = Zone(profiler, "frameCore"); 299 foreach(i; 0 .. 10000) { continue; } 300 } 301 } 302 303 import std.algorithm; 304 305 size_t i = 0; 306 ulong lastTime = 0; 307 // Write duration of each instance of the "frameCore" zone. 308 foreach(var; profiler.profileData.variableRange) 309 { 310 assert(var.time >= lastTime); 311 lastTime = var.time; 312 313 if(i % 3 == 0) { assert(var.name == "frame"); } 314 else if(i % 3 == 1) { assert(var.name == "frame2"); } 315 else if(i % 3 == 2) { assert(var.name == "somethingRandom"); } 316 317 import std.stdio; 318 writefln("%s: %s == %s", var.time, var.name, var.variable); 319 ++i; 320 } 321 } 322 323 /** Light-weight range that iterates over zones in profile data. 324 * 325 * Constructed from a ForwardRange of Event (e.g. EventRange or a std.algorithm wrapper 326 * around an EventRange). Can also be constructed from raw profile data using eventRange(). 327 * 328 * 329 * ForwardRange of ZoneData ordered by $(I end time). 330 * Doesn't allocate any heap memory. 331 * 332 * 333 * If profile data is incomplete (e.g. because the Profiler ran out of assigned memory in 334 * the middle of profiling), zones that don't have zone end events will be automatically 335 * ended at the time of the last recorded event. 336 * 337 * Note: 338 * 339 * ZoneRange only supports zone nesting up to ZoneRange.zoneStack nesting levels 340 * (currently this is 640, which should be enough for everyone, may be increased in future). 341 */ 342 struct ZoneRange(ERange) 343 { 344 static assert(isForwardRange!ERange && is(Unqual!(ElementType!ERange) == Event), 345 "ERange parameter of ZoneRange must be a forward range of Event, e.g. " 346 "EventRange"); 347 348 private: 349 // Range to read profiling events from. 350 ERange events_; 351 352 // Stack of ZoneInfo describing the current zone and all its parents. 353 // 354 // The current zone can be found at zoneStack_[zoneStackDepth_ - 1], its parent 355 // at zoneStack_[zoneStackDepth_ - 2], etc. 356 ZoneInfo[maxStackDepth] zoneStack_; 357 358 // Depth of the zone stack at the moment. 359 size_t zoneStackDepth_ = 0; 360 361 // ID of the next zone. 362 uint nextID_ = 1; 363 364 // startTime of the last processed event. 365 ulong lastEventTime_ = 0; 366 367 static assert(isForwardRange!ZoneRange, "ZoneRange must be a forward range"); 368 static assert(is(Unqual!(ElementType!ZoneRange) == ZoneData), 369 "ZoneRange must be a range of ZoneData"); 370 371 public: 372 /** Construct a ZoneRange processing events from a range of Events (e.g. EventRange). 373 * 374 * Params: 375 * 376 * events = The event range to read from. ZoneRange will create a (shallow) copy, 377 * and will not consume this range. 378 */ 379 this(ERange events) @safe pure nothrow @nogc { events_ = events.save; } 380 381 /// Get the current zone. 382 ZoneData front() @safe pure nothrow @nogc 383 { 384 assert(!empty, "Can't get front of an empty range"); 385 386 // Since profiling can stop at any moment due to running out of assigned memory, 387 // we need to handle the space where we don't have zone end events for all zones. 388 if(events_.empty) 389 { 390 assert(zoneStackDepth_ > 0, "if events_ are empty, something must be in the stack"); 391 return buildZoneData(zoneStack_[0 .. zoneStackDepth_], lastEventTime_); 392 } 393 394 getToNextZoneEnd(); 395 // getToNextZoneEnd can only consume all events if we're empty (no more ZoneEnd 396 // - if there was a ZoneEnd, getToNextZoneEnd() would stop at the ZoneEnd without 397 // making events_ empty. 398 // However, the above assert checks that we're not empty, and the above if() 399 // handles the case where events_ is empty before getToNextZoneEnd(). 400 // So, events_ must not be empty here. 401 assert(!events_.empty, "ZoneRange empty despite assert at the top of function"); 402 assert(events_.front.id == EventID.ZoneEnd, "getToNextZoneEnd got to a non-end event"); 403 return buildZoneData(zoneStack_[0 .. zoneStackDepth_], lastEventTime_); 404 } 405 406 /// Go to the next zone. 407 void popFront() @safe pure nothrow @nogc 408 { 409 assert(!empty, "Can't pop front of an empty range"); 410 411 // Since profiling can stop at any moment due to running out of assigned memory, 412 // we need to handle the case where we don't have zone end events for all zones. 413 if(events_.empty) 414 { 415 assert(zoneStackDepth_ > 0, 416 "non-empty ZoneRange with empty events_ must have non-zero zoneStackDepth_"); 417 } 418 // Pop the ZoneEnd event reached by getToNextZoneEnd() in last range operation. 419 else if(events_.front.id == EventID.ZoneEnd) 420 { 421 events_.popFront(); 422 } 423 --zoneStackDepth_; 424 } 425 426 /// Are there no more zones? 427 bool empty() @safe pure nothrow @nogc 428 { 429 // Must call this; otherwise, if there are no zone events in the entire range, 430 // this would still return true as long as events_ is empty. 431 getToNextZoneEnd(); 432 return events_.empty && zoneStackDepth_ == 0; 433 } 434 435 // Must be a property, isForwardRange won't work otherwise. 436 /// Get a copy of the range in its current state. 437 @property ZoneRange save() @safe pure nothrow const @nogc { return this; } 438 439 private: 440 /* Processes events_ until a ZoneEnd event or the end of events_ is reached. 441 * 442 * If we already are at such an ZoneEnd event, stays there. 443 * 444 * Adds any ZoneStart events to the stack. 445 */ 446 void getToNextZoneEnd() @safe pure nothrow @nogc 447 { 448 for(; !events_.empty; events_.popFront()) 449 { 450 const event = events_.front; 451 lastEventTime_ = event.time; 452 453 with(EventID) final switch(event.id) 454 { 455 case Checkpoint: break; 456 case Variable: break; 457 case ZoneStart: 458 assert(zoneStackDepth_ < maxStackDepth, 459 "Zone nesting too deep; zone stack overflow."); 460 zoneStack_[zoneStackDepth_++] = ZoneInfo(nextID_++, lastEventTime_, null); 461 break; 462 case ZoneEnd: return; 463 // If an info event has the same start time as the current zone, it's info 464 // about the current zone. 465 case Info: 466 auto curZone = &zoneStack_[zoneStackDepth_ - 1]; 467 // The curZone.info == null check is necessary because we want the 468 // *first* info event that follows a zone event (there may be more 469 // info events with the same startTime, e.g. after a variable event 470 // following the zone start event) 471 if(curZone.info == null && event.time == curZone.startTime) 472 { 473 curZone.info = event.info; 474 } 475 break; 476 } 477 } 478 } 479 } 480 /// 481 unittest 482 { 483 // Filter zones based on the info string. Useful to determine durations of only 484 // certain zones. 485 486 import tharsis.prof; 487 488 auto storage = new ubyte[Profiler.maxEventBytes + 2048]; 489 auto profiler = new Profiler(storage); 490 491 // Simulate 16 'frames' 492 foreach(frame; 0 .. 16) 493 { 494 Zone topLevel = Zone(profiler, "frame"); 495 496 // Simulate frame overhead. Replace this with your frame code. 497 { 498 Zone nested1 = Zone(profiler, "frameStart"); 499 foreach(i; 0 .. 1000) { continue; } 500 } 501 { 502 Zone nested2 = Zone(profiler, "frameCore"); 503 foreach(i; 0 .. 10000) { continue; } 504 } 505 } 506 507 import std.algorithm; 508 // Write duration of each instance of the "frameCore" zone. 509 foreach(zone; profiler.profileData.zoneRange.filter!(z => z.info == "frameCore")) 510 { 511 import std.stdio; 512 writeln(zone.duration); 513 } 514 } 515 /// 516 unittest 517 { 518 // Sort top-level zones by duration. If there is one top-level zone per frame, this 519 // sorts frames by duration: useful to get the worst-case frames. 520 521 // This example also uses C malloc/free and std.typecons.scoped 522 // to show how to do this without using the GC. 523 524 import tharsis.prof; 525 526 const storageLength = Profiler.maxEventBytes + 1024 * 1024 * 2; 527 528 import core.stdc.stdlib; 529 // A simple typed-slice malloc wrapper function would avoid the ugly cast/slicing. 530 ubyte[] storage = (cast(ubyte*)malloc(storageLength))[0 .. storageLength]; 531 scope(exit) { free(storage.ptr); } 532 533 import std.typecons; 534 auto profiler = scoped!Profiler(storage); 535 536 // std.typecons.scoped! stores the Profiler on the stack. 537 // Simulate 16 'frames' 538 foreach(frame; 0 .. 16) 539 { 540 Zone topLevel = Zone(profiler, "frame"); 541 542 // Simulate frame overhead. Replace this with your frame code. 543 { 544 Zone nested1 = Zone(profiler, "frameStart"); 545 foreach(i; 0 .. 1000) { continue; } 546 } 547 { 548 Zone nested2 = Zone(profiler, "frameCore"); 549 foreach(i; 0 .. 10000) { continue; } 550 } 551 } 552 553 import std.algorithm; 554 auto zones = profiler.profileData.zoneRange; 555 556 // nestLevel of 1 is toplevel. 557 auto topLevel = zones.filter!(z => z.nestLevel == 1); 558 559 const size_t topLevelLength = zones.walkLength; 560 //TODO replace with std.allocator, or better, new containers once added to Phobos 561 ZoneData[] topLevelArray = (cast(ZoneData*)malloc(topLevelLength * ZoneData.sizeof))[0 .. topLevelLength]; 562 scope(exit) { free(topLevelArray.ptr); } 563 564 topLevel.copy(topLevelArray); 565 topLevelArray.sort!((a, b) => a.duration > b.duration); 566 import std.stdio; 567 // Print the 4 longest frames. 568 foreach(frame; topLevelArray[0 .. 4]) 569 { 570 writeln(frame); 571 } 572 573 auto worst = topLevelArray[0]; 574 575 /* Code based on std.container.array.Array: broken due to DMD 2.068 changes. 576 * Getting obsolete anyway, as containers are finally being redesigned by Andrei Alexandrescu. 577 import std.container; 578 // std.container.Array constructor builds an RAII array containing zones from topLevel. 579 // We need an array as we need random access to sort the zones (ZoneRange generates 580 // ZoneData on-the-fly as it processes profiling data, so it has no random access). 581 auto topLevelArray = Array!ZoneData(topLevel); 582 topLevelArray[].sort!((a, b) => a.duration > b.duration); 583 584 import std.stdio; 585 // Print the 4 longest frames. 586 foreach(frame; topLevelArray[0 .. 4]) 587 { 588 writeln(frame); 589 } 590 591 auto worst = topLevelArray[0]; 592 */ 593 594 // Print details about all zones in the worst frame. 595 writeln("Zones in the worst frame:"); 596 foreach(zone; zones.filter!(z => z.startTime >= worst.startTime && z.endTime <= worst.endTime)) 597 { 598 writefln("%s: %s hnsecs from %s to %s", 599 zone.info, zone.duration, zone.startTime, zone.endTime); 600 } 601 } 602 603 604 /** Construct an EventRange directly from profile data. 605 * 606 * ForwardRange of Event. 607 * 608 * Params: 609 * 610 * profileData = Profile data recorded by a Profiler. Note that modifying or concatenating 611 * profile data is unsafe unless you know what you're doing. 612 * Example: 613 * -------------------- 614 * // Profiler profiler; 615 * 616 * // Create an EventRange from profile data with UFCS syntax. 617 * auto events = profiler.profileData.eventRange; 618 * foreach(event; events) 619 * { 620 * import std.stdio; 621 * writeln(event); 622 * } 623 * -------------------- 624 */ 625 EventRange eventRange(const(ubyte)[] profileData) @safe pure nothrow @nogc 626 { 627 return EventRange(profileData); 628 } 629 630 /** Light-weight type-safe range that iterates over events in profile data. 631 * 632 * EventRange is a 'low-level' range to base other ranges or structures (such as 633 * ZoneRange) on top of. 634 * 635 * Doesn't allocate any heap memory. 636 */ 637 struct EventRange 638 { 639 private: 640 /// Raw profile data recorded by a Profiler. 641 const(ubyte)[] profileData_; 642 643 static assert(isForwardRange!EventRange, "EventRange must be a forward range"); 644 static assert(is(Unqual!(ElementType!EventRange) == Event), 645 "EventRange must be a range of Event"); 646 647 // If empty_ is false, this is the event at the front of the range. 648 // 649 // front_.time is incrementally increased with each readEvent() call instead of 650 // clearing front_ completely. 651 Event front_; 652 653 // Is the range empty (last event has been popped)? 654 bool empty_; 655 656 public: 657 @safe pure nothrow @nogc: 658 /** Construct an EventRange. 659 * 660 * Params: 661 * 662 * profileData = Profile data recorded by a Profiler. Note that modifying or 663 * concatenating raw profile data is unsafe unless you know what you're 664 * doing. 665 */ 666 this(const(ubyte)[] profileData) 667 { 668 profileData_ = profileData; 669 empty_ = profileData_.empty; 670 if(!empty_) { readEvent(); } 671 } 672 673 /// Get the current event. 674 Event front() const 675 { 676 assert(!empty, "Can't get front of an empty range"); 677 return front_; 678 } 679 680 /// Move to the next event. 681 void popFront() 682 { 683 assert(!empty, "Can't pop front of an empty range"); 684 // unoptimized // empty_ = profileData_.empty; 685 empty_ = profileData_.length == 0; 686 if(!empty_) { readEvent(); } 687 } 688 689 /// Are there no more events? 690 bool empty() const { return empty_; } 691 692 // Must be a property, isForwardRange won't work otherwise. 693 /// Get a copy of the range in its current state. 694 @property EventRange save() const { return this; } 695 696 package: 697 /** Get the number of remaining bytes in the underlying profile data. 698 * 699 * Used by code in tharsis.prof package to determine end position of an event in 700 * profile data without increasing memory overhead of EventRange. 701 */ 702 size_t bytesLeft() @safe pure nothrow const @nogc 703 { 704 return profileData_.length; 705 } 706 707 private: 708 /* Read the next event from profile data. 709 * 710 * Called from constructor and popFront() to update front_. 711 */ 712 void readEvent() 713 { 714 // Store on the stack for fast access. 715 const(ubyte)[] profileData = profileData_; 716 scope(exit) { profileData_ = profileData; } 717 assert(!profileData.empty, "Trying to read an event from empty profile data"); 718 719 front_.id = cast(EventID)(profileData[0] & eventIDMask); 720 // Assert validity of the profile data. 721 debug 722 { 723 bool found = allEventIDs.canFind(front_.id); 724 assert(found, "Invalid profiling data; expected event ID but got something else"); 725 } 726 727 const timeBytes = profileData[0] >> eventIDBits; 728 profileData = profileData[1 .. $]; 729 730 assert(profileData.length >= timeBytes, 731 "Invalid profiling data; not long enough to store expected time gap bytes"); 732 733 // Parses 'time bytes' each encoding 7 bits of a time span value 734 void parseTimeBytes(uint count) nothrow @nogc 735 { 736 assert(count <= 8, "Time byte count can't be more than 8 bytes"); 737 738 import std.typetuple; 739 // This unrolls the loop at compile-time (for performance). 740 foreach(b; TypeTuple!(0, 1, 2, 3, 4, 5, 6, 7, 8, 9)) 741 { 742 // 7 is the maximum for time gap, but 8 is used for checkpoints 743 static if(b == 9) 744 { 745 assert(false, "Time durations over 128 * 228 years not supported"); 746 } 747 else 748 { 749 if(count--) 750 { 751 enum bitOffset = b * timeByteBits; 752 assert(profileData[0] != 0, "Time bytes must not be 0"); 753 front_.time += cast(ulong)(profileData[0] & timeByteMask) << bitOffset; 754 profileData = profileData[1 .. $]; 755 } 756 else 757 { 758 return; 759 } 760 } 761 } 762 } 763 764 parseTimeBytes(timeBytes); 765 front_.info_ = null; 766 767 with(EventID) switch(front_.id) 768 { 769 case ZoneStart, ZoneEnd: return; 770 case Checkpoint: 771 // A checkpoint contains absolute start time. 772 // This is not really necessary ATM, (relative time would get us the same 773 // result as this code), but allow 'disjoint' checkpoints that change the 774 // 'current time' in future. 775 front_.time = 0; 776 parseTimeBytes(checkpointByteCount); 777 break; 778 // Info is followed by an info string. 779 case Info: 780 assert(profileData.length != 0, 781 "Invalid profiling data: info event not followed by string length"); 782 const infoBytes = profileData[0]; 783 profileData = profileData[1 .. $]; 784 front_.info_ = cast(const(char)[])profileData[0 .. infoBytes]; 785 786 assert(profileData.length >= infoBytes, 787 "Invalid profiling data: info event not followed by info string"); 788 profileData = profileData[infoBytes .. $]; 789 return; 790 // Variable is followed by variable type and 7-bit encoded value. 791 case Variable: 792 const ubyte type = profileData[0]; 793 profileData = profileData[1 .. $]; 794 bool knownType = allVariableTypes.canFind(type); 795 assert(knownType, "Variable event has unknown type"); 796 front_.var_.type_ = cast(VariableType)type; 797 798 // Decode a 7-bit variable value at the front of profileData. 799 V decode(V)() @trusted nothrow @nogc 800 { 801 enum VType = variableType!V; 802 enum encBytes = variable7BitLengths[VType]; 803 ubyte[encBytes] encoded = profileData[0 .. encBytes]; 804 V[1] decoded; 805 decode7Bit(encoded, cast(ubyte[])(decoded[])); 806 profileData = profileData[encBytes .. $]; 807 808 import std.system; 809 if(std.system.endian != Endian.bigEndian) 810 { 811 import tinyendian; 812 swapByteOrder(decoded[]); 813 } 814 return decoded[0]; 815 } 816 817 final switch(front_.var_.type_) 818 { 819 case VariableType.Int: front_.var_.int_ = decode!int; break; 820 case VariableType.Uint: front_.var_.uint_ = decode!uint; break; 821 case VariableType.Float: front_.var_.float_ = decode!float; break; 822 } 823 return; 824 default: assert(false, "Unknown event ID"); 825 } 826 827 828 // // Unoptimized version: 829 // 830 // assert(!profileData_.empty, "Trying to read an event from empty profile data"); 831 // 832 // // un-optimized // front_.id = cast(EventID)(profileData_.front & eventIDMask); 833 // front_.id = cast(EventID)(profileData_[0] & eventIDMask); 834 // // Assert validity of the profile data. 835 // debug 836 // { 837 // bool found = allEventIDs.canFind(front_.id); 838 // assert(found, "Invalid profiling data; expected event ID but got something else"); 839 // } 840 // 841 // // un-optimized // const timeBytes = profileData_.front >> eventIDBits; 842 // const timeBytes = profileData_.front >> eventIDBits; 843 // // un-optimized // profileData_.popFront(); 844 // profileData_ = profileData[1 .. $]; 845 // 846 // assert(profileData_.length >= timeBytes, 847 // "Invalid profiling data; not long enough to store expected time gap bytes"); 848 // 849 // // Parses 'time bytes' each encoding 7 bits of a time span value 850 // void parseTimeBytes(uint count) nothrow @nogc 851 // { 852 // assert(count <= 8, "Time byte count can't be more than 8 bytes"); 853 // foreach(b; 0 .. count) 854 // { 855 // assert(profileData_.front != 0, "Time bytes must not be 0"); 856 // front_.time += cast(ulong)(profileData_.front() & timeByteMask) 857 // << (b * timeByteBits); 858 // profileData_.popFront(); 859 // } 860 // } 861 // 862 // parseTimeBytes(timeBytes); 863 // front_.info_ = null; 864 // 865 // with(EventID) switch(front_.id) 866 // { 867 // case ZoneStart, ZoneEnd: return; 868 // case Checkpoint: 869 // // A checkpoint contains absolute start time. 870 // // This is not really necessary ATM, (relative time would get us the same 871 // // result as this code), but allow 'disjoint' checkpoints that change the 872 // // 'current time' in future. 873 // front_.time = 0; 874 // parseTimeBytes(checkpointByteCount); 875 // break; 876 // // Info is followed by an info string. 877 // case Info: 878 // assert(!profileData_.empty, 879 // "Invalid profiling data: info event not followed by string length"); 880 // const infoBytes = profileData_.front; 881 // profileData_.popFront; 882 // front_.info_ = cast(const(char)[])profileData_[0 .. infoBytes]; 883 // 884 // assert(profileData_.length >= infoBytes, 885 // "Invalid profiling data: info event not followed by info string"); 886 // profileData_ = profileData_[infoBytes .. $]; 887 // return; 888 // // Variable is followed by variable type and 7-bit encoded value. 889 // case Variable: 890 // const ubyte type = profileData_.front; 891 // profileData_.popFront(); 892 // bool knownType = allVariableTypes.canFind(type); 893 // assert(knownType, "Variable event has unknown type"); 894 // front_.var_.type_ = cast(VariableType)type; 895 // 896 // // Decode a 7-bit variable value at the front of profileData_. 897 // V decode(V)() @trusted pure nothrow @nogc 898 // { 899 // enum VType = variableType!V; 900 // enum encBytes = variable7BitLengths[VType]; 901 // ubyte[encBytes] encoded = profileData_[0 .. encBytes]; 902 // V[1] decoded; 903 // decode7Bit(encoded, cast(ubyte[])(decoded[])); 904 // profileData_ = profileData_[encBytes .. $]; 905 // 906 // import std.system; 907 // if(std.system.endian != Endian.bigEndian) 908 // { 909 // import tinyendian; 910 // swapByteOrder(decoded[]); 911 // } 912 // return decoded[0]; 913 // } 914 // 915 // final switch(front_.var_.type_) 916 // { 917 // case VariableType.Int: front_.var_.int_ = decode!int; break; 918 // case VariableType.Uint: front_.var_.uint_ = decode!uint; break; 919 // case VariableType.Float: front_.var_.float_ = decode!float; break; 920 // } 921 // return; 922 // default: assert(false, "Unknown event ID"); 923 // } 924 } 925 } 926 /// 927 unittest 928 { 929 // Filter zones based on the info string. Useful to determine durations of only 930 // certain zones. 931 932 import tharsis.prof; 933 934 auto storage = new ubyte[Profiler.maxEventBytes + 2048]; 935 auto profiler = new Profiler(storage); 936 937 // Simulate 8 'frames' 938 foreach(frame; 0 .. 8) 939 { 940 Zone topLevel = Zone(profiler, "frame"); 941 942 // Simulate frame overhead. Replace this with your frame code. 943 { 944 Zone nested1 = Zone(profiler, "frameStart"); 945 foreach(i; 0 .. 1000) { continue; } 946 } 947 { 948 Zone nested2 = Zone(profiler, "frameCore"); 949 foreach(i; 0 .. 10000) { continue; } 950 } 951 } 952 953 import std.stdio; 954 // Create an EventRange from profile data with UFCS syntax. 955 auto events = profiler.profileData.eventRange; 956 // Foreach over range calls popFront()/front()/empty() internally 957 foreach(event; events) 958 { 959 writeln(event); 960 } 961 962 // Get a range of only the events with start time between 1000 and 5000 (hectonanoseconds) 963 // 964 // This doesn't filter anything or allocate; filtering only happens once the 965 // range is iterated over (but if we did want to do the filtering right now, e.g. to 966 // get an array of filtered results, we'd suffix this with ".array") 967 auto filtered = events.filter!(e => e.time > 1500 && e.time < 2000); 968 // Here, we print the IDs of events between 10000 and 50000 hectonanoseconds 969 foreach(id; filtered.map!(e => e.id)) 970 { 971 writeln(id); 972 } 973 974 // And here we count the number of events between 1000 and 5000 975 writeln(filtered.count); 976 }