DCHECK in TOT chromeos chrome on device |
||||||||
Issue description
#0 0x000056ee15a4ceea in logging::LogMessage::~LogMessage() ()
at ../../base/logging.cc:874
#1 0x000056ee15ac8d66 in base::internal::AssertBlockingAllowed() ()
at ../../base/threading/thread_restrictions.cc:34
#2 0x000056ee15ac47a6 in base::ScopedBlockingCall::ScopedBlockingCall(base::BlockingType) () at ../../base/threading/scoped_blocking_call.cc:86
#3 0x000056ee15afa8e1 in base::OpenFile(base::FilePath const&, char const*)
() at ../../base/files/file_util_posix.cc:789
#4 0x000056ee15a46448 in base::ReadFileToStringWithMaxSize(base::FilePath const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >*, unsigned long) () at ../../base/files/file_util.cc:135
#5 0x000056ee15a49309 in JSONFileValueDeserializer::Deserialize(int*, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >*) () at ../../base/json/json_file_value_serializer.cc:63
at ../../rlz/chromeos/lib/rlz_value_store_chromeos.cc:348
#7 0x000056ee137c3d71 in rlz_lib::ScopedRlzValueStoreLock::ScopedRlzValueStoreLock() () at ../../rlz/chromeos/lib/rlz_value_store_chromeos.cc:122
(Internal error: pc 0x56ee137c0fce in read in CU, but not in symtab.)
#8 0x000056ee137c6067 in rlz_lib::UpdateExistingAccessPointRlz(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&)
() at ../../rlz/lib/rlz_lib.cc:357
#9 0x000056ee187826da in rlz::RLZTracker::Init(bool, bool, base::TimeDelta, bool, bool, bool) () at ../../components/rlz/rlz_tracker.cc:306
#10 0x000056ee187823f9 in rlz::RLZTracker::InitRlzDelayed(bool, bool, base::TimeDelta, bool, bool, bool) () at ../../components/rlz/rlz_tracker.cc:258
#11 0x000056ee13dc53da in chromeos::UserSessionManager::InitRlzImpl(Profile*, chromeos::UserSessionManager::RlzInitParams const&) ()
at ../../chrome/browser/chromeos/login/session/user_session_manager.cc:1796
#12 0x000056ee12df6d00 in base::internal::Invoker<base::internal::BindState<void (headless::HeadlessWebContentsImpl::*)(headless::HeadlessWebContentsImpl::PendingFrame*, SkBitmap const&), base::WeakPtr<headless::HeadlessWebContentsImpl>, headless::HeadlessWebContentsImpl::PendingFrame*>, void (SkBitmap const&)>::RunOnce(base::internal::BindStateBase*, SkBitmap const&) ()
at ../../base/bind_internal.h:516
#13 0x000056ee1228d4b1 in void base::internal::ReplyAdapter<std::__1::vector<unsigned int, std::__1::allocator<unsigned int> >, std::__1::vector<unsigned int, std::__1::allocator<unsigned int> > const&>(base::OnceCallback<void (std::__1::vector<unsigned int, std::__1::allocator<unsigned int> > const&)>, std::__1::unique_ptr<std::__1::vector<unsigned int, std::__1::allocator<unsigned int> >, std::__1::default_delete<std::__1::vector<unsigned int, std::__1::allocator<unsigned int> > > >*) () at ../../base/callback.h:99
#14 0x000056ee11bd9c07 in base::internal::Invoker<base::internal::BindState<void (*)(base::OnceCallback<void (unsigned long)>, std::__1::unique_ptr<unsigned long, std::__1::default_delete<unsigned long> >*), base::OnceCallback<void (unsigned long)>, base::internal::OwnedWrapper<std::__1::unique_ptr<unsigned long, std::__1::default_delete<unsigned long> > > >, void ()>::RunOnce(base::internal::BindStateBase*) () at ../../base/bind_internal.h:416
#15 0x000056ee15ac4450 in base::(anonymous namespace)::PostTaskAndReplyRelay::RunReply(base::(anonymous namespace)::PostTaskAndReplyRelay) ()
at ../../base/callback.h:99
#16 0x000056ee15ac450b in base::internal::Invoker<base::internal::BindState<void (*)(base::(anonymous namespace)::PostTaskAndReplyRelay), base::(anonymous namespace)::PostTaskAndReplyRelay>, void ()>::RunOnce(base::internal::BindStateBase*) () at ../../base/bind_internal.h:416
(Internal error: pc 0x56ee15b18166 in read in CU, but not in symtab.)
#18 0x000056ee15a56a7f in base::MessageLoopImpl::RunTask(base::PendingTask*)
() at ../../base/message_loop/message_loop_impl.cc:462
#19 0x000056ee15a57132 in base::MessageLoopImpl::DoWork() ()
at ../../base/message_loop/message_loop_impl.cc:473
#20 0x000056ee15b14239 in base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) () at ../../base/message_loop/message_pump_libevent.cc:210
#21 0x000056ee15a56555 in base::MessageLoopImpl::Run(bool) ()
at ../../base/message_loop/message_loop_impl.cc:414
#22 0x000056ee15a80496 in base::RunLoop::Run() ()
at ../../base/run_loop.cc:102
#23 0x000056ee1559a005 in ChromeBrowserMainParts::MainMessageLoopRun(int*) ()
at ../../chrome/browser/chrome_browser_main.cc:1922
#24 0x000056ee12dcf184 in content::BrowserMainLoop::RunMainMessageLoopParts()
() at ../../content/browser/browser_main_loop.cc:993
#25 0x000056ee12dd1b43 in content::BrowserMainRunnerImpl::Run() ()
at ../../content/browser/browser_main_runner_impl.cc:165
#26 0x000056ee12dcb91f in content::BrowserMain(content::MainFunctionParams const&) () at ../../content/browser/browser_main.cc:47
#27 0x000056ee1558aae8 in content::ContentMainRunnerImpl::Run(bool) ()
at ../../content/app/content_main_runner_impl.cc:537
#28 0x000056ee15591f3f in service_manager::Main(service_manager::MainParams const&) () at ../../services/service_manager/embedder/main.cc:472
#29 0x000056ee15588c51 in content::ContentMain(content::ContentMainParams const&) () at ../../content/app/content_main.cc:19
#30 0x000056ee11b7015f in ChromeMain () at ../../chrome/app/chrome_main.cc:102
#31 0x00007c37649b7a94 in __libc_start_main (main=0x56ee11b700c0 <main>,
argc=30, argv=0x7ffdbc58f668, init=<optimized out>, fini=<optimized out>,
rtld_fini=<optimized out>, stack_end=0x7ffdbc58f658)
at ../csu/libc-start.c:308
#32 0x000056ee11b6ff89 in _start ()
,
Nov 17
Does this happen in a VM? Which device?
,
Nov 17
I can repo on a device with dcheck_always_on. Should be a simple fix.
,
Nov 19
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4da12d2dae516cbd8dd16fdb2da75b6662c382ae commit 4da12d2dae516cbd8dd16fdb2da75b6662c382ae Author: Wenzhao Zang <wzang@chromium.org> Date: Mon Nov 19 20:56:16 2018 cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz |UpdateExistingAccessPointRlz| involves file I/O, so it should be posted on a task runner that has MayBlock() in its TaskTraits. |background_task_runner_| serves this purpose. Bug: 906293 Change-Id: If36215767a0dbcfbad56c0432b16b584f6185376 Reviewed-on: https://chromium-review.googlesource.com/c/1340607 Reviewed-by: Roger Tawa <rogerta@chromium.org> Commit-Queue: Wenzhao (Colin) Zang <wzang@chromium.org> Cr-Commit-Position: refs/heads/master@{#609428} [modify] https://crrev.com/4da12d2dae516cbd8dd16fdb2da75b6662c382ae/components/rlz/rlz_tracker.cc
,
Nov 19
,
Nov 21
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/1ce4b50b4e3b26296397ac876769d895540c70b8 commit 1ce4b50b4e3b26296397ac876769d895540c70b8 Author: Hayato Ito <hayato@chromium.org> Date: Wed Nov 21 08:12:23 2018 Revert "cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz" This reverts commit 4da12d2dae516cbd8dd16fdb2da75b6662c382ae. Reason for revert: Flakiness of RlzLibTest.DelayedInitOnlyNoFirstRun The bug is https://crbug.com/907379 Culprit (70.0% confidence): r609428 Original change's description: > cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz > > |UpdateExistingAccessPointRlz| involves file I/O, so it should be > posted on a task runner that has MayBlock() in its TaskTraits. > |background_task_runner_| serves this purpose. > > Bug: 906293 > Change-Id: If36215767a0dbcfbad56c0432b16b584f6185376 > Reviewed-on: https://chromium-review.googlesource.com/c/1340607 > Reviewed-by: Roger Tawa <rogerta@chromium.org> > Commit-Queue: Wenzhao (Colin) Zang <wzang@chromium.org> > Cr-Commit-Position: refs/heads/master@{#609428} TBR=rogerta@chromium.org,wzang@chromium.org # Not skipping CQ checks because original CL landed > 1 day ago. Bug: 906293 Change-Id: I20dbe6c1f73e3599aa30cf8b74512122ad2d0a25 Reviewed-on: https://chromium-review.googlesource.com/c/1345707 Reviewed-by: Hayato Ito <hayato@chromium.org> Commit-Queue: Hayato Ito <hayato@chromium.org> Cr-Commit-Position: refs/heads/master@{#609948} [modify] https://crrev.com/1ce4b50b4e3b26296397ac876769d895540c70b8/components/rlz/rlz_tracker.cc
,
Nov 21
,
Nov 27
,
Nov 28
Issue 902714 has been merged into this issue.
,
Nov 28
We need to fix this asap because it occurs on login and prevents other developers from enabling DCHECK.
,
Nov 28
I hoped to spend some time investigating on the flakiness ( crbug.com/907379 ), but given its urgency, I would reland the CL in #6 with a speculative fix first.
,
Dec 3
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/1d497322e9fd8d9ab1da00767e30c618186151c6 commit 1d497322e9fd8d9ab1da00767e30c618186151c6 Author: Wenzhao Zang <wzang@chromium.org> Date: Mon Dec 03 18:43:40 2018 cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz In addition to fixing the DCHECK, this CL contains a speculative fix for flaky test ( crbug.com/907379 ). The guess for the flakiness is (not able to repro the failure locally though): |RecordProductEvent| may fail to acquire the |ScopedRlzValueStoreLock| when recording the CAI event, because the lock is being taken by |UpdateExistingAccessPointRlz|. In tests, the delay for |ScheduleDelayedInit| is set to zero, so it's possible for this race condition to happen. But in production, the delay is non-zero. I don't think we're losing test coverage by disabling |UpdateExistingAccessPointRlz| here because the call is a no-op in tests, and another test (RlzLibTest.UpdateExistingAccessPointRlz) is testing its implementation. Bug: 906293 , 907379 Change-Id: I208919f22edc09fc1a739a1efe1909a71e5a2730 Reviewed-on: https://chromium-review.googlesource.com/c/1353990 Reviewed-by: Roger Tawa <rogerta@chromium.org> Commit-Queue: Wenzhao (Colin) Zang <wzang@chromium.org> Cr-Commit-Position: refs/heads/master@{#613172} [modify] https://crrev.com/1d497322e9fd8d9ab1da00767e30c618186151c6/chrome/browser/rlz/chrome_rlz_tracker_delegate.cc [modify] https://crrev.com/1d497322e9fd8d9ab1da00767e30c618186151c6/chrome/browser/rlz/chrome_rlz_tracker_delegate.h [modify] https://crrev.com/1d497322e9fd8d9ab1da00767e30c618186151c6/components/rlz/rlz_tracker.cc [modify] https://crrev.com/1d497322e9fd8d9ab1da00767e30c618186151c6/components/rlz/rlz_tracker_delegate.h [modify] https://crrev.com/1d497322e9fd8d9ab1da00767e30c618186151c6/components/rlz/rlz_tracker_unittest.cc
,
Dec 3
,
Dec 4
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/52f966107c7d77bc6121cfb843bcd8649801cf0f commit 52f966107c7d77bc6121cfb843bcd8649801cf0f Author: Jérôme Lebel <jlebel@chromium.org> Date: Tue Dec 04 06:19:46 2018 Revert "cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz" This reverts commit 1d497322e9fd8d9ab1da00767e30c618186151c6. Reason for revert: This patch breaks Chrome iOS ../../ios/chrome/browser/ios_chrome_main_parts.mm:175:56: error: allocating an object of abstract class type 'RLZTrackerDelegateImpl' rlz::RLZTracker::SetRlzDelegate(base::WrapUnique(new RLZTrackerDelegateImpl)); Original change's description: > cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz > > In addition to fixing the DCHECK, this CL contains a speculative fix > for flaky test ( crbug.com/907379 ). The guess for the flakiness is > (not able to repro the failure locally though): > > |RecordProductEvent| may fail to acquire the |ScopedRlzValueStoreLock| > when recording the CAI event, because the lock is being taken by > |UpdateExistingAccessPointRlz|. In tests, the delay for > |ScheduleDelayedInit| is set to zero, so it's possible for this race > condition to happen. But in production, the delay is non-zero. > > I don't think we're losing test coverage by disabling > |UpdateExistingAccessPointRlz| here because the call is a no-op in > tests, and another test (RlzLibTest.UpdateExistingAccessPointRlz) is > testing its implementation. > > Bug: 906293 , 907379 > Change-Id: I208919f22edc09fc1a739a1efe1909a71e5a2730 > Reviewed-on: https://chromium-review.googlesource.com/c/1353990 > Reviewed-by: Roger Tawa <rogerta@chromium.org> > Commit-Queue: Wenzhao (Colin) Zang <wzang@chromium.org> > Cr-Commit-Position: refs/heads/master@{#613172} TBR=rogerta@chromium.org,wzang@chromium.org Change-Id: Ie7888c8175087b921972a86e475415032c58db07 No-Presubmit: true No-Tree-Checks: true No-Try: true Bug: 906293 , 907379 Reviewed-on: https://chromium-review.googlesource.com/c/1360274 Reviewed-by: Jérôme Lebel <jlebel@chromium.org> Commit-Queue: Jérôme Lebel <jlebel@chromium.org> Cr-Commit-Position: refs/heads/master@{#613447} [modify] https://crrev.com/52f966107c7d77bc6121cfb843bcd8649801cf0f/chrome/browser/rlz/chrome_rlz_tracker_delegate.cc [modify] https://crrev.com/52f966107c7d77bc6121cfb843bcd8649801cf0f/chrome/browser/rlz/chrome_rlz_tracker_delegate.h [modify] https://crrev.com/52f966107c7d77bc6121cfb843bcd8649801cf0f/components/rlz/rlz_tracker.cc [modify] https://crrev.com/52f966107c7d77bc6121cfb843bcd8649801cf0f/components/rlz/rlz_tracker_delegate.h [modify] https://crrev.com/52f966107c7d77bc6121cfb843bcd8649801cf0f/components/rlz/rlz_tracker_unittest.cc
,
Dec 6
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/0d2a5a88a940d3df25c6a074824adb6a901e099f commit 0d2a5a88a940d3df25c6a074824adb6a901e099f Author: Jérôme Lebel <jlebel@chromium.org> Date: Thu Dec 06 10:13:37 2018 Reland "cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz" This is a reland of 1d497322e9fd8d9ab1da00767e30c618186151c6 This patch also includes implementation for: RLZTrackerDelegateImpl::ShouldUpdateExistingAccessPointRlz() Original change's description: > cros: Fix DCHECK for rlz_lib::UpdateExistingAccessPointRlz > > In addition to fixing the DCHECK, this CL contains a speculative fix > for flaky test ( crbug.com/907379 ). The guess for the flakiness is > (not able to repro the failure locally though): > > |RecordProductEvent| may fail to acquire the |ScopedRlzValueStoreLock| > when recording the CAI event, because the lock is being taken by > |UpdateExistingAccessPointRlz|. In tests, the delay for > |ScheduleDelayedInit| is set to zero, so it's possible for this race > condition to happen. But in production, the delay is non-zero. > > I don't think we're losing test coverage by disabling > |UpdateExistingAccessPointRlz| here because the call is a no-op in > tests, and another test (RlzLibTest.UpdateExistingAccessPointRlz) is > testing its implementation. > > Bug: 906293 , 907379 > Change-Id: I208919f22edc09fc1a739a1efe1909a71e5a2730 > Reviewed-on: https://chromium-review.googlesource.com/c/1353990 > Reviewed-by: Roger Tawa <rogerta@chromium.org> > Commit-Queue: Wenzhao (Colin) Zang <wzang@chromium.org> > Cr-Commit-Position: refs/heads/master@{#613172} Bug: 906293 , 907379 , 911439 Change-Id: Ic1d9f85bc3714f890d2dc7fcc1d070d0711baec0 Reviewed-on: https://chromium-review.googlesource.com/c/1360692 Commit-Queue: Jérôme Lebel <jlebel@chromium.org> Reviewed-by: Wenzhao (Colin) Zang <wzang@chromium.org> Reviewed-by: Rohit Rao <rohitrao@chromium.org> Reviewed-by: Roger Tawa <rogerta@chromium.org> Reviewed-by: Jérôme Lebel <jlebel@chromium.org> Cr-Commit-Position: refs/heads/master@{#614303} [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/chrome/browser/rlz/chrome_rlz_tracker_delegate.cc [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/chrome/browser/rlz/chrome_rlz_tracker_delegate.h [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/components/rlz/rlz_tracker.cc [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/components/rlz/rlz_tracker_delegate.h [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/components/rlz/rlz_tracker_unittest.cc [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/ios/chrome/browser/rlz/rlz_tracker_delegate_impl.cc [modify] https://crrev.com/0d2a5a88a940d3df25c6a074824adb6a901e099f/ios/chrome/browser/rlz/rlz_tracker_delegate_impl.h
,
Dec 6
Issue 910828 has been merged into this issue. |
||||||||
►
Sign in to add a comment |
||||||||
Comment 1 by achuith@chromium.org
, Nov 17