New issue
Advanced search Search tips

Issue 757906 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Aug 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug

Blocking:
issue 596231



Sign in to add a comment

ActivityTracker thread check failing

Project Member Reported by siggi@chromium.org, Aug 22 2017

Issue description

In ToT, running SyzyASAN with dchecks_always_on, I get a stack overrun in recursive entry to the DCHECK here:

void ThreadActivityTracker::RecordExceptionActivity(const void* program_counter,
                                                    const void* origin,
                                                    Activity::Type type,
                                                    const ActivityData& data) {
  // A thread-checker creates a lock to check the thread-id which means
  // re-entry into this code if lock acquisitions are being tracked.
  DCHECK(thread_checker_.CalledOnValidThread());

  // Fill the reusable exception activity.
  Activity::FillFrom(&header_->last_exception, program_counter, origin, type,
                     data);

  // The data has changed meaning that some other thread trying to copy the
  // contents for reporting purposes could get bad data.
  header_->data_unchanged.store(0, std::memory_order_relaxed);
}


 

Comment 1 by siggi@chromium.org, Aug 22 2017

Blocking: 596231

Comment 2 Deleted

Comment 3 by siggi@chromium.org, Aug 22 2017

Deleted mis-pasted code, redo: the top of the cascade is here:

ThreadActivityTracker::ActivityId ThreadActivityTracker::PushActivity(
    const void* program_counter,
    const void* origin,
    Activity::Type type,
    const ActivityData& data) {
  // A thread-checker creates a lock to check the thread-id which means
  // re-entry into this code if lock acquisitions are being tracked.
  DCHECK(type == Activity::ACT_LOCK_ACQUIRE ||
         thread_checker_.CalledOnValidThread());  << CHECK HERE

  // Get the current depth of the stack. No access to other memory guarded
  // by this variable is done here so a "relaxed" load is acceptable.
  uint32_t depth = header_->current_depth.load(std::memory_order_relaxed);

Not sure why the thread checker is barfing, the thread ID of the local thread is a match.

0:026:x86> ~.
. 26  Id: 1be4.3954 Suspend: 1 Teb: 00466000 Unfrozen
      Start: chrome_68cb0000!base::`anonymous namespace'::ThreadFunc (68db5370)
      Priority: -2  Priority class: 32  Affinity: ffffffff
0:026:x86> dv
           this = 0x0e92b9b0
program_counter = 0x68e47221
         origin = 0x68e5987b
           type = ACT_TASK (0n16)
           data = 0x0fcef460
0:026:x86> ln @@(program_counter)
Browse module
Set bu breakpoint

c:\src\chrome3\src\base\debug\task_annotator.cc(34)+0x5
(68e471f0)   chrome_68cb0000!base::debug::TaskAnnotator::RunTask+0x31   |  (68e473e0)   chrome_68cb0000!trace_event_internal::AddTraceEvent<__int64>
0:026:x86> ln @@(origin)
Browse module
Set bu breakpoint

c:\src\chrome3\src\base\task_scheduler\scheduler_single_thread_task_runner_manager.cc(208)+0x78
(68e597d0)   chrome_68cb0000!base::internal::`anonymous namespace'::SchedulerWorkerCOMDelegate::GetWorkFromWindowsMessageQueue+0xab   |  (68e599b0)   chrome_68cb0000!base::internal::`anonymous namespace'::SchedulerWorkerCOMDelegate::`scalar deleting destructor'
0:026:x86> dtx /r this
dtx is unsupported for this scenario.  It only recognizes dtx [<type>] [<address>] with -a, -h, and -r.  Reverting to dt.
Local var @ esi Type base::debug::ThreadActivityTracker*
   +0x000 __VFN_table : 0x6b6644a8 
   +0x004 header_          : 0x093f7360 base::debug::ThreadActivityTracker::Header
      +0x000 owner            : base::debug::OwningProcess
         +0x000 data_id          : std::atomic<unsigned int>
         +0x004 padding          : 0
         +0x008 process_id       : 0n7140
         +0x010 create_stamp     : 0n13147898691856836
      +0x018 thread_ref       : base::debug::`anonymous-namespace'::ThreadRef
         +0x000 as_id            : 0n14676
         +0x000 as_tid           : 0x3954
      +0x020 start_time       : 0n13147898691856836
      +0x028 start_ticks      : 0n332931505418
      +0x030 stack_slots      : 4
      +0x034 padding          : 0
      +0x038 current_depth    : std::atomic<unsigned int>
         +0x000 _My_val          : 0
      +0x03c data_unchanged   : std::atomic<unsigned int>
         +0x000 _My_val          : 0
      +0x040 last_exception   : base::debug::Activity
         +0x000 time_internal    : 0n0
         +0x008 calling_address  : 0
         +0x010 origin_address   : 0
         +0x018 call_stack       : [10] 0
         +0x068 user_data_ref    : 0
         +0x06c user_data_id     : 0
         +0x070 activity_type    : 0 ''
         +0x071 padding          : [7]  ""
         +0x078 data             : base::debug::ActivityData
      +0x0c0 thread_name      : [32]  "TaskSchedulerSingleThreadCOMSTA"
   +0x008 stack_           : 0x093f7440 base::debug::Activity
      +0x000 time_internal    : 0n333292372892
      +0x008 calling_address  : 0x68dd2732
      +0x010 origin_address   : 0
      +0x018 call_stack       : [10] 0x68df94b7
      +0x068 user_data_ref    : 0
      +0x06c user_data_id     : 0
      +0x070 activity_type    : 0x20 ' '
      +0x071 padding          : [7]  ""
      +0x078 data             : base::debug::ActivityData
         +0x000 generic          : base::debug::ActivityData::<unnamed-type-generic>
         +0x000 task             : base::debug::ActivityData::<unnamed-type-task>
         +0x000 lock             : base::debug::ActivityData::<unnamed-type-lock>
         +0x000 event            : base::debug::ActivityData::<unnamed-type-event>
         +0x000 thread           : base::debug::ActivityData::<unnamed-type-thread>
         +0x000 process          : base::debug::ActivityData::<unnamed-type-process>
         +0x000 exception        : base::debug::ActivityData::<unnamed-type-exception>
   +0x00c stack_slots_     : 4
   +0x010 valid_           : 1
   +0x014 thread_checker_  : base::ThreadChecker
      +0x000 lock_            : base::Lock
         +0x000 owning_thread_ref_ : base::PlatformThreadRef
         +0x004 lock_            : base::internal::LockImpl
      +0x008 thread_id_       : base::PlatformThreadRef
         +0x000 id_              : 0x3954
      +0x00c task_token_      : base::TaskToken
         +0x000 token_           : 0n67
      +0x010 sequence_token_  : base::SequenceToken
         +0x000 token_           : 0n66

Comment 4 by siggi@chromium.org, Aug 22 2017

Cc: fdoray@chromium.org
Francois tells me the ThreadChecker doesn't support the use here.

Comment 5 by siggi@chromium.org, Aug 22 2017

Cc: gab@chromium.org
Because this instrumentation runs on multiple sequences on shared threads, it'll barf when a thread executes a task from a second sequence, is what I'm understanding.
Project Member

Comment 6 by bugdroid1@chromium.org, Aug 23 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/2994b62cc1249c6ca69afc4730c2faa1b079d849

commit 2994b62cc1249c6ca69afc4730c2faa1b079d849
Author: Sigurdur Asgeirsson <siggi@chromium.org>
Date: Wed Aug 23 14:09:51 2017

ActivityTracker: Replace ThreadChecker with explicit thread_id checking.

Turns out the ThreadChecker is not appropriate for thread-bound
instrumentation (any more), as it also checks for valid use of
sequences.

Bug:  757906 
Change-Id: I2c9546fdff39e64360edd6a21db93dbfb925324c
Reviewed-on: https://chromium-review.googlesource.com/627101
Commit-Queue: Sigurður Ásgeirsson <siggi@chromium.org>
Reviewed-by: Mark Mentovai <mark@chromium.org>
Reviewed-by: Brian White <bcwhite@chromium.org>
Cr-Commit-Position: refs/heads/master@{#496676}
[modify] https://crrev.com/2994b62cc1249c6ca69afc4730c2faa1b079d849/base/debug/activity_tracker.cc
[modify] https://crrev.com/2994b62cc1249c6ca69afc4730c2faa1b079d849/base/debug/activity_tracker.h

Comment 7 by siggi@chromium.org, Aug 23 2017

Status: Fixed (was: Started)

Comment 8 by siggi@chromium.org, Aug 24 2017

Labels: Hotlist-dcheck

Sign in to add a comment