• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1[/
2 / Copyright (c) 2003-2021 Christopher M. Kohlhoff (chris at kohlhoff dot com)
3 /
4 / Distributed under the Boost Software License, Version 1.0. (See accompanying
5 / file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
6 /]
7
8[section:handler_tracking Handler Tracking]
9
10To aid in debugging asynchronous programs, Boost.Asio provides support for handler
11tracking. When enabled by defining `BOOST_ASIO_ENABLE_HANDLER_TRACKING`, Boost.Asio
12writes debugging output to the standard error stream. The output records
13asynchronous operations and the relationships between their handlers.
14
15[teletype]
16This feature is useful when debugging and you need to know how your
17asynchronous operations are chained together, or what the pending asynchronous
18operations are. As an illustration, here is the output when you run the HTTP
19Server example, handle a single request, then shut down via Ctrl+C:
20
21  @asio|1589424178.741850|0*1|signal_set@0x7ffee977d878.async_wait
22  @asio|1589424178.742593|0*2|socket@0x7ffee977d8a8.async_accept
23  @asio|1589424178.742619|.2|non_blocking_accept,ec=asio.system:11
24  @asio|1589424178.742625|0|resolver@0x7ffee977d760.cancel
25  @asio|1589424195.830382|.2|non_blocking_accept,ec=system:0
26  @asio|1589424195.830413|>2|ec=system:0
27  @asio|1589424195.830473|2*3|socket@0x7fa71d808230.async_receive
28  @asio|1589424195.830496|.3|non_blocking_recv,ec=system:0,bytes_transferred=151
29  @asio|1589424195.830503|2*4|socket@0x7ffee977d8a8.async_accept
30  @asio|1589424195.830507|.4|non_blocking_accept,ec=asio.system:11
31  @asio|1589424195.830510|<2|
32  @asio|1589424195.830529|>3|ec=system:0,bytes_transferred=151
33  @asio|1589424195.831143|3^5|in 'async_write' (./../../../boost/asio/impl/write.hpp:330)
34  @asio|1589424195.831143|3*5|socket@0x7fa71d808230.async_send
35  @asio|1589424195.831186|.5|non_blocking_send,ec=system:0,bytes_transferred=1090
36  @asio|1589424195.831194|<3|
37  @asio|1589424195.831218|>5|ec=system:0,bytes_transferred=1090
38  @asio|1589424195.831263|5|socket@0x7fa71d808230.close
39  @asio|1589424195.831298|<5|
40  @asio|1589424199.793770|>1|ec=system:0,signal_number=2
41  @asio|1589424199.793781|1|socket@0x7ffee977d8a8.close
42  @asio|1589424199.793809|<1|
43  @asio|1589424199.793840|>4|ec=asio.system:125
44  @asio|1589424199.793854|<4|
45  @asio|1589424199.793883|0|signal_set@0x7ffee977d878.cancel
46
47Each line is of the form:
48
49  <tag>|<timestamp>|<action>|<description>
50
51The `<tag>` is always `@asio`, and is used to identify and extract the handler
52tracking messages from the program output.
53
54The `<timestamp>` is seconds and microseconds from 1 Jan 1970 UTC.
55
56The `<action>` takes one of the following forms:
57
58[variablelist
59  [
60    [>n]
61    [The program entered the handler number `n`. The `<description>` shows the
62    arguments to the handler.]
63  ]
64  [
65    [<n]
66    [The program left handler number `n`.]
67  ]
68  [
69    [!n]
70    [The program left handler number n due to an exception.]
71  ]
72  [
73    [~n]
74    [The handler number `n` was destroyed without having been invoked. This is
75    usually the case for any unfinished asynchronous operations when the
76    `io_context` is destroyed.]
77  ]
78  [
79    [n^m]
80    [The handler number `n` is about to create a new asynchronous operation with
81    completion handler number `m`. The `<description>` contains source location
82    information to help identify where in the program the asynchronous operation
83    is being started.]
84  ]
85  [
86    [n*m]
87    [The handler number `n` created a new asynchronous operation with completion
88    handler number `m`. The `<description>` shows what asynchronous operation
89    was started.]
90  ]
91  [
92    [n]
93    [The handler number `n` performed some other operation. The `<description>`
94    shows what function was called. Currently only `close()` and `cancel()`
95    operations are logged, as these may affect the state of pending
96    asynchronous operations.]
97  ]
98  [
99    [.n]
100    [The implementation performed a system call as part of the asynchronous
101    operation for which handler number `n` is the completion handler. The
102    `<description>` shows what function was called and its results. These
103    tracking events are only emitted when using a reactor-based
104    implementation.]
105  ]
106]
107
108Where the `<description>` shows a synchronous or asynchronous operation, the
109format is `<object-type>@<pointer>.<operation>`. For handler entry, it shows a
110comma-separated list of arguments and their values.
111
112As shown above, Each handler is assigned a numeric identifier. Where the
113handler tracking output shows a handler number of 0, it means that the action
114was performed outside of any handler.
115
116[heading Adding Location Information]
117
118[c++]
119Programs may augment the handler tracking output's location information by
120using the macro `BOOST_ASIO_HANDLER_LOCATION` in the source code. For example:
121
122  #define HANDLER_LOCATION \
123    BOOST_ASIO_HANDLER_LOCATION((__FILE__, __LINE__, __func__))
124
125  // ...
126
127  void do_read()
128  {
129    HANDLER_LOCATION;
130
131    auto self(shared_from_this());
132    socket_.async_read_some(boost::asio::buffer(data_, max_length),
133        [this, self](boost::system::error_code ec, std::size_t length)
134        {
135          HANDLER_LOCATION;
136
137          if (!ec)
138          {
139            do_write(length);
140          }
141        });
142  }
143
144[teletype]
145With the additional location information available, the handler tracking output
146may include a call stack of source locations:
147
148  @asio|1589423304.861944|>7|ec=system:0,bytes_transferred=5
149  @asio|1589423304.861952|7^8|in 'async_write' (./../../../boost/asio/impl/write.hpp:330)
150  @asio|1589423304.861952|7^8|called from 'do_write' (handler_tracking/async_tcp_echo_server.cpp:62)
151  @asio|1589423304.861952|7^8|called from 'operator()' (handler_tracking/async_tcp_echo_server.cpp:51)
152  @asio|1589423304.861952|7*8|socket@0x7ff61c008230.async_send
153  @asio|1589423304.861975|.8|non_blocking_send,ec=system:0,bytes_transferred=5
154  @asio|1589423304.861980|<7|
155
156Furthermore, if `std::source_location` or `std::experimental::source_location`
157are available, the [link boost_asio.reference.use_awaitable_t `use_awaitable_t`]
158token (when default-constructed or used as a default completion token) will
159also cause handler tracking to output a source location for each newly created
160asynchronous operation. A `use_awaitable_t` object may also be explicitly
161constructed with location information.
162
163[heading Visual Representations]
164
165The handler tracking output may be post-processed using the included
166[^handlerviz.pl] tool to create a visual representation of the handlers
167(requires the GraphViz tool [^dot]).
168[c++]
169
170[heading Custom Tracking]
171
172Handling tracking may be customised by defining the
173`BOOST_ASIO_CUSTOM_HANDLER_TRACKING` macro to the name of a header file
174(enclosed in `""` or `<>`). This header file must implement the following
175preprocessor macros:
176
177[table
178  [[Macro] [Description]]
179  [
180    [`BOOST_ASIO_INHERIT_TRACKED_HANDLER`]
181    [Specifies a base class for classes that implement asynchronous operations.
182    When used, the macro immediately follows the class name, so it must have
183    the form `: public my_class`.]
184  ]
185  [
186    [`BOOST_ASIO_ALSO_INHERIT_TRACKED_HANDLER`]
187    [Specifies a base class for classes that implement asynchronous operations.
188    When used, the macro follows other base classes, so it must have the form
189    `, public my_class`.]
190  ]
191  [
192    [`BOOST_ASIO_HANDLER_TRACKING_INIT(args)`]
193    [An expression that is used to initialise the tracking mechanism.]
194  ]
195  [
196    [`BOOST_ASIO_HANDLER_LOCATION(args)`]
197    [A variable declaration that is used to define a source code location.
198    `args` is a parenthesised function argument list containing the file
199    name, line number, and function name.]
200  ]
201  [
202    [`BOOST_ASIO_HANDLER_CREATION(args)`]
203    [An expression that is called on creation of an asynchronous operation.
204    `args` is a parenthesised function argument list containing the owning
205    execution context, the tracked handler, the name of the object type, a
206    pointer to the object, the object's native handle, and the operation name.]
207  ]
208  [
209    [`BOOST_ASIO_HANDLER_COMPLETION(args)`]
210    [An expression that is called on completion of an asynchronous operation.
211    `args` is a parenthesised function argument list containing the tracked
212    handler.]
213  ]
214  [
215    [`BOOST_ASIO_HANDLER_INVOCATION_BEGIN(args)`]
216    [An expression that is called immediately before a completion handler is
217    invoked. `args` is a parenthesised function argument list containing the
218    arguments to the completion handler.]
219  ]
220  [
221    [`BOOST_ASIO_HANDLER_INVOCATION_END`]
222    [An expression that is called immediately after a completion handler is
223    invoked.]
224  ]
225  [
226    [`BOOST_ASIO_HANDLER_OPERATION(args)`]
227    [An expression that is called when some synchronous object operation is
228    called (such as `close()` or `cancel()`). `args` is a parenthesised
229    function argument list containing the owning execution context, the name
230    of the object type, a pointer to the object, the object's native handle,
231    and the operation name.]
232  ]
233  [
234    [`BOOST_ASIO_HANDLER_REACTOR_REGISTRATION(args)`]
235    [An expression that is called when an object is registered with the
236    reactor. `args` is a parenthesised function argument list containing the
237    owning execution context, the object's native handle, and a unique
238    registration key.]
239  ]
240  [
241    [`BOOST_ASIO_HANDLER_REACTOR_DEREGISTRATION(args)`]
242    [An expression that is called when an object is deregistered from the
243    reactor. `args` is a parenthesised function argument list containing the
244    owning execution context, the object's native handle, and a unique
245    registration key.]
246  ]
247  [
248    [`BOOST_ASIO_HANDLER_REACTOR_READ_EVENT`]
249    [A bitmask constant used to identify reactor read readiness events.]
250  ]
251  [
252    [`BOOST_ASIO_HANDLER_REACTOR_WRITE_EVENT`]
253    [A bitmask constant used to identify reactor write readiness events.]
254  ]
255  [
256    [`BOOST_ASIO_HANDLER_REACTOR_ERROR_EVENT`]
257    [A bitmask constant used to identify reactor error readiness events.]
258  ]
259  [
260    [`BOOST_ASIO_HANDLER_REACTOR_EVENTS(args)`]
261    [An expression that is called when an object registered with the reactor
262    becomes ready. `args` is a parenthesised function argument list containing
263    the owning execution context, the unique registration key, and a bitmask of
264    the ready events.]
265  ]
266  [
267    [`BOOST_ASIO_HANDLER_REACTOR_OPERATION(args)`]
268    [An expression that is called when the implementation performs a system
269    call as part of a reactor-based asynchronous operation. `args` is a
270    parenthesised function argument list containing the tracked handler, the
271    operation name, the error code produced by the operation, and (optionally)
272    the number of bytes transferred.]
273  ]
274]
275
276[heading See Also]
277
278[link boost_asio.examples.cpp11_examples.handler_tracking Handler tracking
279examples].
280
281[endsect]
282