blob: b325553fabe36b497d569556885906d79f1480c7 [file] [log] [blame]
[/
/ Copyright (c) 2003-2021 Christopher M. Kohlhoff (chris at kohlhoff dot com)
/
/ Distributed under the Boost Software License, Version 1.0. (See accompanying
/ file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
/]
[section:handler_tracking Handler Tracking]
To aid in debugging asynchronous programs, Boost.Asio provides support for handler
tracking. When enabled by defining `BOOST_ASIO_ENABLE_HANDLER_TRACKING`, Boost.Asio
writes debugging output to the standard error stream. The output records
asynchronous operations and the relationships between their handlers.
[teletype]
This feature is useful when debugging and you need to know how your
asynchronous operations are chained together, or what the pending asynchronous
operations are. As an illustration, here is the output when you run the HTTP
Server example, handle a single request, then shut down via Ctrl+C:
@asio|1589424178.741850|0*1|signal_set@0x7ffee977d878.async_wait
@asio|1589424178.742593|0*2|socket@0x7ffee977d8a8.async_accept
@asio|1589424178.742619|.2|non_blocking_accept,ec=asio.system:11
@asio|1589424178.742625|0|resolver@0x7ffee977d760.cancel
@asio|1589424195.830382|.2|non_blocking_accept,ec=system:0
@asio|1589424195.830413|>2|ec=system:0
@asio|1589424195.830473|2*3|socket@0x7fa71d808230.async_receive
@asio|1589424195.830496|.3|non_blocking_recv,ec=system:0,bytes_transferred=151
@asio|1589424195.830503|2*4|socket@0x7ffee977d8a8.async_accept
@asio|1589424195.830507|.4|non_blocking_accept,ec=asio.system:11
@asio|1589424195.830510|<2|
@asio|1589424195.830529|>3|ec=system:0,bytes_transferred=151
@asio|1589424195.831143|3^5|in 'async_write' (./../../../boost/asio/impl/write.hpp:330)
@asio|1589424195.831143|3*5|socket@0x7fa71d808230.async_send
@asio|1589424195.831186|.5|non_blocking_send,ec=system:0,bytes_transferred=1090
@asio|1589424195.831194|<3|
@asio|1589424195.831218|>5|ec=system:0,bytes_transferred=1090
@asio|1589424195.831263|5|socket@0x7fa71d808230.close
@asio|1589424195.831298|<5|
@asio|1589424199.793770|>1|ec=system:0,signal_number=2
@asio|1589424199.793781|1|socket@0x7ffee977d8a8.close
@asio|1589424199.793809|<1|
@asio|1589424199.793840|>4|ec=asio.system:125
@asio|1589424199.793854|<4|
@asio|1589424199.793883|0|signal_set@0x7ffee977d878.cancel
Each line is of the form:
<tag>|<timestamp>|<action>|<description>
The `<tag>` is always `@asio`, and is used to identify and extract the handler
tracking messages from the program output.
The `<timestamp>` is seconds and microseconds from 1 Jan 1970 UTC.
The `<action>` takes one of the following forms:
[variablelist
[
[>n]
[The program entered the handler number `n`. The `<description>` shows the
arguments to the handler.]
]
[
[<n]
[The program left handler number `n`.]
]
[
[!n]
[The program left handler number n due to an exception.]
]
[
[~n]
[The handler number `n` was destroyed without having been invoked. This is
usually the case for any unfinished asynchronous operations when the
`io_context` is destroyed.]
]
[
[n^m]
[The handler number `n` is about to create a new asynchronous operation with
completion handler number `m`. The `<description>` contains source location
information to help identify where in the program the asynchronous operation
is being started.]
]
[
[n*m]
[The handler number `n` created a new asynchronous operation with completion
handler number `m`. The `<description>` shows what asynchronous operation
was started.]
]
[
[n]
[The handler number `n` performed some other operation. The `<description>`
shows what function was called. Currently only `close()` and `cancel()`
operations are logged, as these may affect the state of pending
asynchronous operations.]
]
[
[.n]
[The implementation performed a system call as part of the asynchronous
operation for which handler number `n` is the completion handler. The
`<description>` shows what function was called and its results. These
tracking events are only emitted when using a reactor-based
implementation.]
]
]
Where the `<description>` shows a synchronous or asynchronous operation, the
format is `<object-type>@<pointer>.<operation>`. For handler entry, it shows a
comma-separated list of arguments and their values.
As shown above, Each handler is assigned a numeric identifier. Where the
handler tracking output shows a handler number of 0, it means that the action
was performed outside of any handler.
[heading Adding Location Information]
[c++]
Programs may augment the handler tracking output's location information by
using the macro `BOOST_ASIO_HANDLER_LOCATION` in the source code. For example:
#define HANDLER_LOCATION \
BOOST_ASIO_HANDLER_LOCATION((__FILE__, __LINE__, __func__))
// ...
void do_read()
{
HANDLER_LOCATION;
auto self(shared_from_this());
socket_.async_read_some(boost::asio::buffer(data_, max_length),
[this, self](boost::system::error_code ec, std::size_t length)
{
HANDLER_LOCATION;
if (!ec)
{
do_write(length);
}
});
}
[teletype]
With the additional location information available, the handler tracking output
may include a call stack of source locations:
@asio|1589423304.861944|>7|ec=system:0,bytes_transferred=5
@asio|1589423304.861952|7^8|in 'async_write' (./../../../boost/asio/impl/write.hpp:330)
@asio|1589423304.861952|7^8|called from 'do_write' (handler_tracking/async_tcp_echo_server.cpp:62)
@asio|1589423304.861952|7^8|called from 'operator()' (handler_tracking/async_tcp_echo_server.cpp:51)
@asio|1589423304.861952|7*8|socket@0x7ff61c008230.async_send
@asio|1589423304.861975|.8|non_blocking_send,ec=system:0,bytes_transferred=5
@asio|1589423304.861980|<7|
Furthermore, if `std::source_location` or `std::experimental::source_location`
are available, the [link boost_asio.reference.use_awaitable_t `use_awaitable_t`]
token (when default-constructed or used as a default completion token) will
also cause handler tracking to output a source location for each newly created
asynchronous operation. A `use_awaitable_t` object may also be explicitly
constructed with location information.
[heading Visual Representations]
The handler tracking output may be post-processed using the included
[^handlerviz.pl] tool to create a visual representation of the handlers
(requires the GraphViz tool [^dot]).
[c++]
[heading Custom Tracking]
Handling tracking may be customised by defining the
`BOOST_ASIO_CUSTOM_HANDLER_TRACKING` macro to the name of a header file
(enclosed in `""` or `<>`). This header file must implement the following
preprocessor macros:
[table
[[Macro] [Description]]
[
[`BOOST_ASIO_INHERIT_TRACKED_HANDLER`]
[Specifies a base class for classes that implement asynchronous operations.
When used, the macro immediately follows the class name, so it must have
the form `: public my_class`.]
]
[
[`BOOST_ASIO_ALSO_INHERIT_TRACKED_HANDLER`]
[Specifies a base class for classes that implement asynchronous operations.
When used, the macro follows other base classes, so it must have the form
`, public my_class`.]
]
[
[`BOOST_ASIO_HANDLER_TRACKING_INIT(args)`]
[An expression that is used to initialise the tracking mechanism.]
]
[
[`BOOST_ASIO_HANDLER_LOCATION(args)`]
[A variable declaration that is used to define a source code location.
`args` is a parenthesised function argument list containing the file
name, line number, and function name.]
]
[
[`BOOST_ASIO_HANDLER_CREATION(args)`]
[An expression that is called on creation of an asynchronous operation.
`args` is a parenthesised function argument list containing the owning
execution context, the tracked handler, the name of the object type, a
pointer to the object, the object's native handle, and the operation name.]
]
[
[`BOOST_ASIO_HANDLER_COMPLETION(args)`]
[An expression that is called on completion of an asynchronous operation.
`args` is a parenthesised function argument list containing the tracked
handler.]
]
[
[`BOOST_ASIO_HANDLER_INVOCATION_BEGIN(args)`]
[An expression that is called immediately before a completion handler is
invoked. `args` is a parenthesised function argument list containing the
arguments to the completion handler.]
]
[
[`BOOST_ASIO_HANDLER_INVOCATION_END`]
[An expression that is called immediately after a completion handler is
invoked.]
]
[
[`BOOST_ASIO_HANDLER_OPERATION(args)`]
[An expression that is called when some synchronous object operation is
called (such as `close()` or `cancel()`). `args` is a parenthesised
function argument list containing the owning execution context, the name
of the object type, a pointer to the object, the object's native handle,
and the operation name.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_REGISTRATION(args)`]
[An expression that is called when an object is registered with the
reactor. `args` is a parenthesised function argument list containing the
owning execution context, the object's native handle, and a unique
registration key.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_DEREGISTRATION(args)`]
[An expression that is called when an object is deregistered from the
reactor. `args` is a parenthesised function argument list containing the
owning execution context, the object's native handle, and a unique
registration key.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_READ_EVENT`]
[A bitmask constant used to identify reactor read readiness events.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_WRITE_EVENT`]
[A bitmask constant used to identify reactor write readiness events.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_ERROR_EVENT`]
[A bitmask constant used to identify reactor error readiness events.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_EVENTS(args)`]
[An expression that is called when an object registered with the reactor
becomes ready. `args` is a parenthesised function argument list containing
the owning execution context, the unique registration key, and a bitmask of
the ready events.]
]
[
[`BOOST_ASIO_HANDLER_REACTOR_OPERATION(args)`]
[An expression that is called when the implementation performs a system
call as part of a reactor-based asynchronous operation. `args` is a
parenthesised function argument list containing the tracked handler, the
operation name, the error code produced by the operation, and (optionally)
the number of bytes transferred.]
]
]
[heading See Also]
[link boost_asio.examples.cpp11_examples.handler_tracking Handler tracking
examples].
[endsect]