Observatory: Include profiler samples in the timeline view.

runtime/vm/profiler_service.cc

 // Copyright (c) 2015, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 
 #include "vm/profiler_service.h"
 
 #include "vm/growable_array.h"
 #include "vm/native_symbol.h"
 #include "vm/object.h"
 #include "vm/os.h"
@@ skipping 779 matching lines @@
     }
   }
 
   ZoneGrowableArray<ProfileCode*> table_;
 };
 
 
 ProfileTrieNode::ProfileTrieNode(intptr_t table_index)
     : table_index_(table_index),
       count_(0),
-      children_(0) {
+      children_(0),
+      frame_id_(-1) {
   ASSERT(table_index_ >= 0);
 }
 
 
 ProfileTrieNode::~ProfileTrieNode() {
 }
 
 
 void ProfileTrieNode::SortChildren() {
   children_.Sort(ProfileTrieNodeCompare);
@@ skipping 238 matching lines @@
     RegisterProfileCodeTag(VMTag::kInlineEndCodeTagId);
   }
 
   void FilterSamples() {
     ScopeTimer sw("ProfileBuilder::FilterSamples", FLAG_trace_profiler);
     SampleBuffer* sample_buffer = Profiler::sample_buffer();
     if (sample_buffer == NULL) {
       return;
     }
     samples_ = sample_buffer->BuildProcessedSampleBuffer(filter_);
+    profile_->samples_ = samples_;
     profile_->sample_count_ = samples_->length();
   }
 
   void UpdateMinMaxTimes(int64_t timestamp) {
     profile_->min_time_ =
         timestamp < profile_->min_time_ ? timestamp : profile_->min_time_;
     profile_->max_time_ =
         timestamp > profile_->max_time_ ? timestamp : profile_->max_time_;
   }
 
@@ skipping 257 matching lines @@
         current = AppendTruncatedTag(current);
       }
 
       // Walk the sampled PCs.
       for (intptr_t frame_index = sample->length() - 1;
            frame_index >= 0;
            frame_index--) {
         ASSERT(sample->At(frame_index) != 0);
         current = ProcessFrame(current, sample_index, sample, frame_index);
       }
+
+      sample->set_timeline_trie(current);
     }
   }
 
   void BuildExclusiveFunctionTrie(ProfileFunctionTrieNode* root) {
     ScopeTimer sw("ProfileBuilder::BuildExclusiveFunctionTrie",
                   FLAG_trace_profiler);
     ASSERT(tick_functions_);
     for (intptr_t sample_index = 0;
          sample_index < samples_->length();
          sample_index++) {
@@ skipping 620 matching lines @@
   bool tick_functions_;
   bool inclusive_tree_;
 
   ProcessedSampleBuffer* samples_;
   ProfileInfoKind info_kind_;
 };  // ProfileBuilder.
 
 
 Profile::Profile(Isolate* isolate)
     : isolate_(isolate),
+      zone_(Thread::Current()->zone()),
+      samples_(NULL),
       live_code_(NULL),
       dead_code_(NULL),
       tag_code_(NULL),
       functions_(NULL),
       dead_code_index_offset_(-1),
       tag_code_index_offset_(-1),
       min_time_(kMaxInt64),
       max_time_(0) {
   ASSERT(isolate_ != NULL);
   for (intptr_t i = 0; i < kNumTrieKinds; i++) {
@@ skipping 41 matching lines @@
   index -= tag_code_index_offset_;
   return tag_code_->At(index);
 }
 
 
 ProfileTrieNode* Profile::GetTrieRoot(TrieKind trie_kind) {
   return roots_[static_cast<intptr_t>(trie_kind)];
 }
 
 
-void Profile::PrintJSON(JSONStream* stream) {
-  ScopeTimer sw("Profile::PrintJSON", FLAG_trace_profiler);
+void Profile::PrintTimelineFrameJSON(JSONObject* frames,
+                                     ProfileTrieNode* current,
+                                     ProfileTrieNode* parent,
+                                     intptr_t* next_id) {
+  ASSERT(current->frame_id() == -1);
+  intptr_t id = *next_id;

[Cutch, 2015/12/15 21:54:59]

const intptr_t id = *next_id++;

[rmacnak, 2015/12/16 00:14:21]

Doesn't mean the same thing. Led to the crashes.

+  *next_id = id + 1;
+  current->set_frame_id(id);
+  ASSERT(current->frame_id() != -1);
+
+  {
+    // The samples from many isolates may be merged into a single timeline,
+    // so prefix frames id with the isolate.
+    intptr_t isolate_id = reinterpret_cast<intptr_t>(isolate_);
+    const char* key = zone_->PrintToString("f%" Pd "-%" Pd,
+                                           isolate_id, current->frame_id());
+    JSONObject frame(frames, key);
+    frame.AddProperty("category", "Dart");

[Cutch, 2015/12/15 21:54:59]

Do we need to emit a category for each stack frame? This really bloats the JSON
size.

[rmacnak, 2015/12/16 00:14:20]

The samples all have random looking colors if this is omitted.

+    ProfileFunction* func = GetFunction(current->table_index());
+    frame.AddProperty("name", func->Name());
+    if (parent != NULL) {
+      ASSERT(parent->frame_id() != -1);
+      frame.AddPropertyF("parent", "f%" Pd "-%" Pd,
+                         isolate_id, parent->frame_id());
+    }
+  }
+
+  for (intptr_t i = 0; i < current->NumChildren(); i++) {
+    ProfileTrieNode* child = current->At(i);
+    PrintTimelineFrameJSON(frames, child, current, next_id);
+  }
+}
+
+
+void Profile::PrintTimelineJSON(JSONStream* stream) {
+  ScopeTimer sw("Profile::PrintTimelineJSON", FLAG_trace_profiler);
+  JSONObject obj(stream);
+  obj.AddProperty("type", "_CpuProfileTimeline");
+  obj.AddProperty("samplePeriod",
+                  static_cast<intptr_t>(FLAG_profile_period));
+  obj.AddProperty("stackDepth",

[Cutch, 2015/12/15 21:54:59]

Factor this out into a PrintProfileHeaderJson() and share thec ode between
PrintTimelineJSON and PrintProfileJSON.

+                  static_cast<intptr_t>(FLAG_max_profile_depth));
+  obj.AddProperty("sampleCount", sample_count());
+  obj.AddProperty("timeSpan", MicrosecondsToSeconds(GetTimeSpan()));
+  {
+    JSONObject frames(&obj, "stackFrames");
+    ProfileTrieNode* root = GetTrieRoot(kInclusiveFunction);
+    intptr_t next_id = 0;
+    PrintTimelineFrameJSON(&frames, root, NULL, &next_id);
+  }
+  {
+    JSONArray events(&obj, "traceEvents");
+    intptr_t pid = OS::ProcessId();
+    intptr_t isolate_id = reinterpret_cast<intptr_t>(isolate_);
+    for (intptr_t sample_index = 0;
+         sample_index < samples_->length();
+         sample_index++) {
+      ProcessedSample* sample = samples_->At(sample_index);
+      JSONObject event(&events);
+      event.AddProperty("name", "DartSample");

[Cutch, 2015/12/15 21:54:59]

Can we shorten the name to be "DS" or even drop it entirely?

[rmacnak, 2015/12/16 00:14:20]

Works when dropped.

+      event.AddProperty("ph", "P");  // kind = sample event
+      event.AddProperty64("pid", pid);
+      event.AddProperty64("tid", OSThread::ThreadIdToIntPtr(sample->tid()));
+      event.AddPropertyTimeMicros("ts", sample->timestamp());
+      event.AddProperty("cat", VMTag::TagName(sample->vm_tag()));

[Cutch, 2015/12/15 21:54:59]

cat should be hard coded to "Dart"

[rmacnak, 2015/12/16 00:14:20]

Done.

+
+      ProfileTrieNode* trie = sample->timeline_trie();
+      ASSERT(trie->frame_id() != -1);
+      event.AddPropertyF("sf", "f%" Pd "-%" Pd,
+                         isolate_id, trie->frame_id());
+    }
+  }
+}
+
+
+void Profile::PrintProfileJSON(JSONStream* stream) {
+  ScopeTimer sw("Profile::PrintProfileJSON", FLAG_trace_profiler);
   JSONObject obj(stream);
   obj.AddProperty("type", "_CpuProfile");
   obj.AddProperty("samplePeriod",
                   static_cast<intptr_t>(FLAG_profile_period));
   obj.AddProperty("stackDepth",
                   static_cast<intptr_t>(FLAG_max_profile_depth));
   obj.AddProperty("sampleCount", sample_count());
   obj.AddProperty("timeSpan", MicrosecondsToSeconds(GetTimeSpan()));
   {
     JSONArray codes(&obj, "codes");
@@ skipping 140 matching lines @@
 intptr_t ProfileTrieWalker::SiblingCount() {
   ASSERT(parent_ != NULL);
   return parent_->NumChildren();
 }
 
 
 void ProfilerService::PrintJSONImpl(Thread* thread,
                                     JSONStream* stream,
                                     Profile::TagOrder tag_order,
                                     intptr_t extra_tags,
-                                    SampleFilter* filter) {
+                                    SampleFilter* filter,
+                                    bool as_timeline) {
   Isolate* isolate = thread->isolate();
   // Disable thread interrupts while processing the buffer.
   DisableThreadInterruptsScope dtis(thread);
 
   SampleBuffer* sample_buffer = Profiler::sample_buffer();
   if (sample_buffer == NULL) {
     stream->PrintError(kFeatureDisabled, NULL);
     return;
   }
 
   {
     StackZone zone(thread);
     HANDLESCOPE(thread);
     Profile profile(isolate);
     profile.Build(thread, filter, tag_order, extra_tags);
-    profile.PrintJSON(stream);
+    if (as_timeline) {
+      profile.PrintTimelineJSON(stream);
+    } else {
+      profile.PrintProfileJSON(stream);
+    }
   }
 }
 
 
 class NoAllocationSampleFilter : public SampleFilter {
  public:
   explicit NoAllocationSampleFilter(Isolate* isolate)
       : SampleFilter(isolate) {
   }
 
   bool FilterSample(Sample* sample) {
     return !sample->is_allocation_sample();
   }
 };
 
 
 void ProfilerService::PrintJSON(JSONStream* stream,
                                 Profile::TagOrder tag_order,
                                 intptr_t extra_tags) {
   Thread* thread = Thread::Current();
   Isolate* isolate = thread->isolate();
   NoAllocationSampleFilter filter(isolate);
-  PrintJSONImpl(thread, stream, tag_order, extra_tags, &filter);
+  const bool as_timeline = false;
+  PrintJSONImpl(thread, stream, tag_order, extra_tags, &filter, as_timeline);
 }
 
 
 class ClassAllocationSampleFilter : public SampleFilter {
  public:
   ClassAllocationSampleFilter(Isolate* isolate, const Class& cls)
       : SampleFilter(isolate),
         cls_(Class::Handle(cls.raw())) {
     ASSERT(!cls_.IsNull());
   }
 
   bool FilterSample(Sample* sample) {
     return sample->is_allocation_sample() &&
            (sample->allocation_cid() == cls_.id());
   }
 
  private:
   const Class& cls_;
 };
 
 
 void ProfilerService::PrintAllocationJSON(JSONStream* stream,
                                           Profile::TagOrder tag_order,
                                           const Class& cls) {
   Thread* thread = Thread::Current();
   Isolate* isolate = thread->isolate();
   ClassAllocationSampleFilter filter(isolate, cls);
-  PrintJSONImpl(thread, stream, tag_order, kNoExtraTags, &filter);
+  const bool as_timeline = false;
+  PrintJSONImpl(thread, stream, tag_order, kNoExtraTags, &filter, as_timeline);
 }
 
 
+void ProfilerService::PrintTimelineJSON(JSONStream* stream,
+                                        Profile::TagOrder tag_order) {
+  Thread* thread = Thread::Current();
+  Isolate* isolate = thread->isolate();
+  NoAllocationSampleFilter filter(isolate);
+  const bool as_timeline = true;
+  PrintJSONImpl(thread, stream, tag_order, kNoExtraTags, &filter, as_timeline);
+}
+
+
 void ProfilerService::ClearSamples() {
   SampleBuffer* sample_buffer = Profiler::sample_buffer();
   if (sample_buffer == NULL) {
     return;
   }
 
   Thread* thread = Thread::Current();
   Isolate* isolate = thread->isolate();
 
   // Disable thread interrupts while processing the buffer.
   DisableThreadInterruptsScope dtis(thread);
 
   ClearProfileVisitor clear_profile(isolate);
   sample_buffer->VisitSamples(&clear_profile);
 }
 
 }  // namespace dart