Stop holding onto TimelineEvents

runtime/vm/timeline.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 <cstdlib>
 
 #include "vm/atomic.h"
 #include "vm/isolate.h"
 #include "vm/json_stream.h"
 #include "vm/lockers.h"
@@ skipping 260 matching lines @@
                         int64_t micros) {
   Init(kEnd, label);
   timestamp0_ = micros;
 }
 
 
 void TimelineEvent::SetNumArguments(intptr_t length) {
   // Cannot call this twice.
   ASSERT(arguments_ == NULL);
   ASSERT(arguments_length_ == 0);
+  if (length == 0) {
+    return;
+  }
   arguments_length_ = length;
   arguments_ = reinterpret_cast<TimelineEventArgument*>(
       calloc(sizeof(TimelineEventArgument), length));
 }
 
 
 void TimelineEvent::SetArgument(intptr_t i, const char* name, char* argument) {
   ASSERT(i >= 0);
   ASSERT(i < arguments_length_);
   arguments_[i].name = name;
@@ skipping 20 matching lines @@
 }
 
 
 void TimelineEvent::CopyArgument(intptr_t i,
                                  const char* name,
                                  const char* argument) {
   SetArgument(i, name, strdup(argument));
 }
 
 
+void TimelineEvent::StealArguments(intptr_t arguments_length,
+                                   TimelineEventArgument* arguments) {
+  if (arguments_length == 0) {
+    return;
+  }
+  SetNumArguments(arguments_length);
+  for (intptr_t i = 0; i < arguments_length; i++) {
+    SetArgument(i, arguments[i].name, arguments[i].value);
+    // Steal.
+    arguments[i].name = NULL;
+    arguments[i].value = NULL;
+  }

[turnidge, 2015/10/08 17:59:19]

Perhaps you could steal the whole arguments array and skip the loop?

arguments_length_ = arguments_length;
arguments_ = arguments;

[Cutch, 2015/10/08 20:08:10]

Done.

+}
+
+
 void TimelineEvent::Complete() {
   TimelineEventRecorder* recorder = Timeline::recorder();
   if (recorder != NULL) {
     recorder->CompleteEvent(this);
   }
 }
 
 
 void TimelineEvent::FreeArguments() {
   if (arguments_ == NULL) {
@@ skipping 129 matching lines @@
   }
   ASSERT(name_ != NULL);
   TimelineEvent* event = recorder->StartEvent();
   if (event != NULL) {
     event->StreamInit(this);
   }
   return event;
 }
 
 
+void TimelineDurationScope::Init() {
+  ASSERT(enabled_ == false);
+  ASSERT(label_ != NULL);
+  ASSERT(stream_ != NULL);
+  if (!stream_->Enabled()) {
+    // Stream is not enabled, do nothing.
+    return;
+  }
+  TimelineEvent* event = stream_->StartEvent();
+  if (event == NULL) {
+    return;
+  }
+  enabled_ = true;
+  event->Begin(label_);
+  event->Complete();
+}
+
+void TimelineDurationScope::FreeArguments() {
+  if (arguments_ == NULL) {
+    return;
+  }
+  for (intptr_t i = 0; i < arguments_length_; i++) {
+    free(arguments_[i].value);
+  }
+  free(arguments_);
+  arguments_ = NULL;
+  arguments_length_ = 0;
+}
+
+
+TimelineDurationScope::~TimelineDurationScope() {
+  if (!enabled_) {
+    FreeArguments();
+    return;
+  }
+  TimelineEvent* event = stream_->StartEvent();
+  if (event == NULL) {
+    FreeArguments();
+    return;
+  }
+  event->End(label_);
+  event->StealArguments(arguments_length_, arguments_);

[turnidge, 2015/10/08 17:59:19]

If StealArguments steals the whole array, follow this by:

arguments_length_ = 0;
arguments_ = NULL;

and remove the call to FreeArguments.

[Cutch, 2015/10/08 20:08:10]

Done.

+  event->Complete();
+  FreeArguments();
+}
+
+
+void TimelineDurationScope::SetNumArguments(intptr_t length) {
+  if (!enabled()) {
+    return;
+  }
+  ASSERT(arguments_ == NULL);
+  ASSERT(arguments_length_ == 0);
+  arguments_length_ = length;

[turnidge, 2015/10/08 17:59:19]

You could choose to guard the allocation of arguments_ here...

if (arguments_length_ > 0) {
  calloc
}

[Cutch, 2015/10/08 20:08:10]

Done.

+  arguments_ = reinterpret_cast<TimelineEventArgument*>(
+      calloc(sizeof(TimelineEventArgument), length));
+}
+
+
+// |name| must be a compile time constant. Takes ownership of |argumentp|.
+void TimelineDurationScope::SetArgument(intptr_t i,
+                                        const char* name,
+                                        char* argument) {
+  if (!enabled()) {
+    return;
+  }
+  ASSERT(i >= 0);
+  ASSERT(i < arguments_length_);
+  arguments_[i].name = name;
+  arguments_[i].value = argument;
+}
+
+
+// |name| must be a compile time constant. Copies |argument|.
+void TimelineDurationScope::CopyArgument(intptr_t i,
+                                         const char* name,
+                                         const char* argument) {
+  if (!enabled()) {
+    return;
+  }
+  SetArgument(i, name, strdup(argument));
+}
+
+
 void TimelineDurationScope::FormatArgument(intptr_t i,
                                            const char* name,
                                            const char* fmt, ...) {
-  if (event_ == NULL) {
+  if (!enabled()) {
     return;
   }
   va_list args;
   va_start(args, fmt);
   intptr_t len = OS::VSNPrint(NULL, 0, fmt, args);
   va_end(args);
 
   char* buffer = reinterpret_cast<char*>(malloc(len + 1));
   va_list args2;
   va_start(args2, fmt);
   OS::VSNPrint(buffer, (len + 1), fmt, args2);
   va_end(args2);
 
-  event_->SetArgument(i, name, buffer);
+  SetArgument(i, name, buffer);
 }
 
 
 TimelineEventFilter::TimelineEventFilter() {
 }
 
 
 TimelineEventFilter::~TimelineEventFilter() {
 }
 
@@ skipping 40 matching lines @@
 
 
 void TimelineEventRecorder::PrintJSONMeta(JSONArray* events) const {
 }
 
 
 TimelineEvent* TimelineEventRecorder::ThreadBlockStartEvent() {
   // Grab the current thread.
   Thread* thread = Thread::Current();
   ASSERT(thread != NULL);
-  // We are accessing the thread's timeline block- so take the lock.
-  MutexLocker ml(thread->timeline_block_lock());
-
-  if (thread->isolate() == NULL) {
-    // Non-isolate thread case. This should be infrequent.
-    return GlobalBlockStartEvent();
-  }
+  ASSERT(thread->isolate() != NULL);
+  Mutex* thread_block_lock = thread->timeline_block_lock();
+  ASSERT(thread_block_lock != NULL);
+  // We are accessing the thread's timeline block- so take the lock here.
+  // This lock will be held until the call to |CompleteEvent| is made.
+  thread_block_lock->Lock();
 
   TimelineEventBlock* thread_block = thread->timeline_block();
 
   if ((thread_block != NULL) && thread_block->IsFull()) {
     MutexLocker ml(&lock_);
     // Thread has a block and it is full:
     // 1) Mark it as finished.
     thread_block->Finish();
     // 2) Allocate a new block.
     thread_block = GetNewBlockLocked(thread->isolate());
     thread->set_timeline_block(thread_block);
   } else if (thread_block == NULL) {
     MutexLocker ml(&lock_);
     // Thread has no block. Attempt to allocate one.
     thread_block = GetNewBlockLocked(thread->isolate());
     thread->set_timeline_block(thread_block);
   }
   if (thread_block != NULL) {
+    // NOTE: We are exiting this function with the thread's block lock held.
     ASSERT(!thread_block->IsFull());
     return thread_block->StartEvent();
   }
+  // Drop lock here as no event is being handed out.
+  thread_block_lock->Unlock();
   return NULL;
 }
 
 
-
 TimelineEvent* TimelineEventRecorder::GlobalBlockStartEvent() {
-  MutexLocker ml(&lock_);
+  // Take recorder lock. This lock will be held until the call to
+  // |CompleteEvent| is made.
+  lock_.Lock();
   if (FLAG_trace_timeline) {
     OS::Print("GlobalBlockStartEvent in block %p for thread %" Px "\n",
               global_block_, OSThread::CurrentCurrentThreadIdAsIntPtr());
   }
   if ((global_block_ != NULL) && global_block_->IsFull()) {
     // Global block is full.
     global_block_->Finish();
     global_block_ = NULL;
   }
   if (global_block_ == NULL) {
     // Allocate a new block.
     global_block_ = GetNewBlockLocked(NULL);
     ASSERT(global_block_ != NULL);
   }
   if (global_block_ != NULL) {
+    // NOTE: We are exiting this function with the recorder's lock held.
     ASSERT(!global_block_->IsFull());
     return global_block_->StartEvent();
   }
+  // Drop lock here as no event is being handed out.
+  lock_.Unlock();
   return NULL;
 }
 
 
+void TimelineEventRecorder::ThreadBlockCompleteEvent(TimelineEvent* event) {
+  // Grab the current thread.
+  Thread* thread = Thread::Current();
+  ASSERT(thread != NULL);
+  ASSERT(thread->isolate() != NULL);
+  // This event came from the isolate's thread local block. Unlock the
+  // thread's block lock.
+  Mutex* thread_block_lock = thread->timeline_block_lock();
+  ASSERT(thread_block_lock != NULL);
+  thread_block_lock->Unlock();
+}
+
+
+void TimelineEventRecorder::GlobalBlockCompleteEvent(TimelineEvent* event) {
+  // This event came from the global block, unlock the recorder's lock now
+  // that the event is filled.
+  lock_.Unlock();
+}
+
+
 // Trims the ']' character.
 static void TrimOutput(char* output,
                        intptr_t* output_length) {
   ASSERT(output != NULL);
   ASSERT(output_length != NULL);
   ASSERT(*output_length >= 2);
   // We expect the first character to be the opening of an array.
   ASSERT(output[0] == '[');
   // We expect the last character to be the closing of an array.
   ASSERT(output[*output_length - 1] == ']');
@@ skipping 247 matching lines @@
     if (block->LowerTimeBound() < earliest_time) {
       earliest_time = block->LowerTimeBound();
       earliest_index = block_idx;
     }
   }
   return earliest_index;
 }
 
 
 TimelineEvent* TimelineEventRingRecorder::StartEvent() {
+  // Grab the current thread.
+  Thread* thread = Thread::Current();
+  ASSERT(thread != NULL);
+  if (thread->isolate() == NULL) {
+    // Non-isolate thread case. This should be infrequent.
+    return GlobalBlockStartEvent();
+  }
   return ThreadBlockStartEvent();
 }
 
 
 void TimelineEventRingRecorder::CompleteEvent(TimelineEvent* event) {
-  // no-op.
+  if (event == NULL) {
+    return;
+  }
+  Thread* thread = Thread::Current();
+  ASSERT(thread != NULL);
+  if (thread->isolate() == NULL) {
+    GlobalBlockCompleteEvent(event);
+  } else {
+    ThreadBlockCompleteEvent(event);
+  }
 }
 
 
 TimelineEventStreamingRecorder::TimelineEventStreamingRecorder() {
 }
 
 
 TimelineEventStreamingRecorder::~TimelineEventStreamingRecorder() {
 }
 
@@ skipping 101 matching lines @@
   dart_events_[dart_events_cursor_++] = dart_event;
 }
 
 
 TimelineEventBlock* TimelineEventEndlessRecorder::GetHeadBlockLocked() {
   return head_;
 }
 
 
 TimelineEvent* TimelineEventEndlessRecorder::StartEvent() {
+  // Grab the current thread.
+  Thread* thread = Thread::Current();
+  ASSERT(thread != NULL);
+  if (thread->isolate() == NULL) {
+    // Non-isolate thread case. This should be infrequent.
+    return GlobalBlockStartEvent();
+  }
   return ThreadBlockStartEvent();
 }
 
 
 void TimelineEventEndlessRecorder::CompleteEvent(TimelineEvent* event) {
-  // no-op.
+  if (event == NULL) {
+    return;
+  }
+  Thread* thread = Thread::Current();
+  ASSERT(thread != NULL);
+  if (thread->isolate() == NULL) {
+    GlobalBlockCompleteEvent(event);
+  } else {
+    ThreadBlockCompleteEvent(event);
+  }
 }
 
 
 TimelineEventBlock* TimelineEventEndlessRecorder::GetNewBlockLocked(
     Isolate* isolate) {
   TimelineEventBlock* block = new TimelineEventBlock(block_index_++);
   block->set_next(head_);
   block->Open(isolate);
   head_ = block;
   if (FLAG_trace_timeline) {
@@ skipping 258 matching lines @@
       // If an isolate was specified, skip events from other isolates.
       continue;
     }
     ASSERT(event->event_as_json() != NULL);
     result = zone->ConcatStrings(result, event->event_as_json());
   }
   return result;
 }
 
 }  // namespace dart