New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 749299 link

Starred by 1 user
Status: Assigned
Owner:
sky@chromium.org
Cc:
█ skuhne@chromium.org
gab@chromium.org
sullivan@chromium.org
sky@chromium.org
nedngu...@google.com
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug



Sign in to add a comment

DCHECK in sessions::SessionBackend::AppendCommandsToFile.

Project Member Reported by erikc...@chromium.org, Jul 26 2017 
I appear to be hitting a DCHECK in telemetry_perf_unittests.

"""
  	0a55eca4 6ec2476b 0a55eccc 6ec24203 705441e4 chrome!base::debug::BreakDebugger+0x9
  	0a55ecac 6ec24203 705441e4 0000012a 0dae3d32 chrome!?Run@?$Invoker@U?$BindState@P6AXPBDHV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@base@@1@Z$$V@internal@base@@$$A6AXPBDHV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@3@1@Z@internal@base@@SAXPAVBindStateBase@23@$$QAPBD$$QAH$$QAV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@3@3@Z+0x27
  	0a55eccc 6ec2475e 6ec24763 0a55ee40 0a55ee44 chrome!base::internal::FunctorTraits<void (__cdecl*)(char const *,int,base::BasicStringPiece<std::basic_string<char,std::char_traits<char>,std::allocator<char> > >,base::BasicStringPiece<std::basic_string<char,std::char_traits<char>,std::allocator<char> > >),void>::Invoke<char const *,int,base::BasicStringPiece<std::basic_string<char,std::char_traits<char>,std::allocator<char> > >,base::BasicStringPiece<std::basic_string<char,std::char_traits<char>,std::allocator<char> > > >+0x20
  	0a55ece8 6ec42c78 029fd058 0a55ee40 0a55ee44 chrome!?Run@?$Invoker@U?$BindState@P6AXPBDHV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@base@@1@Z$$V@internal@base@@$$A6AXPBDHV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@3@1@Z@internal@base@@SAXPAVBindStateBase@23@$$QAPBD$$QAH$$QAV?$BasicStringPiece@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@3@3@Z+0x1a
  	0a55f270 6ea3fe28 0923ccd8 0923ccb0 6ea3fcdc chrome!logging::LogMessage::~LogMessage+0x328
  	0a55f338 6ea3fd2a 0e1148b8 0a55f358 0923ccb0 chrome!sessions::SessionBackend::AppendCommandsToFile+0xd7
  	0a55f350 6ea3d9cb 0e0dbba0 0e0dbbb8 0e0dbbb8 chrome!sessions::SessionBackend::AppendCommands+0x4e
  	0a55f380 6ea3df79 0e480134 0e480138 0e480120 chrome!base::internal::Invoker<base::internal::BindState<void (__thiscall sessions::SessionBackend::*)(std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > >,bool),scoped_refptr<sessions::SessionBackend>,base::internal::PassedWrapper<std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > > >,bool>,void __cdecl(void)>::RunImpl<void (__thiscall sessions::SessionBackend::*const &)(std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > >,bool),std::tuple<scoped_refptr<sessions::SessionBackend>,base::internal::PassedWrapper<std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > > >,bool> const &,0,1,2>+0x36
  	0a55f394 6ecdbc3e 0e480120 705ba084 7054404c chrome!base::internal::Invoker<base::internal::BindState<void (__thiscall sessions::SessionBackend::*)(std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > >,bool),scoped_refptr<sessions::SessionBackend>,base::internal::PassedWrapper<std::vector<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> >,std::allocator<std::unique_ptr<sessions::SessionCommand,std::default_delete<sessions::SessionCommand> > > > >,bool>,void __cdecl(void)>::Run+0x16
  	0a55f494 6ece28b4 705ba0a0 0e3e8208 0e3aadb0 chrome!base::debug::TaskAnnotator::RunTask+0x18e
  	0a55f6bc 6ece2c95 0e3e8208 0e3aadb0 09b2daf0 chrome!base::internal::TaskTracker::PerformRunTask+0x434
  	0a55f78c 6ecee0bd 003aadb0 09adb898 76621430 chrome!base::internal::TaskTracker::RunNextTask+0xe5
  	0a55f868 6ec62952 00000000 00000000 09adb898 chrome!base::internal::SchedulerWorker::Thread::ThreadMain+0x20d
  	*** WARNING: Unable to verify checksum for kernel32.dll
  	*** ERROR: Symbol file could not be found.  Defaulted to export symbols for kernel32.dll - 
  	0a55f884 7662337a 00000694 0a55f8d0 77a492b2 chrome!base::PlatformThread::Sleep+0x122
  	WARNING: Stack unwind information not available. Following frames may be wrong.
  	0a55f890 77a492b2 09adb898 7f81a9ea 00000000 kernel32!BaseThreadInitThunk+0x12
  	0a55f8d0 77a49285 6ec628c0 09adb898 00000000 ntdll!RtlInitializeExceptionChain+0x63
  	0a55f8e8 00000000 6ec628c0 09adb898 00000000 ntdll!RtlInitializeExceptionChain+0x36
"""

See https://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_ng/builds/497757

cc-ing owners

Comment 1 by sky@chromium.org, Jul 26 2017

Cc: gab@chromium.org
This code hasn't changed in a long time. I could see a couple of possibilities:
. task scheduling changes have some how broke this.
. we just started running with DCHECKs enabled on perf test. I have no idea if this is true, but if this is true it could explain why we are now only seeing them.
. Running out of disk space?
. Something changed in file writing in base.

The NOTREACHEDs aren't fatal, perhaps the right thing is to convert them to DVLOGs, but it would be nice to understand why these started hitting.

+gab for task scheduling changes possibly impacting this.

Comment 2 by erikc...@chromium.org, Jul 26 2017

Cc: nedngu...@google.com sullivan@chromium.org
+nednguyen, sullivan speed-ops folks.

Comment 3 by erikc...@chromium.org, Jul 26 2017 

At least between builds, space doesn't seem to be an issue.

"""
chrome-bot@VM513-M4 ~
$ df -h
Filesystem      Size  Used Avail Use% Mounted on
C:/cygwin        80G   31G   50G  39% /
E:              350G  199G  152G  57% /cygdrive/e

"""

Comment 4 by gab@chromium.org, Jul 27 2017 

Re. scheduling changes: would be possible say somethings we should be mutually exclusive no longer are but AFAICT the only caller of this is @ 

https://cs.chromium.org/chromium/src/components/sessions/core/base_session_service.cc?rcl=ec8b0b3a1c8a354f075369c5e388983672e323d6&l=142

and that one is still pending migration off of BlockingPool in chrome/browser/sessions/session_service.cc

(and it's tasks were already running in parallel per not getting a sequence from the BlockingPool so no future task scheduler change could break either IMO)

Comment 5 by gab@chromium.org, Jul 27 2017 

Hmmm hold on, this code does look racy to me.

SessionBackend::AppendCommands() uses the global |current_session_file_| from a parallel tasks (currently in BlockingPool).

That can race with SessionBackend::MoveCurrentSessionToLastSession() also posted as a parallel task (and resetting the same global |current_session_file|).

I think BaseSessionService::RunTaskOnBackendThread() needs to use a SequencedTaskRunner. What a great opportunity to complete migration of chrome/browser/sessions/session_service.cc and friends to TaskScheduler =D.

Re. why is this failing now: since many things are being moved off the BlockingPool right now, it's possible the conditions of this race have changed and it became more likely to occur but this has always been scheduling these two tasks in parallel which is incorrect.

Comment 6 by sky@chromium.org, Jul 27 2017

Labels: -Pri-3 Pri-2
Owner: sky@chromium.org
Status: Assigned (was: Untriaged)

Comment 7 by sky@chromium.org, Jul 28 2017 

gab,

> SessionBackend::AppendCommands() uses the global |current_session_file_| from a parallel tasks (currently in BlockingPool).
>
> That can race with SessionBackend::MoveCurrentSessionToLastSession() also posted as a parallel task (and resetting the same global |current_session_file|).

This is true, but the tasks are posted using PostSequencedWorkerTask() with a sequence_token_ unique to the instance, so doesn't that mean the tasks all run serially?

Comment 8 by gab@chromium.org, Jul 28 2017 

Ah oops, I always forget about the SequenceToken part of that API (I just read it as pool->PostTask()... Yes they should be serialized so I guess that's not it... hmmmm...

Comment 9 by gab@chromium.org, Jul 28 2017 

There's ~SessionBackend() that resets |current_session_file_| without posting to the sequence.

Ideally this code would use a SequenceChecker to confirm things are running on the sequence they expect.

Comment 10 by sky@chromium.org, Jul 28 2017 

SessionBackend is ref counted. That said, it does seem like ~BaseSessionService should post a task to ensure ~BaseSessionService runs on the sequenced task runner.
►

Sign in to add a comment