bytes_transferred > 0 assertion fails

[Bobface]

I am basically having the exactly same problem as described here: Assertion failed: (bytes_transferred > 0).

I am using a websocket::stream<ssl::stream<tcp::socket>> to connect to a ws server. After some time (can be minutes, hours or even days) the bytes_transferred > 0 assertion fails:

#2 0x00007ffff398139a in __assert_fail_base (fmt=0x7ffff3b087d8 "%s%s%s:%u: %s%sAssertion %s' failed.\n%n", assertion=assertion@entry=0x555557004919 "bytes_transferred > 0", file=file@entry=0x5555570047a8 "/usr/local/include/boost/beast/websocket/impl/read.ipp", line=line@entry=496

I can also post the full gdb stack trace if that would help.

Are there any updates regarding this bug/problem?

Thanks in advance!

Boost Version: 1.69
Asio Version: 1.12.1
Beast Version: 186
gcc (Ubuntu 8.2.0-1ubuntu2~18.04) 8.2.0

[vinniefalco]

Investigating...

[vinniefalco]

Are there any updates regarding this bug/problem?

No. But I guess I can add configurable setting which will invoke the completion handler with an error instead of asserting? You could opt-in to it as a workaround.

[Bobface]

Are there any updates regarding this bug/problem?

No. But I guess I can add configurable setting which will invoke the completion handler with an error instead of asserting? You could opt-in to it as a workaround.

That would be great!

[vinniefalco]

We think that this is very likely a bug in Asio for not handling SSL_ERROR_ZERO_RETURN. Treating it as an EOF would be the right thing to do. I have put together a patch for Asio:
vinniefalco/boost.asio@89feb2a

If you could apply this patch, uncomment the line which logs to cerr, and adjust the line so it logs to wherever/however you log in your program, then it would be very helpful for us to know what the log output is if the problem happens again. It is possible you won't see the log line (or the assert in beast) because of the handling of SSL_ERROR_ZERO_RETURN.

[Bobface]

Thank you for the update! I have also investigated a little bit. I think the error only happens when I async_close the websocket stream from inside a handler which has been scheduled with asio::post. I will try to find out more and report back.

[vinniefalco]

Did you try my patch?

[Bobface]

I have installed it, waiting for the error to occur now.

[vinniefalco]

The suspense is killing me

[Bobface]

Me too. It seems like a tough bug always disappears when you are trying to track it down .. :) I am logging stderr to a file, as soon as I get some output I will post it here.

[Bobface]

The error happened now, however I only got the assert output from sterr which I posted in my question above (Assertion bytes_transferred > 0 failed). I double checked that the patch is installed correctly.

[vinniefalco]

What did if(result <= 0) std::cerr << "result <= 0, ssl_error = " << ssl_error << std::endl; print?

[Bobface]

It didn't print anything, I only got the assertion message from stderr.

[vinniefalco]

Hmm, but you did uncomment this line right?

 //if(result <= 0) std::cerr << "result <= 0, ssl_error = " << ssl_error << std::endl;

vinniefalco/boost.asio@89feb2a#diff-9693888572396784daf4f0aded26ce3aR286

[Bobface]

Yes I did, then I rebuilt boost and my application.

[vinniefalco]

Well that makes no sense at all.. in that asio file on line 287 is the only way that the function can return with the error cleared but if there's no output it means the else was not taken...

[vinniefalco]

We need more info. Please try editing that engine::perform function to log as much information as possible when *bytes_transferred==0. For example what is the value of sys_error? Apparently our understanding of the function is lacking because I would have expected there to be some kind of error. So the more information that we can gather about the variables in that function when this condition occurs, the more likely we will be able to diagnose it.

[Bobface]

Dereferencing bytes_transferred resulted in segfaults, so I checked for result <= 0 which seems to be more or less the same as bytes_transferred. However this spams the output with lines like this (at least 20 per second):
pending_output_before=0 result=-1 ssl_error=2 sys_error=0 pending_output_after=203

Is there a better place where I could check for result <= 0?

[pdimov]

ssl_error=2 is SSL_ERROR_WANT_READ, which should be part of normal operation, so you could just skip the output in this case and see if anything else turns up.

[Bobface]

The application just crashed, this is the output:

pending_output_before=0 result=0 ssl_error=6 sys_error=0 pending_output_after=0
pending_output_before=0 result=-1 ssl_error=5 sys_error=0 pending_output_after=0

The second line was printed directly before the output. The first line seems to be older.

[vinniefalco]

Any update?

[Bobface]

Seems to be running fine so far!

[vinniefalco]

I'll go ahead and close this, the pull request to fix asio is here:
boostorg/asio#182