Paul R.
Paul R.

Reputation: 738

boost::asio::async_read ends without fulfilling the completion condition

On Windows, I am observing that if an async_read operation successfully completes on a serial port, and I immediately initiate another async_read operation to read n bytes, the second async_read operation immediately completes unexpectedly with success and 0 bytes transferred.

Why is this happening and how can I avoid it?


For specifics, I am using Boost.Asio on Windows to communicate with a micro-controller via RS232 emulated by an ATXMEGA-192A3U. I send a start command to the controller and read the output with a timeout. I read the output by calling the ReadPort function for which the code is given below. The program performs the following reading tasks in a row:

  1. Check the answer of the micro-controller to the start command. This read succeeds in reading the 3 characters I expect: R\r\n
  2. Read n bytes of output from the controller for a few hundreds of ms.

The async_read operation in step 2 unexpectedly completes with success, despite not having read the number of requested bytes.

class BoostBasedCommunication
{
public:
    BoostBasedCommunication();
    ~BoostBasedCommunication(void);
    /*...*/
    virtual int ReadPort(
        int const numberOfCharacters, // maximum number of characters to be read
        unsigned long const globalTimeout, // maximum time the operation is allowed to take in ms
        unsigned long const intermediateTimeout, // maximum time allowed between two consequtive characters in ms
        int& numberOfCharactersRead
        );
    /*...*/

private:
    /*...*/
    std::vector<unsigned char> inputBuffer; ///< buffer to save data to that is received
    size_t numberOfBytesRead; ///< Number of bytes read
    int lastErrorCode; ///< last error code
    io_service my_io_service; ///< boost io service class
    serial_port port; ///< boost serial port class
    /*...*/
};

// Reads from the port until numberOfCharacters have been read, or the 
// deadline_timer has expired, or the time between two consecutive calls of 
// the completion condition is larger than intermediateTimeoutMS

int BoostBasedCommunication::ReadPort(
    int const numberOfCharacters, // maximum number of characters to be read
    unsigned long const globalTimeoutMS, // maximum time the operation is allowed to take in ms
    unsigned long const intermediateTimeoutMS, // maximum time allowed between two consecutive characters in ms
    int& numberOfCharactersRead // Actual number of characters read
    )
{
    try
    {
        OutputDebugStringA("ReadPort called\r\n");
        my_io_service.reset();
        deadline_timer gloabalTimeout(my_io_service);
        inputBuffer.resize(numberOfCharacters);
        timeoutHandler myGlobalTimeoutHandler(&port);

        completion_handler_2 myHandler(&gloabalTimeout, numberOfBytesRead);
        completion_condition_2 my_completion_condition(intermediateTimeoutMS, numberOfCharacters);

        // Set the timer
        gloabalTimeout.expires_from_now(boost::posix_time::milliseconds(globalTimeoutMS));
        gloabalTimeout.async_wait(myGlobalTimeoutHandler);

        async_read(port, boost::asio::buffer(inputBuffer, numberOfCharacters), my_completion_condition, myHandler);

        my_io_service.run(); // run the io service
        numberOfCharactersRead = numberOfBytesRead;
    }
    catch (std::exception&)
    {
        return COMMUNICATIONFAILED;
    }
    return NOERROR;
}

class completion_condition_2
{
public:
    completion_condition_2(
        long intermediateTimeOutTime,
        size_t numberOfCharactersTobeRead
        ) :intermediateTimeOutTime(intermediateTimeOutTime),
        numberOfCharactersTobeRead(numberOfCharactersTobeRead)
    {}

    std::size_t operator()(
        const boost::system::error_code& error, // Result of latest async_read_some operation.
        std::size_t bytes_transferred // Number of bytes transferred so far.
        )
    {
        if (error)
        {
            OutputDebugStringA(("completion_condition received error code: " + error.message() + "\r\n").c_str());

            if (error.value() == ERROR_OPERATION_ABORTED)
            {
                return 0;
            }
        }

        /* ...Code concerning the intermediate timeout, which is commented out...*/

        if (numberOfCharactersTobeRead <= bytes_transferred) // Enough data has been read
        {
            std::stringstream message;
            message << "completion_condition: bytes transferred: " << bytes_transferred << " of " << numberOfCharactersTobeRead << " => done!" << std::endl;
            OutputDebugStringA(message.str().c_str());
            return 0;
        }
        else // More data should be read.
        {
            std::stringstream message;
            message << "completion_condition: bytes transferred: " << bytes_transferred << " of " << numberOfCharactersTobeRead << " => continue!" << std::endl;
            OutputDebugStringA(message.str().c_str());
            return numberOfCharactersTobeRead - bytes_transferred;
        }
    }

private:
    size_t numberOfCharactersTobeRead; ///< Number of characters to be read
};

class completion_handler_2 {
public:
    completion_handler_2(
        deadline_timer* _globalTimeout,
        size_t& numberOfBytesRead
        ) :_globalTimeout(_globalTimeout),
        numberOfBytesRead(numberOfBytesRead)
    {
    }

    void operator()(
        const boost::system::error_code& error, // Result of operation.
        std::size_t bytes_transferred           // Number of bytes read.
        )
    {
        OutputDebugStringA(("completion handler called with error code: " + error.message() + "\r\n").c_str());
        if (error)
        {
            if (error.value() == ERROR_OPERATION_ABORTED)
            {
                numberOfBytesRead = bytes_transferred;
                return;
            }
            else
            {
                BOOST_THROW_EXCEPTION(std::exception("Communication failed"));
            }
        }

        OutputDebugStringA("completion handler: timeout cancelation.\r\n");

        _globalTimeout->cancel();
        numberOfBytesRead = bytes_transferred;
    }

private:
    deadline_timer* _globalTimeout; ///< global timeout deadline timer
    size_t& numberOfBytesRead; ///< number of bytes read
};

When I perform the first read that is working as expected, I receive the following output:

ReadPort called
completion_condition: bytes transferred: 0 of 3 => continue!
completion_condition: bytes transferred: 3 of 3 => done!
completion handler called with error code: success
completion handler timeout cancelation.
timeoutHandler received error code: The I/O operation has been aborted because of either a thread exit or an application request

If I immediately perform another read after the first has completed, the operation completes after 2 ms with the following output:

ReadPort called
completion_condition: bytes transferred: 0 of 1024 => continue!
completion handler called with error code: success // Why is the completion handler called here, although the completion condition did not return 0?
completion handler timeout cancelation.
timeoutHandler received error code: The I/O operation has been aborted because of either a thread exit or an application request

A third read, immediately following the last one works as expected:

ReadPort called
completion_condition: bytes transferred: 0 of 1024 => continue!
completion_condition: bytes transferred: 8 of 1024 => continue!
...
completion_condition: bytes transferred: 88 of 1024 => continue!
completion_condition: bytes transferred: 96 of 1024 => continue!
timeoutHandler called cancel of seriel port.
completion_condition received error code: The I/O operation has been aborted because of either a thread exit or an application request
completion handler called with error code: The I/O operation has been aborted because of either a thread exit or an application request

Upvotes: 1

Views: 2252

Answers (1)

Tanner Sansbury
Tanner Sansbury

Reputation: 51901

In short, the fundamental problem is either:

  • Asio's interpretation of the ReadFile API contract with timeouts is incorrect
  • a communication driver is violating the ReadFile API contract

The easiest solution is to account for this behavior in the application code, and issue another async_read operation if the prior one completes with success and 0 bytes read. Depending on the communication driver's implementation, a 1 milliseconds sleep between reads may work.


The COMMTIMEOUTS documentation states that for the read interval timeout:

The maximum time allowed to elapse before the arrival of the next byte on the communications line, in milliseconds. If the interval between the arrival of any two bytes exceeds this amount, the ReadFile operation is completed and any buffered data is returned. [...]

Asio's interpretation of the documentation, namely the emphasized text, is that for a given ReadFile operation, the read interval timeout begins after the first byte has been read. The implication is that if ReadFile is requested to read more than 0 bytes, Asio does not expect the ReadFile operation to return a status indicating it has successfully read 0 bytes synchronously or asynchronously. With this interpretation, Asio's implementation configures the serial port with a read interval timeout of 1 millisecond1.

// Set up timeouts so that the serial port will behave similarly to a
// network socket. Reads wait for at least one byte, then return with
// whatever they have. Writes return once everything is out the door.
::COMMTIMEOUTS timeouts;
timeouts.ReadIntervalTimeout = 1;
timeouts.ReadTotalTimeoutMultiplier = 0;
timeouts.ReadTotalTimeoutConstant = 0;

The async_read is a composed operation implemented in zero or more calls to intermediate async_read_some operations. The async_read operation interprets an intermediate async_read_some operation completing with success and 0 bytes transferred as-if no further progress will be made for the composed operation, and thus the async_read operation completes. This interpretation becomes problematic when the underlying system call to ReadFile unexpectedly completes synchronously with success and 0 bytes read.

With this details, alternative solutions are to either:

  • patch the communication driver so that a timeout interval only begins for a ReadFile operation once the operation has read at least a single byte
  • patch Asio. If one has detailed the observed behavior of ReadFile and finds that it only occurs if the ReadFile operation completes synchronously, then one may be able to patch the async_read_some() operation within win_iocp_handle_service::start_read_op. Otherwise, one could patch the various read_op specializations so that their completion predicate does not exit if 0 bytes have been read, but more than 0 had been requested.

1. If the communication driver's implementation is allowing the read interval timeout that started at the last byte read for ReadFilen operation to affect ReadFilen+1 operation that is initiated within the read interval timeout gap, then sleeping between ReadFilen and ReadFilen+1 for the period of the read interval timeout would prevent the Asio read operations from completing with success and 0 bytes when the supplied buffer's size is greater than 0 bytes.

Upvotes: 1

Related Questions