|
|
Created:
9 years, 11 months ago by Chris Evans Modified:
7 years, 2 months ago CC:
chromium-reviews, vrk (LEFT CHROMIUM), sjl, Alpha Left Google, ddorwin+watch_chromium.org, acolwell GONE FROM CHROMIUM, annacc, awong Base URL:
svn://svn.chromium.org/chrome/trunk/src/ Visibility:
Public. |
DescriptionUse the lock when accessing the buffer object.
BUG=69195
TEST=play Z-Type for hours :)
Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=71211
Patch Set 1 #
Total comments: 1
Messages
Total messages: 11 (0 generated)
Headache to track down, easy to fix :)
http://codereview.chromium.org/6157007/diff/1/media/audio/audio_output_contro... File media/audio/audio_output_controller.cc (right): http://codereview.chromium.org/6157007/diff/1/media/audio/audio_output_contro... media/audio/audio_output_controller.cc:231: AutoLock auto_lock(lock_); LGTM. Good catch!
oh my :( I wonder if threadsanitizer could catch this...
+thread race experts
> I wonder if threadsanitizer could catch this... It should, but only if there are tests that execute this code in multiple threads. Apparently, nobody plays Z-type under ThreadSanitizer for hours. :( afaict, this code is not executed at all when running media_unittests
On 2011/01/13 06:02:53, kcc2 wrote: > > I wonder if threadsanitizer could catch this... > It should, but only if there are tests that execute this code in multiple > threads. > Apparently, nobody plays Z-type under ThreadSanitizer for hours. :( > afaict, this code is not executed at all when running media_unittests yeah I think the buildbots don't run audio tests because not all bots are guaranteed to have functioning sound cards :(
What is the object on which you had a race? Was it AudioOutputController::buffer_? What was another function accessing it? What is the other function accessing it concurrently?
Voila. ==9818== WARNING: Possible data race during read of size 8 at 0x1D8CB4B0: {{{ ==9818== T8 (Chrome_IOThread) (L{L835}): ==9818== #0 media::SeekableBuffer::Append(media::Buffer*) media/base/seekable_buffer.cc:81 ==9818== #1 media::AudioOutputController::EnqueueData(unsigned char const*, unsigned int) media/audio/audio_output_controller.cc:138 ==9818== #2 AudioRendererHost::OnNotifyPacketReady(IPC::Message const&, int, unsigned int) chrome/browser/renderer_host/audio_renderer_host.cc:402 ==9818== #3 bool IPC::MessageWithTuple<Tuple2<int, unsigned int> >::Dispatch<AudioRendererHost, AudioRendererHost, int, unsigned int>(IPC::Message const*, AudioRendererHost*, AudioRendererHo» ==9818== #4 AudioRendererHost::OnMessageReceived(IPC::Message const&, bool*) chrome/browser/renderer_host/audio_renderer_host.cc:245 ==9818== #5 BrowserMessageFilter::DispatchMessage(IPC::Message const&) chrome/browser/browser_message_filter.cc:78 ==9818== #6 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) chrome/browser/browser_message_filter.cc:67 ==9818== #7 IPC::ChannelProxy::Context::TryFilters(IPC::Message const&) ipc/ipc_channel_proxy.cc:87 ==9818== #8 IPC::SyncChannel::SyncContext::OnMessageReceived(IPC::Message const&) ipc/ipc_sync_channel.cc:290 ==9818== #9 IPC::Channel::ChannelImpl::ProcessIncomingMessages() ipc/ipc_channel_posix.cc:739 ==9818== #10 IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) ipc/ipc_channel_posix.cc:1006 ==9818== #11 base::MessagePumpLibevent::FileDescriptorWatcher::OnFileCanReadWithoutBlocking(int, base::MessagePumpLibevent*) base/message_pump_libevent.cc:96 ==9818== Concurrent write(s) happened at (OR AFTER) these points: ==9818== T19 (AudioThread) (L{}): ==9818== #0 media::SeekableBuffer::Clear() media/base/seekable_buffer.cc:30 ==9818== #1 media::AudioOutputController::DoFlush() media/audio/audio_output_controller.cc:231 ==9818== #2 MessageLoop::RunTask(Task*) base/message_loop.cc:356 ==9818== #3 MessageLoop::DeferOrRunPendingTask(MessageLoop::PendingTask const&) base/message_loop.cc:365 ==9818== #4 MessageLoop::DoWork() base/message_loop.cc:558 ==9818== #5 base::MessagePumpDefault::Run(base::MessagePump::Delegate*) base/message_pump_default.cc:23 ==9818== #6 MessageLoop::RunInternal() base/message_loop.cc:331 ==9818== #7 MessageLoop::Run() base/message_loop.cc:234 ==9818== #8 base::Thread::ThreadMain() base/threading/thread.cc:164 ==9818== #9 base::(anonymous namespace)::ThreadFunc(void*) base/threading/platform_thread_posix.cc:51 ==9818== Location 0x1D8CB4B0 is 160 bytes inside a block starting at 0x1D8CB410 of size 200 allocated by T8 from heap: ==9818== #0 operator new(unsigned long) /home/kcc/drt/trunk/tsan/ts_valgrind_intercepts.c:418 ==9818== #1 media::AudioOutputController::Create(media::AudioOutputController::EventHandler*, AudioParameters, unsigned int) media/audio/audio_output_controller.cc:56 ==9818== #2 AudioRendererHost::OnCreateStream(IPC::Message const&, int, ViewHostMsg_Audio_CreateStream_Params const&, bool) chrome/browser/renderer_host/audio_renderer_host.cc:297 ==9818== #3 bool IPC::MessageWithTuple<Tuple3<int, ViewHostMsg_Audio_CreateStream_Params, bool> >::Dispatch<AudioRendererHost, AudioRendererHost, int, ViewHostMsg_Audio_CreateStream_Params c» ==9818== #4 AudioRendererHost::OnMessageReceived(IPC::Message const&, bool*) chrome/browser/renderer_host/audio_renderer_host.cc:240 ==9818== #5 BrowserMessageFilter::DispatchMessage(IPC::Message const&) chrome/browser/browser_message_filter.cc:78 ==9818== #6 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) chrome/browser/browser_message_filter.cc:67 ==9818== #7 IPC::ChannelProxy::Context::TryFilters(IPC::Message const&) ipc/ipc_channel_proxy.cc:87 ==9818== Locks involved in this report (reporting last lock sites): {L835} ==9818== L835 (0x1D8CB450) ==9818== #0 pthread_mutex_lock /home/kcc/drt/trunk/tsan/ts_valgrind_intercepts.c:891 ==9818== #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:44 ==9818== #2 media::AudioOutputController::EnqueueData(unsigned char const*, unsigned int) media/audio/audio_output_controller.cc:132 ==9818== #3 AudioRendererHost::OnNotifyPacketReady(IPC::Message const&, int, unsigned int) chrome/browser/renderer_host/audio_renderer_host.cc:402 ==9818== #4 bool IPC::MessageWithTuple<Tuple2<int, unsigned int> >::Dispatch<AudioRendererHost, AudioRendererHost, int, unsigned int>(IPC::Message const*, AudioRendererHost*, AudioRendererHo» ==9818== #5 AudioRendererHost::OnMessageReceived(IPC::Message const&, bool*) chrome/browser/renderer_host/audio_renderer_host.cc:245 ==9818== #6 BrowserMessageFilter::DispatchMessage(IPC::Message const&) chrome/browser/browser_message_filter.cc:78 ==9818== #7 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) chrome/browser/browser_message_filter.cc:67 ==9818== Race verifier data: 0x14D5B3E,0x14D54D7 ==9818== }}} I've built chrome before the fix (r71158) and run it on Z-type for ~5 minutes. This was painfully slow, but worked. It would be nice to have a threaded unittest for this code... :)
Cool! Yeah I have some ideas on cleaning up the code + improving testing. On 2011/01/13 08:54:01, kcc2 wrote: > Voila. > > ==9818== WARNING: Possible data race during read of size 8 at 0x1D8CB4B0: {{{ > > > ==9818== T8 (Chrome_IOThread) (L{L835}): > > > ==9818== #0 media::SeekableBuffer::Append(media::Buffer*) > media/base/seekable_buffer.cc:81 > > ==9818== #1 media::AudioOutputController::EnqueueData(unsigned char const*, > unsigned int) media/audio/audio_output_controller.cc:138 > > ==9818== #2 AudioRendererHost::OnNotifyPacketReady(IPC::Message const&, > int, unsigned int) chrome/browser/renderer_host/audio_renderer_host.cc:402 > > ==9818== #3 bool IPC::MessageWithTuple<Tuple2<int, unsigned int> > >::Dispatch<AudioRendererHost, AudioRendererHost, int, unsigned > int>(IPC::Message const*, AudioRendererHost*, AudioRendererHo» > ==9818== #4 AudioRendererHost::OnMessageReceived(IPC::Message const&, > bool*) chrome/browser/renderer_host/audio_renderer_host.cc:245 > > ==9818== #5 BrowserMessageFilter::DispatchMessage(IPC::Message const&) > chrome/browser/browser_message_filter.cc:78 > > ==9818== #6 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) > chrome/browser/browser_message_filter.cc:67 > > ==9818== #7 IPC::ChannelProxy::Context::TryFilters(IPC::Message const&) > ipc/ipc_channel_proxy.cc:87 > > ==9818== #8 IPC::SyncChannel::SyncContext::OnMessageReceived(IPC::Message > const&) ipc/ipc_sync_channel.cc:290 > > ==9818== #9 IPC::Channel::ChannelImpl::ProcessIncomingMessages() > ipc/ipc_channel_posix.cc:739 > > ==9818== #10 IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) > ipc/ipc_channel_posix.cc:1006 > > ==9818== #11 > base::MessagePumpLibevent::FileDescriptorWatcher::OnFileCanReadWithoutBlocking(int, > base::MessagePumpLibevent*) base/message_pump_libevent.cc:96 > > ==9818== Concurrent write(s) happened at (OR AFTER) these points: > > > ==9818== T19 (AudioThread) (L{}): > > > ==9818== #0 media::SeekableBuffer::Clear() media/base/seekable_buffer.cc:30 > > > ==9818== #1 media::AudioOutputController::DoFlush() > media/audio/audio_output_controller.cc:231 > > ==9818== #2 MessageLoop::RunTask(Task*) base/message_loop.cc:356 > > > ==9818== #3 MessageLoop::DeferOrRunPendingTask(MessageLoop::PendingTask > const&) base/message_loop.cc:365 > > ==9818== #4 MessageLoop::DoWork() base/message_loop.cc:558 > > > ==9818== #5 base::MessagePumpDefault::Run(base::MessagePump::Delegate*) > base/message_pump_default.cc:23 > > ==9818== #6 MessageLoop::RunInternal() base/message_loop.cc:331 > > > ==9818== #7 MessageLoop::Run() base/message_loop.cc:234 > > > ==9818== #8 base::Thread::ThreadMain() base/threading/thread.cc:164 > > > ==9818== #9 base::(anonymous namespace)::ThreadFunc(void*) > base/threading/platform_thread_posix.cc:51 > > ==9818== Location 0x1D8CB4B0 is 160 bytes inside a block starting at > 0x1D8CB410 of size 200 allocated by T8 from heap: > > ==9818== #0 operator new(unsigned long) > /home/kcc/drt/trunk/tsan/ts_valgrind_intercepts.c:418 > > ==9818== #1 > media::AudioOutputController::Create(media::AudioOutputController::EventHandler*, > AudioParameters, unsigned int) media/audio/audio_output_controller.cc:56 > > ==9818== #2 AudioRendererHost::OnCreateStream(IPC::Message const&, int, > ViewHostMsg_Audio_CreateStream_Params const&, bool) > chrome/browser/renderer_host/audio_renderer_host.cc:297 > ==9818== #3 bool IPC::MessageWithTuple<Tuple3<int, > ViewHostMsg_Audio_CreateStream_Params, bool> >::Dispatch<AudioRendererHost, > AudioRendererHost, int, ViewHostMsg_Audio_CreateStream_Params c» > ==9818== #4 AudioRendererHost::OnMessageReceived(IPC::Message const&, > bool*) chrome/browser/renderer_host/audio_renderer_host.cc:240 > > ==9818== #5 BrowserMessageFilter::DispatchMessage(IPC::Message const&) > chrome/browser/browser_message_filter.cc:78 > > ==9818== #6 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) > chrome/browser/browser_message_filter.cc:67 > > ==9818== #7 IPC::ChannelProxy::Context::TryFilters(IPC::Message const&) > ipc/ipc_channel_proxy.cc:87 > > ==9818== Locks involved in this report (reporting last lock sites): {L835} > > > ==9818== L835 (0x1D8CB450) > > > ==9818== #0 pthread_mutex_lock > /home/kcc/drt/trunk/tsan/ts_valgrind_intercepts.c:891 > > ==9818== #1 base::internal::LockImpl::Lock() > base/synchronization/lock_impl_posix.cc:44 > > ==9818== #2 media::AudioOutputController::EnqueueData(unsigned char const*, > unsigned int) media/audio/audio_output_controller.cc:132 > > ==9818== #3 AudioRendererHost::OnNotifyPacketReady(IPC::Message const&, > int, unsigned int) chrome/browser/renderer_host/audio_renderer_host.cc:402 > > ==9818== #4 bool IPC::MessageWithTuple<Tuple2<int, unsigned int> > >::Dispatch<AudioRendererHost, AudioRendererHost, int, unsigned > int>(IPC::Message const*, AudioRendererHost*, AudioRendererHo» > ==9818== #5 AudioRendererHost::OnMessageReceived(IPC::Message const&, > bool*) chrome/browser/renderer_host/audio_renderer_host.cc:245 > > ==9818== #6 BrowserMessageFilter::DispatchMessage(IPC::Message const&) > chrome/browser/browser_message_filter.cc:78 > > ==9818== #7 BrowserMessageFilter::OnMessageReceived(IPC::Message const&) > chrome/browser/browser_message_filter.cc:67 > > ==9818== Race verifier data: 0x14D5B3E,0x14D54D7 > > > ==9818== }}} > > I've built chrome before the fix (r71158) and run it on Z-type for ~5 minutes. > This was painfully slow, but worked. > > It would be nice to have a threaded unittest for this code... :)
Do you mean "the tests are not run anywhere" or "the tests are not run on the machines with no soundcards" ? On 2011/01/13 06:29:47, scherkus wrote: > On 2011/01/13 06:02:53, kcc2 wrote: > > > I wonder if threadsanitizer could catch this... > > It should, but only if there are tests that execute this code in multiple > > threads. > > Apparently, nobody plays Z-type under ThreadSanitizer for hours. :( > > afaict, this code is not executed at all when running media_unittests > > yeah I think the buildbots don't run audio tests because not all bots are > guaranteed to have functioning sound cards :(
On 2011/01/18 15:17:53, Timur Iskhodzhanov wrote: > Do you mean "the tests are not run anywhere" or "the tests are not run on the > machines with no soundcards" ? None of the tests in audio_output_controller_unittest.cc run because it checks for CHROME_HEADLESS environment variable, which I believe every bot defines whether it has a sound card or not. |