New issue
Advanced search Search tips

Issue 859888 link

Starred by 1 user

Issue metadata

Status: Duplicate
Merged: issue 859738
Owner:
Closed: Jul 3
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug



Sign in to add a comment

DCHECK: ThreadProfiler posts tasks with negative delay.

Project Member Reported by erikc...@chromium.org, Jul 3

Issue description

I was running Chrome in a debugger and hit this condition. It looks like this # is sometimes negative:

"""
base::TimeDelta PeriodicSamplingScheduler::GetTimeToNextCollection() {
  double sampling_offset_seconds =
      (period_duration_ - sampling_duration_).InSecondsF() * RandDouble();
  base::TimeTicks next_collection_time =
      period_start_time_ +
      base::TimeDelta::FromSecondsD(sampling_offset_seconds);
  period_start_time_ += period_duration_;
  return next_collection_time - Now();
}
"""

Given that Now() can be changed arbitrarily [e.g. by using change their clock], this logic probably needs to be reworked to not call Now().

"""
[2646:775:0703/103633.012131:FATAL:incoming_task_queue.cc(48)] Check failed: delay.InMilliseconds() == 0 (-1161466 vs. 0)delay should not be negative
Process 2646 stopped
* thread #1, name = 'CrBrowserMain', queue = 'com.apple.main-thread', stop reason = EXC_BREAKPOINT (code=EXC_I386_BPT, subcode=0x0)
    frame #0: 0x000000011a364574 libbase.dylib`::BreakDebugger() at debugger_posix.cc:269
   266 	  // Terminate the program after signaling the debug break.
   267 	  _exit(1);
   268 	#endif
-> 269 	}
   270 	
   271 	}  // namespace debug
   272 	}  // namespace base
(lldb) bt
* thread #1, name = 'CrBrowserMain', queue = 'com.apple.main-thread', stop reason = EXC_BREAKPOINT (code=EXC_I386_BPT, subcode=0x0)
  * frame #0: 0x000000011a364574 libbase.dylib`::BreakDebugger() at debugger_posix.cc:269
    frame #1: 0x000000011a005bc2 libbase.dylib`::~LogMessage() at logging.cc:855
    frame #2: 0x000000011a002565 libbase.dylib`::~LogMessage() at logging.cc:586
    frame #3: 0x000000011a050720 libbase.dylib`::CalculateDelayedRuntime() at incoming_task_queue.cc:48
    frame #4: 0x000000011a05041b libbase.dylib`::AddToIncomingQueue() at incoming_task_queue.cc:75
    frame #5: 0x000000011a0691e8 libbase.dylib`::PostDelayedTask() at message_loop_task_runner.cc:31
    frame #6: 0x0000000104ffaf1f libchrome_dll.dylib`::ScheduleNextPeriodicCollection() at thread_profiler.cc:269
    frame #7: 0x00000001050006ef libchrome_dll.dylib`::Invoke<void (ThreadProfiler::*)(), base::WeakPtr<ThreadProfiler>>() at bind_internal.h:507
    frame #8: 0x000000010500060a libchrome_dll.dylib`::MakeItSo<void (ThreadProfiler::*)(), base::WeakPtr<ThreadProfiler>>() at bind_internal.h:627
    frame #9: 0x00000001050005a0 libchrome_dll.dylib`::RunImpl<void (ThreadProfiler::*)(), std::__1::tuple<base::WeakPtr<ThreadProfiler> >, 0>() at bind_internal.h:681
    frame #10: 0x00000001050004f9 libchrome_dll.dylib`::RunOnce() at bind_internal.h:649
    frame #11: 0x0000000119f27aac libbase.dylib`::Run() at callback.h:99
    frame #12: 0x0000000119f87289 libbase.dylib`::RunTask() at task_annotator.cc:101
    frame #13: 0x000000011a05110a libbase.dylib`::RunTask() at incoming_task_queue.cc:129
    frame #14: 0x000000011a05dd48 libbase.dylib`::RunTask() at message_loop.cc:319
    frame #15: 0x000000011a05e319 libbase.dylib`::DeferOrRunPendingTask() at message_loop.cc:329
    frame #16: 0x000000011a05e64a libbase.dylib`::DoWork() at message_loop.cc:373
    frame #17: 0x000000011a06b7c2 libbase.dylib`::RunWork() at message_pump_mac.mm:455
    frame #18: 0x000000011a06b74c libbase.dylib`::___ZN4base24MessagePumpCFRunLoopBase13RunWorkSourceEPv_block_invoke() at message_pump_mac.mm:432
    frame #19: 0x000000011a009d2a libbase.dylib`base::mac::CallWithEHFrame(void () block_pointer) at call_with_eh_frame_asm.S:36
    frame #20: 0x000000011a06a625 libbase.dylib`::RunWorkSource() at message_pump_mac.mm:431
    frame #21: 0x00007fff28c03a21 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
    frame #22: 0x00007fff28cbb26c CoreFoundation`__CFRunLoopDoSource0 + 108
    frame #23: 0x00007fff28be6ab0 CoreFoundation`__CFRunLoopDoSources0 + 208
    frame #24: 0x00007fff28be5f2d CoreFoundation`__CFRunLoopRun + 1293
    frame #25: 0x00007fff28be5787 CoreFoundation`CFRunLoopRunSpecific + 487
    frame #26: 0x00007fff27ef2e26 HIToolbox`RunCurrentEventLoopInMode + 286
    frame #27: 0x00007fff27ef2b96 HIToolbox`ReceiveNextEventCommon + 613
    frame #28: 0x00007fff27ef2914 HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 64
    frame #29: 0x00007fff261bdf5f AppKit`_DPSNextEvent + 2085
    frame #30: 0x00007fff26953b4c AppKit`-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 3044
    frame #31: 0x0000000103b6c83a libchrome_dll.dylib`::__71-[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]_block_invoke() at chrome_browser_application_mac.mm:233
    frame #32: 0x000000011a009d2a libbase.dylib`base::mac::CallWithEHFrame(void () block_pointer) at call_with_eh_frame_asm.S:36
    frame #33: 0x0000000103b6c6d8 libchrome_dll.dylib`::-[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]() at chrome_browser_application_mac.mm:232
    frame #34: 0x00007fff261b2d6d AppKit`-[NSApplication run] + 764
    frame #35: 0x000000011a06ce2c libbase.dylib`::DoRun() at message_pump_mac.mm:808
    frame #36: 0x000000011a069cb5 libbase.dylib`::Run() at message_pump_mac.mm:184
    frame #37: 0x000000011a05d4fc libbase.dylib`::Run() at message_loop.cc:271
    frame #38: 0x000000011a159d9e libbase.dylib`::Run() at run_loop.cc:102
    frame #39: 0x0000000103b7e710 libchrome_dll.dylib`::MainMessageLoopRun() at chrome_browser_main.cc:2053
    frame #40: 0x00000001219fb902 libcontent.dylib`::RunMainMessageLoopParts() at browser_main_loop.cc:977
    frame #41: 0x0000000121a05a8a libcontent.dylib`::Run() at browser_main_runner_impl.cc:169
    frame #42: 0x00000001219eda2c libcontent.dylib`::BrowserMain() at browser_main.cc:51
    frame #43: 0x00000001248f0198 libcontent.dylib`::RunBrowserProcessMain() at content_main_runner_impl.cc:608
    frame #44: 0x00000001248f325f libcontent.dylib`::Run() at content_main_runner_impl.cc:955
    frame #45: 0x00000001248e82f5 libcontent.dylib`::RunEmbedderProcess() at content_service_manager_main_delegate.cc:53
    frame #46: 0x0000000119dd7f08 libembedder.dylib`::Main() at main.cc:459
    frame #47: 0x00000001248efd46 libcontent.dylib`::ContentMain() at content_main.cc:19
    frame #48: 0x0000000101006eee libchrome_dll.dylib`::ChromeMain() at chrome_main.cc:101
    frame #49: 0x0000000100000deb Chromium`main at chrome_exe_main_mac.cc:101
    frame #50: 0x00007fff50599115 libdyld.dylib`start + 1
"""
 
Mergedinto: 859738
Status: Duplicate (was: Assigned)
Calling base::TimeTicks::Now() is fine because TimeTicks monotonically increases. It looks like the problem is that we're not accounting for jumps in the tick count due times we're not executing.

Sign in to add a comment