Tracing: Added some temp debug prints to investigate crbug.com/638744

base/trace_event/trace_log.cc

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/trace_event/trace_log.h"
 
 #include <algorithm>
 #include <cmath>
 #include <memory>
 #include <utility>
@@ skipping 1449 matching lines @@
     TraceEventETWExport::AddCompleteEndEvent(name);
 #endif  // OS_WIN
 
   std::string console_message;
   if (category_group_enabled_local & ENABLED_FOR_RECORDING) {
     OptionalAutoLock lock(&lock_);
 
     TraceEvent* trace_event = GetEventByHandleInternal(handle, &lock);
     if (trace_event) {
       DCHECK(trace_event->phase() == TRACE_EVENT_PHASE_COMPLETE);
+      // TEMP(oysteine) to debug crbug.com/638744
+      if (trace_event->duration().ToInternalValue() != -1) {
+        DVLOG(1) << "TraceHandle: chunk_seq " << handle.chunk_seq
+                 << ", chunk_index " << handle.chunk_index << ", event_index "
+                 << handle.event_index;
+
+        std::string serialized_event;
+        trace_event->AppendAsJSON(&serialized_event, ArgumentFilterPredicate());
+        DVLOG(1) << "TraceEvent: " << serialized_event;
+        lock_.AssertAcquired();
+      }
+
       trace_event->UpdateDuration(now, thread_now);
 #if defined(OS_ANDROID)
       trace_event->SendToATrace();
 #endif
     }
 
     if (trace_options() & kInternalEchoToConsole) {
       console_message =
           EventToConsoleMessage(TRACE_EVENT_PHASE_END, now, trace_event);
     }
@@ skipping 299 matching lines @@
 }
 
 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
   if (*category_group_enabled_) {
     TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, name_,
                                                 event_handle_);
   }
 }
 
 }  // namespace trace_event_internal