1578136 - Crash in mozilla::net::TLSFilterTransaction::OnReadSegment

Status: VERIFIED FIXED

(Core :: Networking, defect, P1)

Description

[Andrea Marchesini [:baku]]

https://crash-stats.mozilla.org/report/index/8a3a7180-c5ff-4df6-953b-2c6f90190830

STR in https://github.com/mozilla/secure-proxy/issues/561

Comment 1

[Honza Bambas (:mayhemer)]

[Tracking Requested - why for this release]:
this is secure proxy major functionality problem.

What happens:

• we create a websocket connection via the fallback to h1.1 proxying
• the crash happens during send of data on a ws in direction to the server when the socket can't eat more data (SSL short write), we would block
• we therefor attempt to schedule writing for this tunneled connection on the outer connection; this only makes sense when we are going via a h2 tunnel, which is not the case here
  • for h1 tunneled ws Connection()->TransactionHasDataToWrite(this) is a no-op, it will use mTransaction->Connection() which is nsHttpConnection that implements TransactionHasDataToWrite as { }
• this->Connection() is null because the transaction (and with it the assigned TLSFilterTransaction) have already been closed after the 101 response:

2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: I/nsHttp http response [
  HTTP/1.1 101 Switching Protocols
  Server: openresty/1.13.6.2
  Date: Mon, 02 Sep 2019 13:17:28 GMT
  Connection: upgrade
  Upgrade: websocket
  Sec-WebSocket-Accept: PbneoG6BYygl7r1Qw0e5d7PW7X4=
  Via: 1.1 google
  Alt-Svc: clear
    OriginalHeaders
  Server: openresty/1.13.6.2
  Date: Mon, 02 Sep 2019 13:17:28 GMT
  Connection: upgrade
  Upgrade: websocket
  Sec-WebSocket-Accept: PbneoG6BYygl7r1Qw0e5d7PW7X4=
  Via: 1.1 google
  Alt-Svc: clear
]
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpTransaction::CheckForStickyAuthScheme this=0000020694689C00
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp   already sticky
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp   already sticky
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpConnection::OnHeadersAvailable [this=0000020694692400 trans=0000020694689C00 response-head=0000020691CE57C0]
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp Connection can be reused [this=0000020694692400 idle-timeout=115sec]
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpConnection::DontReuse 0000020694692400 spdysession=0000000000000000
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: E/nsHttp nsHttpTransaction::HandleContent [this=0000020694689C00 count=0 read=0 mContentRead=0 mContentLength=0]
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpTransaction::RemoveDispatchedAsBlocking this=0000020694689C00 not blocking
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpTransaction 0000020694689C00 request context set to null in ReleaseBlockingTransaction() - was 0000000000000000
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: D/nsHttp TLSFilterTransaction 00000206913177C0 called trans->WriteSegments rv=0 0
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 0000020694692400 trans->ws rv=0 n=0 socketin=0
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: D/nsHttp TLSFilterTransaction::WriteSegmentsAgain 00000206913177C0 max=32768
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpTransaction::WriteSegments 0000020694689C00
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: D/nsHttp TLSFilterTransaction 00000206913177C0 called trans->WriteSegments rv=80470002 0
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 0000020694692400 trans->ws rv=80470002 n=0 socketin=0
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpConnection::CloseTransaction[this=0000020694692400 trans=00000206913177C0 reason=80470002]
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: D/nsHttp TLSFilterTransaction::Close 00000206913177C0 0
2019-09-02 13:17:29.792000 UTC - [Parent 28208: Socket Thread]: V/nsHttp nsHttpTransaction::Close [this=0000020694689C00 reason=0]

I won't comment on this design weirdness.

To fix this we only need to add a non-null check, because when writing of ws data WOULD_BLOCK, the caller WebSocketChannel::OnOutputStreamReady makes sure to poll for write:

      if (rv == NS_BASE_STREAM_WOULD_BLOCK) {
        mSocketOut->AsyncWait(this, 0, 0, mSocketThread);
        return NS_OK;
      }

A non-null check (or an explained non-null assertion) is a good thing generally.

Comment 2

[Honza Bambas (:mayhemer)]

Attachment: Bug 1578136 - Add a non-null check before dereferencing TLSFilterTransaction::Connection(), r=dragana

Comment 3

[Dragana Damjanovic [:dragana]]

Thanks Honza.

Comment 4

[Honza Bambas (:mayhemer)]

Comment on attachment 9089886 [details]
Bug 1578136 - Add a non-null check before dereferencing TLSFilterTransaction::Connection(), r=dragana

Beta/Release Uplift Approval Request

• User impact if declined: Null-deref crash during websocket upload (e.g. send.firefox.com) and using secured h2 proxy (e.g firefox private network)

thus, this is a secure-proxy beta blocker.

• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: see comment 0
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): this is a very safe and simple patch. if the code continues past the non-null check we properly follow expected code paths.
• String changes made/needed:

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/integration/autoland/rev/171b7cbb6c4a1c8fd52e4a3db8daf1020f78a458
https://hg.mozilla.org/mozilla-central/rev/171b7cbb6c4a

Comment 6

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9089886 [details]
Bug 1578136 - Add a non-null check before dereferencing TLSFilterTransaction::Connection(), r=dragana

Approved for 70.0b4.

Comment 7

[Ryan VanderMeulen [:RyanVM]]

Can we land a testcase for this?

Comment 8

[Honza Bambas (:mayhemer)]

(In reply to Ryan VanderMeulen [:RyanVM] from comment #7)

Can we land a testcase for this?

Not right now. We are dep on bug 1571573.

Comment 9

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/releases/mozilla-beta/rev/f7b7283f9bee

Comment 11

[Rares Doghi, Desktop QA]

Hi Guys, since Bug 1571573 is Fixed can someone help us with a test case for this issue ?

Comment 12

[Honza Bambas (:mayhemer)]

Steps to manually reproduce:

1. Go to send.firefox.com.
2. Upload any archived file (larger, 20MB+, makes it more likely in case of a fast upstream).

For an automated test, we need an upload-throttled WS server side by the updated node.

Comment 13

[Rares Doghi, Desktop QA]

Hi, This issue is Verified as Fixed in our latest Nightly Build as well as Beta 70.0b7 on Windows 10, Mac Osx 10.14 and Ubuntu 18.04.

Comment 14

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9089886 [details]
Bug 1578136 - Add a non-null check before dereferencing TLSFilterTransaction::Connection(), r=dragana

Fixes a Secure Proxy crash. Approved for 69.0.1.

Comment 15

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-release/rev/cd3c8dcb9c4d

Comment 16

[Rares Doghi, Desktop QA]

Hi, This issue is verified as fixed in Firefox 69.0.1 on Windows 10 , Ubuntu 18.04 and Mac 10.14.

Comment 17

[Emma Humphries ☕️🎸🧞‍♀️✨ (she/they) [:emceeaich] (Pacific Time) use needinfo]

This bug has been identified as part of a pilot on determining root causes of blocking and dot release drivers.

It needs a root-cause set for it. Please see the list at https://docs.google.com/document/d/1FFEGsmoU8T0N8R9kk-MXWptOPtXXXRRIe4vQo3_HgMw/.

Add the root cause as a whiteboard tag in the form [rca - <cause> ] and remove the rca-needed keyword.

If you have questions, please contact :tmaity.