Race condition in SocketTransport

[Geoff Lankow]

Hi all, I'm fighting with a race condition. I'm calling output.write and transport.close but the call to close sometimes happens on the main thread before the socket thread completes the write:

[Parent 4048037: Main Thread]: D/nsSocketTransport nsSocketTransport::Close 7fc2ecb6f000 reason=0
[Parent 4048037: Main Thread]: D/nsSocketTransport nsSocketInputStream::CloseWithStatus [this=7fc2ecb6f290 reason=80470002]
[Parent 4048037: Main Thread]: D/nsSocketTransport nsSocketOutputStream::CloseWithStatus [this=7fc2ecb6f2c8 reason=80470002]
[Parent 4048037: Socket Thread]: D/nsSocketTransport nsSocketOutputStream::Write [this=7fc2ecb6f2c8 count=52]

When this happens the receiving end doesn't get all of the data and my tests fail.

How can I be sure the output stream is ready before closing it? There doesn't appear to be any checks in the code. Is this expected behaviour or a bug?

GL

[Randell Jesup]

So nsSocketOutputStream::CloseWithStatus() with a non-zero reason will call transport->OnOutputClosed().  If that's called off the socket thread, it sends a MSG_OUTPUT_CLOSED to the socket thread, so this should be processed on the socket thread after your write.  This should cause a SOCKET_LOG(("  MSG_OUTPUT_CLOSED")) and then a nsSocketTransport::OnMsgOutputClosed  log.  Do these happen before or after the ::Write on Socket Thread?

To help more we'd need more details/code/complete logs.   Can you join us in #necko on matrix?

Thanks!

Randell Jesup, Mozilla Network team

[Geoff Lankow]

Okay, you're right, those things do happen and I'd missed them. Confirmation bias is fun! I'll keep digging.

Why else might onStopRequest occur at the receiving end without onDataAvailable called for the last available chunk? This is the code in question although large chunks of it are irrelevant.

I am lurking in #necko now, although I suspect you are not around, given the time of day.

GL