[asio-users] Weird effect when reading more than 1000 bytes with async_read

[Guido Winkelmann]

Hi,

I'm having some weird problems trying to read an incoming file from an SSL
stream via a boost::asio::streambuf using async_read. I'm using asio is
shipped with Boost 1.46

The incoming file is of a known size (which has been signalled by the peer
before sending the file), so I was going to use async_read with
transfer_at_least() as a completion handler. Since I don't want the entire
incoming file in memory before writing it to the disk, I decided I would read
at most 16000 bytes in one async_read call, write that to the disk and then
iteratively read the rest of the file. The code originally looked like this:

size_t bytes_to_read = file->bytesleft() < 16000 ? file->bytesleft() : 16000;
boost::asio::async_read(m_conn->get_socket(),
m_readbuffer,
boost::asio::transfer_at_least(bytes_to_read),
boost::bind(&Order::handle_read_file_block, this,
boost::asio::placeholders::error, file,
handler));

The problem is that Order::handle_read_file_block() never gets called. (I made
sure that the peer is actually sending the number of expected bytes.) The
entire programs appears to just hang after that, although other asynchronous
operations on other sockets, but on the same io_service, are not affected.

m_conn->get_socket() returns
boost::asio::ssl::stream<boost::asio::ip::tcp::socket>&; m_readbuffer is of
type boost::asio::streambuf.

I've experimented with replacing boost::asio::transfer_at_least() with my own
completion_condition, which was easier to debug for me:

class completion_condition {
public:
completion_condition(std::size_t filesize) : m_filesize(filesize) {}
~completion_condition() {}

std::size_t operator()(const boost::system::error_code& error,
std::size_t bytes_transferred) {
std::cerr << "In completion_condition::operator(), bytes_transferred: " <<
bytes_transferred << ", returning " << m_filesize - bytes_transferred <<
std::endl;
return m_filesize - bytes_transferred;
}

std::size_t m_filesize;};

The output of that looked like this
In completion_condition::operator(), bytes_transferred: 0, returning 1672
In completion_condition::operator(), bytes_transferred: 512, returning 1160
In completion_condition::operator(), bytes_transferred: 1024, returning 648
In completion_condition::operator(), bytes_transferred: 1211, returning 461
In completion_condition::operator(), bytes_transferred: 1249, returning 423

... and then nothing.

Meaning async_read() read five blocks of 1249 bytes and then just stopped, as
if there was nothing more to read on the socket.

The interesting part is what happens when I reduce the block size to 1000,
i.e. call transfer_at_least (or my own completion_condition) with a value of
no more than 1000. In that case, the file gets transferred successfully and
without any corruption (MD5 sum checks out) in several smaller steps (2 in the
case of this 1672 byte file).
BTW, the incoming file data on the socket is immediately followed by some more
bytes belonging to the protocol, but not to the file being transferred, so it
can't be just an off-by-one error somewhere, either. (I.e. asking async_read to
read just one more byte than there is available)

So, does anyone have any idea why async_read might just refuse to read 1672
bytes from a socket in one go, but will happily read all of it when called
twice for a smaller amount of data?

Regards,

Guido

[Marat Abrarov]

Hi, Guido.

Solution can be tied to the used version of OpenSSL and to the used OS/compiler.
Could we see minimal working example (server + client)?
Also notice that the issue can be related to the work with socket (or SSL stream) - the number of async_read_some calls
at second test is less than the one at first test - it makes me to think about some errors at work with socket (or SSL
stream) between this numbers.

P.S. The fastest solution is to try Boost 1.47 - Boost.Asio 1.6 has rewritten SSL support.

Regards,
Marat Abrarov.

[Guido Winkelmann]

Post by Marat Abrarov
Hi, Guido.
Solution can be tied to the used version of OpenSSL and to the used OS/compiler.

Well, I got Gentoo with Linux 2.6.39, OpenSSL 1.0.0e, glibc 2.12.2 and gcc
4.5.3.

Post by Marat Abrarov
Could we see minimal working example (server + client)?
Also notice that the issue can be related to the work with socket (or SSL
stream) - the number of async_read_some calls at second test is less than
the one at first test - it makes me to think about some errors at work with
socket (or SSL stream) between this numbers.
P.S. The fastest solution is to try Boost 1.47 - Boost.Asio 1.6 has rewritten SSL support.

I suppose I'll try that first - producing a minimal working example at this
point would be a lot of work, and the code in question is not Open Source...

Guido

[Guido Winkelmann]

Post by Guido Winkelmann

Post by Marat Abrarov
P.S. The fastest solution is to try Boost 1.47 - Boost.Asio 1.6 has
rewritten SSL support.

I suppose I'll try that first - producing a minimal working example at this
point would be a lot of work, and the code in question is not Open Source...

No luck - the problem is still there with Boost 1.47.

[Brant Knudson]

Maybe you've already read some bytes from the message, during the
previous read? I've had this problem myself when trying to use
transfer_at_least.

Here's the completion handler I use:

std::size_t checkStreambufContains(
const boost::system::error_code& error,
const boost::asio::streambuf& streambuf,
uint64_t bytes_required
)
{
if ( error ) return 0; // There was an error, don't need any more
if ( streambuf.size() >= bytes_required ) return 0; // Streambuf
contains the bytes.
return (bytes_required - streambuf.size()); // Return the number
of bytes I want
}

HTH, Brant

[Igor R]

Post by Guido Winkelmann
I'm having some weird problems trying to read an incoming file from an SSL
stream via a boost::asio::streambuf using async_read. I'm using asio is
shipped with Boost 1.46

Does is happen with SSL only?
Perhaps, it's worth trying your use-case with Asio 1.6 (Boost 1.47),
as it adds "a new, completely rewritten SSL implementation":
http://www.boost.org/doc/libs/1_47_0/doc/html/boost_asio/history.html

[Marat Abrarov]

Try to add error logging:

std::size_t completion_condition::operator()(
const boost::system::error_code& error, std::size_t bytes_transferred)
{
std::cerr << "In completion_condition::operator()"
<< ", bytes_transferred: " << bytes_transferred
<< ", error: " << error.value()
<< ", returning " << m_filesize - bytes_transferred
<< std::endl;
return m_filesize - bytes_transferred;
}

Regards,
Marat Abrarov.

[Guido Winkelmann]

Post by Marat Abrarov
std::size_t completion_condition::operator()(
const boost::system::error_code& error, std::size_t bytes_transferred)
{
std::cerr << "In completion_condition::operator()"
<< ", bytes_transferred: " << bytes_transferred
<< ", error: " << error.value()
<< ", returning " << m_filesize - bytes_transferred
<< std::endl;
return m_filesize - bytes_transferred;
}
Regards,
Marat Abrarov.

Right, i should have thought of logging the error value, too, right away...

The result does not look very helpful, though:

In completion_condition::operator(), bytes_transferred: 0, returning 1672
error: 0
In completion_condition::operator(), bytes_transferred: 512, returning 1160
error: 0
In completion_condition::operator(), bytes_transferred: 1024, returning 648
error: 0
In completion_condition::operator(), bytes_transferred: 1211, returning 461
error: 0
In completion_condition::operator(), bytes_transferred: 1249, returning 423
error: 0

[Rutger ter Borg]

Post by Guido Winkelmann
Hi,
I'm having some weird problems trying to read an incoming file from an SSL
stream via a boost::asio::streambuf using async_read. I'm using asio is
shipped with Boost 1.46

You have made sure that, before initiating the next async read, the
istream or iterator that is eating your streambuf commits its results to
the streambuf? (e.g., the istream or input iterator is either
destructed, or you use streambuf.consume)?

Cheers,

Rutger

[Guido Winkelmann]

Post by Rutger ter Borg

Post by Guido Winkelmann
Hi,
I'm having some weird problems trying to read an incoming file from an
SSL stream via a boost::asio::streambuf using async_read. I'm using
asio is shipped with Boost 1.46

You have made sure that, before initiating the next async read, the
istream or iterator that is eating your streambuf commits its results to
the streambuf? (e.g., the istream or input iterator is either
destructed, or you use streambuf.consume)?

No...
I wasn't even aware that was necessary. I'm actually doing a new async_read or
async_read_until on a streambuf with a still-existing istream object quite
frequently. My usual modus operandi when reading line-based data from a socket
looks like this:

std::istream s(&m_buffer);
std::string line;
std::getline(s, line);

//<Do something with line>

if(<expecting more lines>)
{
// s still exists at this point
boost::asio::async_read_until(<socket>, m_buffer, "\n",<somecallback>);
}

Is that totally wrong now?

Guido

[Rutger ter Borg]

Post by Guido Winkelmann
No...
I wasn't even aware that was necessary. I'm actually doing a new async_read or
async_read_until on a streambuf with a still-existing istream object quite
frequently. My usual modus operandi when reading line-based data from a socket
std::istream s(&m_buffer);
std::string line;
std::getline(s, line);
//<Do something with line>
if(<expecting more lines>)
{
// s still exists at this point
boost::asio::async_read_until(<socket>, m_buffer, "\n",<somecallback>);
}
Is that totally wrong now?
Guido

I've had my share of problems with it. It's a while ago, but I thought
it had to do with buffering on the stream level, or something like that.
pubsetbuf may also help.

Cheers,

Rutger