New issue
Advanced search Search tips

Issue 708245 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Jul 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug



Sign in to add a comment

PCHECKs in OFFICIAL_BUILD are stripped of key error information

Project Member Reported by rsesek@chromium.org, Apr 4 2017

Issue description

Consider code like this:

https://cs.chromium.org/chromium/src/sandbox/linux/services/thread_helpers.cc?type=cs&q=IsSingleThreadedImpl&l=37
 40   int fstat_ret = fstatat(proc_fd, "self/task/", &task_stat, 0);
 41   PCHECK(0 == fstat_ret);

In a non-official build, PCHECK will read errno, convert it to a string, and then write it to the LOG(FATAL) stream.

But in OFFICIAL_BUILD mode, P/CHECK has EAT_STREAM_PARAMETERS, which means the PLOG_STREAM info gets dropped. This makes it improbable to recover the errno value, since that is typically stored in TLS and is not captured by crash dumps. Because of the eaten stream, even if you manually examine the minidump memory, you're not going to be able to recover anything about the error situation, except that the CHECK was tripped.

One possible idea for PCHECK would be to manually grab errno and either push it onto the stack or load it into a known register. The former is probably better to preserve the register state, though.
 
Labels: -OS-Chrome

Comment 2 by rsesek@chromium.org, Jul 25 2017

Cc: dcheng@chromium.org
Owner: rsesek@chromium.org
Status: Started (was: Assigned)
https://chromium-review.googlesource.com/c/584817
Project Member

Comment 3 by bugdroid1@chromium.org, Jul 25 2017

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

commit d2f495f421a722cd282683f7283d7894697a48f1
Author: Robert Sesek <rsesek@chromium.org>
Date: Tue Jul 25 22:03:14 2017

Include system error message in PCHECK for OFFICIAL_BUILDs.

After ba910a65a5a63594dc8558b337c3cb12028bc4fd the CHECK macro, which is used to
implement PCHECK, dropped all logging stream messages. For PCHECK, this meant
that the system error code and message were no longer included in crash reports.
Particularly on POSIX, this made difficult retrieving essential information
about why the condition failed, as errno is stored in TLS and is not easily
captured by crash reports.

This change reimplements PCHECK for OFFICIAL_BUILD to include only the system
error code information, but it discards all other logging streams, including the
stringified condition.

Bug:  708245 
Change-Id: Ib39359370fba8b6aabe2f9c1a76783d838e2a926
Reviewed-on: https://chromium-review.googlesource.com/584817
Reviewed-by: Nico Weber <thakis@chromium.org>
Commit-Queue: Robert Sesek <rsesek@chromium.org>
Cr-Commit-Position: refs/heads/master@{#489457}
[modify] https://crrev.com/d2f495f421a722cd282683f7283d7894697a48f1/base/logging.cc
[modify] https://crrev.com/d2f495f421a722cd282683f7283d7894697a48f1/base/logging.h

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

Status: Fixed (was: Started)
Hooray!

https://crash.corp.google.com/browse?q=ReportID%3D%27ed7cb30140000000%27&ignore_case=false&enable_rewrite=true&omit_field_name=&omit_field_value=&omit_field_opt=%3D

LOG_FATAL=scoped_file.cc:48: : Bad file descriptor (9)

0x00000001029fb9e1	(Google Chrome Framework -debugger_posix.cc:267 )	base::debug::BreakDebugger()
0x0000000102a150e0	(Google Chrome Framework -logging.cc:784 )	logging::LogMessage::~LogMessage()
0x0000000102a1533d	(Google Chrome Framework -logging.cc:547 )	logging::ErrnoLogMessage::~ErrnoLogMessage()
0x0000000102a0fc1a	(Google Chrome Framework -scoped_file.cc:48 )	base::internal::ScopedFDCloseTraits::Free(int)
0x0000000102a082c3	(Google Chrome Framework -scoped_generic.h:146 )	base::File::Close()
0x0000000102dfb9eb	(Google Chrome Framework -simple_synchronous_entry.cc:1015 )	disk_cache::SimpleSynchronousEntry::CloseFiles()
0x0000000102dfb967	(Google Chrome Framework -simple_synchronous_entry.cc:833 )	disk_cache::SimpleSynchronousEntry::~SimpleSynchronousEntry()
0x0000000102df89ff	(Google Chrome Framework -simple_synchronous_entry.cc:830 )	disk_cache::SimpleSynchronousEntry::OpenEntry(net::CacheType, base::FilePath const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned long long, bool, base::TimeTicks const&, disk_cache::SimpleEntryCreationResults*)
0x0000000102df003d	(Google Chrome Framework -bind_internal.h:151 )	base::internal::Invoker<base::internal::BindState<void (*)(net::CacheType, base::FilePath const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned long long, bool, base::TimeTicks const&, disk_cache::SimpleEntryCreationResults*), net::CacheType, base::FilePath, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, unsigned long long, bool, base::TimeTicks, disk_cache::SimpleEntryCreationResults*>, void ()>::Run(base::internal::BindStateBase*)
0x0000000102a74198	(Google Chrome Framework -callback.h:91 )	base::(anonymous namespace)::PostTaskAndReplyRelay::RunTaskAndPostReply()
0x00000001029fc551	(Google Chrome Framework -callback.h:91 )	base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)
0x0000000102a68c70	(Google Chrome Framework -task_tracker.cc:335 )	base::internal::TaskTracker::PerformRunTask(std::__1::unique_ptr<base::internal::Task, std::__1::default_delete<base::internal::Task> >, base::internal::Sequence*)
0x0000000102a691a2	(Google Chrome Framework -task_tracker_posix.cc:22 )	base::internal::TaskTrackerPosix::PerformRunTask(std::__1::unique_ptr<base::internal::Task, std::__1::default_delete<base::internal::Task> >, base::internal::Sequence*)
0x0000000102a688e3	(Google Chrome Framework -task_tracker.cc:251 )	base::internal::TaskTracker::RunNextTask(base::internal::Sequence*)
0x0000000102a64048	(Google Chrome Framework -scheduler_worker.cc:84 )	base::internal::SchedulerWorker::Thread::ThreadMain()
0x0000000102a73fc6	(Google Chrome Framework -platform_thread_posix.cc:71 )	base::(anonymous namespace)::ThreadFunc(void*)
0x00007fff95cf9059	(libsystem_pthread.dylib + 0x00004059 )	_pthread_body
0x00007fff95cf8fd6	(libsystem_pthread.dylib + 0x00003fd6 )	_pthread_start
0x00007fff95cf63ec	(libsystem_pthread.dylib + 0x000013ec )	thread_start
0x0000000102a73f6f	(Google Chrome Framework + 0x01b7bf6f )	

https://crash.corp.google.com/browse?q=ReportID%3D%2745e577a268000000%27&ignore_case=false&enable_rewrite=true&omit_field_name=&omit_field_value=&omit_field_opt=%3D

LOG_FATAL=platform_channel_pair_posix.cc:68: : Too many open files in system (23)

0x0000000106e229e1	(Google Chrome Framework -debugger_posix.cc:267 )	base::debug::BreakDebugger()
0x0000000106e3c0e0	(Google Chrome Framework -logging.cc:784 )	logging::LogMessage::~LogMessage()
0x0000000106e3c33d	(Google Chrome Framework -logging.cc:547 )	logging::ErrnoLogMessage::~ErrnoLogMessage()
0x000000010569fd45	(Google Chrome Framework -platform_channel_pair_posix.cc:68 )	mojo::edk::PlatformChannelPair::PlatformChannelPair(bool)
0x00000001082d5c7e	(Google Chrome Framework -node_controller.cc:1060 )	mojo::edk::NodeController::OnRequestIntroduction(mojo::edk::ports::NodeName const&, mojo::edk::ports::NodeName const&)
0x00000001082ce550	(Google Chrome Framework -node_channel.cc:646 )	mojo::edk::NodeChannel::OnChannelMessage(void const*, unsigned long, std::__1::unique_ptr<std::__1::vector<mojo::edk::PlatformHandle, std::__1::allocator<mojo::edk::PlatformHandle> >, mojo::edk::PlatformHandleVectorDeleter>)
0x00000001082beb6d	(Google Chrome Framework -channel.cc:711 )	mojo::edk::Channel::OnReadComplete(unsigned long, unsigned long*)
0x00000001082bfea0	(Google Chrome Framework -channel_posix.cc:320 )	mojo::edk::(anonymous namespace)::ChannelPosix::OnFileCanReadWithoutBlocking(int)
0x0000000106e4ca16	(Google Chrome Framework -message_pump_libevent.cc:97 )	base::MessagePumpLibevent::OnLibeventNotification(int, short, void*)
0x0000000106ed972b	(Google Chrome Framework -event.c:381 )	event_base_loop
0x0000000106e4cc2d	(Google Chrome Framework -message_pump_libevent.cc:224 )	base::MessagePumpLibevent::Run(base::MessagePump::Delegate*)
0x0000000106e6fd02	(Google Chrome Framework -run_loop.cc:112 )	base::RunLoop::Run()
0x0000000105915953	(Google Chrome Framework -browser_thread_impl.cc:278 )	content::BrowserThreadImpl::IOThreadRun(base::RunLoop*)
0x0000000105915a13	(Google Chrome Framework -browser_thread_impl.cc:313 )	content::BrowserThreadImpl::Run(base::RunLoop*)
0x0000000106ea0b58	(Google Chrome Framework -thread.cc:338 )	base::Thread::ThreadMain()
0x0000000106e9afc6	(Google Chrome Framework -platform_thread_posix.cc:71 )	base::(anonymous namespace)::ThreadFunc(void*)
0x00007fff8b8b999c	(libsystem_pthread.dylib + 0x0000399c )	_pthread_body
0x00007fff8b8b9919	(libsystem_pthread.dylib + 0x00003919 )	_pthread_start
0x00007fff8b8b7350	(libsystem_pthread.dylib + 0x00001350 )	thread_start
0x0000000106e9af6f	(Google Chrome Framework + 0x01b7bf6f )	

I was also able to retrieve the aliased errno from the stackdump:

60f4550800700000  000070000855f460 %rbp logging::ErrnoLogMessage::~ErrnoLogMessage()
3ec3e30601000000  0000000106e3c33e logging::ErrnoLogMessage::~ErrnoLogMessage()
0000000000000000
1700000000000000  0x17 = 23 (ENFILE)
2200000000000000
50ec936dba7f0000  00007fba6d93ec4f <heap>
f03b006bba7f0000  00007fba6b003bf0 <heap>
0000000000000000
e0f5550800700000  000070000855f5e0 <heap>
46fd690501000000  000000010569fd46 mojo::edk::PlatformChannelPair::PlatformChannelPair(bool)
00e00b0501000000  00000001050be000
1700000000000000
03000000ba7f0000  00007fba00000003
689a320c01000000  000000010c329a68 vtable for std::__1::basic_ostringstream<char, std::__1::char_traits<char>, std::__1::allocator<char> >
2099320c01000000  000000010c329920 vtable for std::__1::basic_ostringstream<char, std::__1::char_traits<char>, std::__1::allocator<char> >
307ce974ff7f0000  00007fff74e97c30 <heap>

Sign in to add a comment