- Assert that we do not hold the timeline lock while entering

  potential safepoints.
- Enable timeline for existing test as a regression test.
- Fix allocation with timeline lock held during deoptimization to
  prevent deadlock.

BUG=
R=rmacnak@google.com

Review URL: https://codereview.chromium.org/1514653002 .

runtime/vm/deopt_instructions.cc

@@ -43,7 +43,7 @@ DeoptContext::DeoptContext(const StackFrame* frame,
       deopt_reason_(ICData::kDeoptUnknown),
       deopt_flags_(0),
       thread_(Thread::Current()),
-      timeline_event_(NULL),
+      deopt_start_micros_(0),
       deferred_slots_(NULL),
       deferred_objects_count_(0),
       deferred_objects_(NULL),
@@ -99,14 +99,7 @@ DeoptContext::DeoptContext(const StackFrame* frame,
   if (dest_options != kDestIsAllocated) {
     // kDestIsAllocated is used by the debugger to generate a stack trace
     // and does not signal a real deopt.
-    Isolate* isolate = Isolate::Current();
-    TimelineStream* compiler_stream = isolate->GetCompilerStream();
-    ASSERT(compiler_stream != NULL);
-    timeline_event_ = compiler_stream->StartEvent();
-    if (timeline_event_ != NULL) {
-      timeline_event_->DurationBegin("Deoptimize");
-      timeline_event_->SetNumArguments(3);
-    }
+    deopt_start_micros_ = OS::GetCurrentMonotonicMicros();
   }
 
   if (FLAG_trace_deoptimization || FLAG_trace_deoptimization_verbose) {
@@ -143,24 +136,28 @@ DeoptContext::~DeoptContext() {
   delete[] deferred_objects_;
   deferred_objects_ = NULL;
   deferred_objects_count_ = 0;
-  if (timeline_event_ != NULL) {
-    const Code& code = Code::Handle(zone(), code_);
-    const Function& function = Function::Handle(zone(), code.function());
-    timeline_event_->CopyArgument(
-        0,
-        "function",
-        const_cast<char*>(function.QualifiedUserVisibleNameCString()));
-    timeline_event_->CopyArgument(
-        1,
-        "reason",
-        const_cast<char*>(DeoptReasonToCString(deopt_reason())));
-    timeline_event_->FormatArgument(
-        2,
-        "deoptimizationCount",
-        "%d",
-        function.deoptimization_counter());
-    timeline_event_->DurationEnd();
-    timeline_event_->Complete();
+  if (deopt_start_micros_ != 0) {
+    Isolate* isolate = Isolate::Current();
+    TimelineStream* compiler_stream = isolate->GetCompilerStream();
+    ASSERT(compiler_stream != NULL);
+    if (compiler_stream->Enabled()) {
+      const Code& code = Code::Handle(zone(), code_);
+      const Function& function = Function::Handle(zone(), code.function());
+      const char* function_name = function.QualifiedUserVisibleNameCString();
+      const char* reason = DeoptReasonToCString(deopt_reason());
+      int counter = function.deoptimization_counter();
+      TimelineEvent* timeline_event = compiler_stream->StartEvent();
+      if (timeline_event != NULL) {
+        timeline_event->Duration("Deoptimize",
+                                 deopt_start_micros_,
+                                 OS::GetCurrentMonotonicMicros());
+        timeline_event->SetNumArguments(3);
+        timeline_event->CopyArgument(0, "function", function_name);
+        timeline_event->CopyArgument(1, "reason", reason);
+        timeline_event->FormatArgument(2, "deoptimizationCount", "%d", counter);
+        timeline_event->Complete();
+      }
+    }
   }
 }
 

runtime/vm/deopt_instructions.h

@@ -224,7 +224,7 @@ class DeoptContext {
   uint32_t deopt_flags_;
   intptr_t caller_fp_;
   Thread* thread_;
-  TimelineEvent* timeline_event_;
+  int64_t deopt_start_micros_;
 
   DeferredSlot* deferred_slots_;
 

runtime/vm/timeline.cc

@@ -189,67 +189,68 @@ void TimelineEvent::Reset() {
 
 void TimelineEvent::AsyncBegin(const char* label, int64_t async_id) {
   Init(kAsyncBegin, label);
-  timestamp0_ = OS::GetCurrentMonotonicMicros();
+  set_timestamp0(OS::GetCurrentMonotonicMicros());
   // Overload timestamp1_ with the async_id.
-  timestamp1_ = async_id;
+  set_timestamp1(async_id);
 }
 
 
 void TimelineEvent::AsyncInstant(const char* label,
                                  int64_t async_id) {
   Init(kAsyncInstant, label);
-  timestamp0_ = OS::GetCurrentMonotonicMicros();
+  set_timestamp0(OS::GetCurrentMonotonicMicros());
   // Overload timestamp1_ with the async_id.
-  timestamp1_ = async_id;
+  set_timestamp1(async_id);
 }
 
 
 void TimelineEvent::AsyncEnd(const char* label,
                              int64_t async_id) {
   Init(kAsyncEnd, label);
-  timestamp0_ = OS::GetCurrentMonotonicMicros();
+  set_timestamp0(OS::GetCurrentMonotonicMicros());
   // Overload timestamp1_ with the async_id.
-  timestamp1_ = async_id;
+  set_timestamp1(async_id);
 }
 
 
 void TimelineEvent::DurationBegin(const char* label) {
   Init(kDuration, label);
-  timestamp0_ = OS::GetCurrentMonotonicMicros();
+  set_timestamp0(OS::GetCurrentMonotonicMicros());
 }
 
 
 void TimelineEvent::DurationEnd() {
-  timestamp1_ = OS::GetCurrentMonotonicMicros();
+  ASSERT(timestamp1_ == 0);
+  set_timestamp1(OS::GetCurrentMonotonicMicros());
 }
 
 
 void TimelineEvent::Instant(const char* label) {
   Init(kInstant, label);
-  timestamp0_ = OS::GetCurrentMonotonicMicros();
+  set_timestamp0(OS::GetCurrentMonotonicMicros());
 }
 
 
 void TimelineEvent::Duration(const char* label,
                              int64_t start_micros,
                              int64_t end_micros) {
   Init(kDuration, label);
-  timestamp0_ = start_micros;
-  timestamp1_ = end_micros;
+  set_timestamp0(start_micros);
+  set_timestamp1(end_micros);
 }
 
 
 void TimelineEvent::Begin(const char* label,
                           int64_t micros) {
   Init(kBegin, label);
-  timestamp0_ = micros;
+  set_timestamp0(micros);
 }
 
 
 void TimelineEvent::End(const char* label,
                         int64_t micros) {
   Init(kEnd, label);
-  timestamp0_ = micros;
+  set_timestamp0(micros);
 }
 
 
@@ -675,6 +676,12 @@ TimelineEvent* TimelineEventRecorder::ThreadBlockStartEvent() {
   // 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();
+#if defined(DEBUG)
+  Thread* T = Thread::Current();
+  if (T != NULL) {
+    T->IncrementNoSafepointScopeDepth();
+  }
+#endif  // defined(DEBUG)
 
   TimelineEventBlock* thread_block = thread->timeline_block();
 
@@ -699,6 +706,11 @@ TimelineEvent* TimelineEventRecorder::ThreadBlockStartEvent() {
     return event;
   }
   // Drop lock here as no event is being handed out.
+#if defined(DEBUG)
+  if (T != NULL) {
+    T->DecrementNoSafepointScopeDepth();
+  }
+#endif  // defined(DEBUG)
   thread_block_lock->Unlock();
   return NULL;
 }
@@ -714,6 +726,12 @@ void TimelineEventRecorder::ThreadBlockCompleteEvent(TimelineEvent* event) {
   // Unlock the thread's block lock.
   Mutex* thread_block_lock = thread->timeline_block_lock();
   ASSERT(thread_block_lock != NULL);
+#if defined(DEBUG)
+  Thread* T = Thread::Current();
+  if (T != NULL) {
+    T->DecrementNoSafepointScopeDepth();
+  }
+#endif  // defined(DEBUG)
   thread_block_lock->Unlock();
 }
 

runtime/vm/timeline.h

@@ -236,16 +236,6 @@ class TimelineEvent {
   const char* GetSerializedJSON() const;
 
  private:
-  int64_t timestamp0_;
-  int64_t timestamp1_;
-  TimelineEventArgument* arguments_;
-  intptr_t arguments_length_;
-  uword state_;
-  const char* label_;
-  const char* category_;
-  ThreadId thread_;
-  Dart_Port isolate_id_;
-
   void FreeArguments();
 
   void StreamInit(TimelineStream* stream);
@@ -257,13 +247,32 @@ class TimelineEvent {
     state_ = EventTypeField::update(event_type, state_);
   }
 
+  void set_timestamp0(int64_t value) {
+    ASSERT(timestamp0_ == 0);
+    timestamp0_ = value;
+  }
+  void set_timestamp1(int64_t value) {
+    ASSERT(timestamp1_ == 0);
+    timestamp1_ = value;
+  }
+
   enum StateBits {
     kEventTypeBit = 0,  // reserve 4 bits for type.
     kNextBit = 4,
   };
 
   class EventTypeField : public BitField<EventType, kEventTypeBit, 4> {};
 
+  int64_t timestamp0_;
+  int64_t timestamp1_;
+  TimelineEventArgument* arguments_;
+  intptr_t arguments_length_;
+  uword state_;
+  const char* label_;
+  const char* category_;
+  ThreadId thread_;
+  Dart_Port isolate_id_;
+
   friend class TimelineEventRecorder;
   friend class TimelineEventEndlessRecorder;
   friend class TimelineEventRingRecorder;

tests/standalone/array_bounds_check_generalization_test.dart

@@ -2,7 +2,9 @@
 // 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.
 //
-// VMOptions=--optimization_counter_threshold=10 --no-use-osr
+// We are using --complete-timeline below to ensure that we get timeline events
+// generated during all phases of compilation and deoptimization.
+// VMOptions=--optimization_counter_threshold=10 --no-use-osr --complete-timeline
 
 import "package:expect/expect.dart";