1136453 - Assertion failure in nsPipe::AdvanceReadCursor

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Seth Fowler [:seth] [:s2h]]

While debugging bug 1130607 I triggered an assertion failure in nsPipe::AdvanceReadCursor. The assertion that failed is "*aAvailableOut >= aBytesRead"; it failed because *aAvailableOut is 0 but aBytesRead is 5840.

To reproduce, follow the STR for bug 1130607 (note that the User Agent Overridder addon has a bug where its icon starts invisible, so you'll have to click blindly to find the dropdown to enable it to the right of the invisible icon) and then start scrolling quickly down the page. I'm not sure how easy this is to reproduce. I only did this two or three times before triggering the bug. I had shift-refreshed many times before that, though.

The crash happens on the ImageIO thread during an off-main-thread delivery of OnDataAvailable. Here's the stack:

#0	0x00000001016c6cb2 in nsPipe::AdvanceReadCursor(nsPipeReadState&, unsigned int, unsigned int*) at /Users/mfowler/Code/mozdev/xpcom/io/nsPipe3.cpp:550
#1	0x00000001016c9e4a in nsPipeInputStream::ReadSegments(nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) at /Users/mfowler/Code/mozdev/xpcom/io/nsPipe3.cpp:1164
#2	0x00000001016b69e0 in nsInputStreamTee::ReadSegments(nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) at /Users/mfowler/Code/mozdev/xpcom/io/nsInputStreamTee.cpp:273
#3	0x0000000102c1edc2 in mozilla::image::RasterImage::OnImageDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/image/src/RasterImage.cpp:1210
#4	0x0000000102c4634d in imgRequest::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/image/src/imgRequest.cpp:930
#5	0x0000000102c344fc in ProxyListener::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/image/src/imgLoader.cpp:2485
#6	0x00000001018c0152 in nsStreamListenerTee::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/netwerk/base/nsStreamListenerTee.cpp:93
#7	0x0000000101b347e6 in mozilla::net::nsHttpChannel::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/netwerk/protocol/http/nsHttpChannel.cpp:5740
#8	0x0000000101b34f8f in non-virtual thunk to mozilla::net::nsHttpChannel::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) at /Users/mfowler/Code/mozdev/netwerk/protocol/http/nsHttpChannel.cpp:5774
#9	0x000000010185838e in nsInputStreamPump::OnStateTransfer() at /Users/mfowler/Code/mozdev/netwerk/base/nsInputStreamPump.cpp:607
#10	0x0000000101857a8d in nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream*) at /Users/mfowler/Code/mozdev/netwerk/base/nsInputStreamPump.cpp:436
#11	0x0000000101858baf in non-virtual thunk to nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream*) at /Users/mfowler/Code/mozdev/netwerk/base/nsInputStreamPump.cpp:502
#12	0x00000001016d9e40 in nsInputStreamReadyEvent::Run() at /Users/mfowler/Code/mozdev/xpcom/io/nsStreamUtils.cpp:90
#13	0x0000000101709535 in nsThread::ProcessNextEvent(bool, bool*) at /Users/mfowler/Code/mozdev/xpcom/threads/nsThread.cpp:855
#14	0x00000001017636c7 in NS_ProcessNextEvent(nsIThread*, bool) at /Users/mfowler/Code/mozdev/xpcom/glue/nsThreadUtils.cpp:265
#15	0x0000000101d9eef1 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) at /Users/mfowler/Code/mozdev/ipc/glue/MessagePump.cpp:368
#16	0x0000000101d32e25 in MessageLoop::RunInternal() at /Users/mfowler/Code/mozdev/ipc/chromium/src/base/message_loop.cc:233
#17	0x0000000101d32d35 in MessageLoop::RunHandler() at /Users/mfowler/Code/mozdev/ipc/chromium/src/base/message_loop.cc:226
#18	0x0000000101d32cdd in MessageLoop::Run() at /Users/mfowler/Code/mozdev/ipc/chromium/src/base/message_loop.cc:200
#19	0x0000000101707b46 in nsThread::ThreadFunc(void*) at /Users/mfowler/Code/mozdev/xpcom/threads/nsThread.cpp:356
#20	0x00000001013736cf in _pt_root at /Users/mfowler/Code/mozdev/nsprpub/pr/src/pthreads/ptthread.c:212
#21	0x00007fff90cdf2fc in _pthread_body ()
#22	0x00007fff90cdf279 in _pthread_start ()
#23	0x00007fff90cdd4b1 in thread_start ()

Here are the member variables of the nsPipe:

(nsPipe) $0 = {
  mRefCnt = {
    mValue = {
      mozilla::detail::AtomicBaseIncDec<unsigned long, mozilla::MemoryOrdering> = {
        mozilla::detail::AtomicBase<unsigned long, mozilla::MemoryOrdering> = (mValue = 2)
      }
    }
  }
  _mOwningThread = (mThread = void * = 0x00000001004481a0)
  mOutput = {
    mPipe = 0x000000012eee5de0
    mWriterRefCnt = {
      mValue = {
        mozilla::detail::AtomicBaseIncDec<unsigned long, mozilla::MemoryOrdering> = {
          mozilla::detail::AtomicBase<unsigned long, mozilla::MemoryOrdering> = (mValue = 1)
        }
      }
    }
    mLogicalOffset = 46720
    mBlocking = false
    mBlocked = false
    mWritable = false
    mCallback = (mRawPtr = nsIOutputStreamCallback * = 0x0000000000000000)
    mCallbackFlags = 0
  }
  mInputList = {
    nsTArray_Impl<nsPipeInputStream *, nsTArrayInfallibleAllocator> = {
      nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_CopyWithMemutils> = {
        mHdr = 0x000000010a512f10
      }
    }
  }
  mOriginalInput = {
    mRawPtr = 0x000000013bf1c900
  }
  mReentrantMonitor = {
    mozilla::BlockingResourceBase = {
      mChainPrev = 0x0000000000000000
      mName = 0x0000000107803b82 "nsPipe.mReentrantMonitor"
      mType = eReentrantMonitor
      mAcquired = true
    }
    mReentrantMonitor = 0x000000013c76f400
    mEntryCount = 1
  }
  mBuffer = {
    mSegmentSize = 32768
    mMaxSize = 786432
    mSegmentArray = 0x000000012e099200
    mSegmentArrayCount = 32
    mFirstSegmentIndex = 0
    mLastSegmentIndex = 1
  }
  mWriteSegment = 0
  mWriteCursor = 0x000000011fc2c6d0 "D9h\x9b\x87U:\x14<i\U0000009a\x91t\xb9*\aN\x1a8\x8e\312b\345շ6*\xa0\x84\x96$Mɪ>LJ\xa5m\xbb˕VKKԖ\xbe\x97\x80\x9a\x1a\x8e*\x9f\xb30\311\324(\x90\xb2\x8f\x1c\x03\xb8\x16\360\341M\311B\300\304JJ\x12\x9a\x8e\x89\x98\x9ft\370\xb3?ӧ\xb3\xb6\361\325\364_L\x93\375CXV\x962\x88\xa7\321Y\xa2\x90\x95\"-¸\xbc

Comment 1

[Seth Fowler [:seth] [:s2h]]

Ack, Bugzilla cut off my comment. I'll attach the relevant part of the LLDB session.

This happened on OS X, but I'd expected it to be a multiplatform issue.

Comment 2

[Seth Fowler [:seth] [:s2h]]

Attachment: LLDB session

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

This is almost certainly my fault.

Seth, do you have steps to reproduce I can follow?

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

Sorry, I see it now in comment 0.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

I'm at a work week now.  I will probably have to look at this when I get back next week.

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

Ehsan kindly volunteered to back out the offending patches for now.  I think this is best.

Ehsan, here are the revs that need to be backed out on central and aurora:

  https://hg.mozilla.org/mozilla-central/rev/27de4b553912
  https://hg.mozilla.org/mozilla-central/rev/212080d51fb7

We then need to reopen bug 1133939.

Thank you!

Comment 7

[(no longer active)]

Marking this as security-sensitive as this is a UAF.

Comment 8

[Ryan VanderMeulen [:RyanVM]]

Hits in automation too.
https://treeherder.mozilla.org/logviewer.html#?job_id=2131919&repo=fx-team

Comment 9

[Ben Kelly [:bkelly, not reviewing]]

Interesting.  I thought that would have gone away when we backed out bug 1133939.

To be clear, I think bug 1133939 had a UAF.  I don't think this particular assert means a UAF is still present.

I will investigate more this week.

Comment 10

[Ben Kelly [:bkelly, not reviewing]]

Whats more, I'm fairly certain this condition existed in the past with nsPipe as well.  I added this assertion and its catching an existing race.  The consequence here is just that the available count goes negative and wraps around just as the pipe is being closed.

Comment 11

[(no longer active)]

Removing the security flag since the offending patch was backed out and it never got past Aurora.

Comment 12

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=2131919
repository: fx-team
start_time: 2015-03-02T11:37:47
who: rvandermeulen[at]mozilla[dot]com
machine: t-snow-r4-0097
buildname: Rev4 MacOSX Snow Leopard 10.6 fx-team debug test mochitest-other
revision: ddbeb492edfb

Assertion failure: *aAvailableOut >= aBytesRead, at /builds/slave/fx-team-osx64-d-00000000000000/build/src/xpcom/io/nsPipe3.cpp:534
2422 ERROR TEST-UNEXPECTED-FAIL | toolkit/identity/tests/chrome/test_sandbox.xul | application terminated with exit code 1
PROCESS-CRASH | toolkit/identity/tests/chrome/test_sandbox.xul | application crashed [@ nsPipe::AdvanceReadCursor(nsPipeReadState&, unsigned int, unsigned int*)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 13

[Andrew McCreight [:mccr8]]

Well, it just happened on trunk, so...

Comment 14

[Ben Kelly [:bkelly, not reviewing]]

The assertion is expected to happen, but its separate from the UAF I noticed.  Bug 1133939 was deleting buffers in the same place that triggered the assertion, but that has been backed out.

Comment 15

[Ben Kelly [:bkelly, not reviewing]]

The patch up in bug 1133939 should fix this.  I'm doing a bunch of try triggers now.  Unlikely to get reviewed until next week.

Comment 16

[Ben Kelly [:bkelly, not reviewing]]

Bug 1133939 now has gtests that trigger the problem.

Comment 17

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=2245848
repository: fx-team
start_time: 2015-03-12T07:21:57
who: rvandermeulen[at]mozilla[dot]com
machine: t-snow-r4-0016
buildname: Rev4 MacOSX Snow Leopard 10.6 fx-team debug test mochitest-other
revision: edc1012c711b

TypeError: this.connection.client.mainRoot is null: exports.AppManager.isMainProcessDebuggable@resource://gre/modules/commonjs/toolkit/loader.js -> resource:///modules/devtools/webide/app-manager.js:436:1
TypeError: this.connection.client.mainRoot is null: exports.AppManager.isMainProcessDebuggable@resource://gre/modules/commonjs/toolkit/loader.js -> resource:///modules/devtools/webide/app-manager.js:436:1
TypeError: this.connection.client.mainRoot is null: exports.AppManager.isMainProcessDebuggable@resource://gre/modules/commonjs/toolkit/loader.js -> resource:///modules/devtools/webide/app-manager.js:436:1
TypeError: this.connection.client.mainRoot is null: exports.AppManager.isMainProcessDebuggable@resource://gre/modules/commonjs/toolkit/loader.js -> resource:///modules/devtools/webide/app-manager.js:436:1
Assertion failure: *aAvailableOut >= aBytesRead, at /builds/slave/fx-team-osx64-d-00000000000000/build/src/xpcom/io/nsPipe3.cpp:534
2507 ERROR TEST-UNEXPECTED-FAIL | toolkit/identity/tests/chrome/test_sandbox.xul | application terminated with exit code 1
PROCESS-CRASH | toolkit/identity/tests/chrome/test_sandbox.xul | application crashed [@ nsPipe::AdvanceReadCursor(nsPipeReadState&, unsigned int, unsigned int*)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 18

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=2249964
repository: fx-team
start_time: 2015-03-12T10:20:14
who: rvandermeulen[at]mozilla[dot]com
machine: t-w864-ix-054
buildname: Windows 8 64-bit fx-team debug test mochitest-5
revision: 95407a270367

Assertion failure: *aAvailableOut >= aBytesRead, at c:\builds\moz2_slave\fx-team-w64-d-0000000000000000\build\src\xpcom\io\nsPipe3.cpp:534
1445 ERROR TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/mochitest/mixedcontent/test_unsecurePictureDup.html | application terminated with exit code 1
PROCESS-CRASH | security/manager/ssl/tests/mochitest/mixedcontent/test_unsecurePictureDup.html | application crashed [@ nsPipe::AdvanceReadCursor(nsPipeReadState &,unsigned int,unsigned int *)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 19

[Ben Kelly [:bkelly, not reviewing]]

I will land bug 1133939 today which should fix this.

Comment 20

[Ben Kelly [:bkelly, not reviewing]]

Ok, bug 1133939 is in central.  Lets see if this reproduces again.

Comment 21

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-aurora&job_id=691239
repository: mozilla-aurora
start_time: 2015-03-19T05:05:40
who: rvandermeulen[at]mozilla[dot]com
machine: t-snow-r4-0007
buildname: Rev4 MacOSX Snow Leopard 10.6 mozilla-aurora debug test mochitest-other
revision: 8c310e0dbcc3

Assertion failure: *aAvailableOut >= aBytesRead, at /builds/slave/m-aurora-m64-d-000000000000000/build/src/xpcom/io/nsPipe3.cpp:534
2366 ERROR TEST-UNEXPECTED-FAIL | toolkit/identity/tests/chrome/test_sandbox.xul | application terminated with exit code 1
PROCESS-CRASH | toolkit/identity/tests/chrome/test_sandbox.xul | application crashed [@ nsPipe::AdvanceReadCursor(nsPipeReadState&, unsigned int, unsigned int*)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 22

[(no longer active)]

comment 21 should be ignored, since it's from Aurora.

Comment 23

[Ryan VanderMeulen [:RyanVM]]

Well, ignored in that we need this fix on Aurora too :P

Comment 24

[Ben Kelly [:bkelly, not reviewing]]

Bug 1133939 needs uplift to aurora.

Comment 25

[Ben Kelly [:bkelly, not reviewing]]

Marking this fixed on trunk.  Uplift has been requested in bug 1133939.