1//
2// detail/impl/handler_tracking.ipp
3// ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
4//
5// Copyright (c) 2003-2021 Christopher M. Kohlhoff (chris at kohlhoff dot com)
6//
7// Distributed under the Boost Software License, Version 1.0. (See accompanying
8// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
9//
10
11#ifndef BOOST_ASIO_DETAIL_IMPL_HANDLER_TRACKING_IPP
12#define BOOST_ASIO_DETAIL_IMPL_HANDLER_TRACKING_IPP
13
14#if defined(_MSC_VER) && (_MSC_VER >= 1200)
15# pragma once
16#endif // defined(_MSC_VER) && (_MSC_VER >= 1200)
17
18#include <boost/asio/detail/config.hpp>
19
20#if defined(BOOST_ASIO_CUSTOM_HANDLER_TRACKING)
21
22// The handler tracking implementation is provided by the user-specified header.
23
24#elif defined(BOOST_ASIO_ENABLE_HANDLER_TRACKING)
25
26#include <cstdarg>
27#include <cstdio>
28#include <boost/asio/detail/handler_tracking.hpp>
29
30#if defined(BOOST_ASIO_HAS_BOOST_DATE_TIME)
31# include <boost/asio/time_traits.hpp>
32#elif defined(BOOST_ASIO_HAS_CHRONO)
33# include <boost/asio/detail/chrono.hpp>
34# include <boost/asio/detail/chrono_time_traits.hpp>
35# include <boost/asio/wait_traits.hpp>
36#endif // defined(BOOST_ASIO_HAS_BOOST_DATE_TIME)
37
38#if defined(BOOST_ASIO_WINDOWS_RUNTIME)
39# include <boost/asio/detail/socket_types.hpp>
40#elif !defined(BOOST_ASIO_WINDOWS)
41# include <unistd.h>
42#endif // !defined(BOOST_ASIO_WINDOWS)
43
44#include <boost/asio/detail/push_options.hpp>
45
46namespace boost {
47namespace asio {
48namespace detail {
49
50struct handler_tracking_timestamp
51{
52  uint64_t seconds;
53  uint64_t microseconds;
54
55  handler_tracking_timestamp()
56  {
57#if defined(BOOST_ASIO_HAS_BOOST_DATE_TIME)
58    boost::posix_time::ptime epoch(boost::gregorian::date(1970, 1, 1));
59    boost::posix_time::time_duration now =
60      boost::posix_time::microsec_clock::universal_time() - epoch;
61#elif defined(BOOST_ASIO_HAS_CHRONO)
62    typedef chrono_time_traits<chrono::system_clock,
63        boost::asio::wait_traits<chrono::system_clock> > traits_helper;
64    traits_helper::posix_time_duration now(
65        chrono::system_clock::now().time_since_epoch());
66#endif
67    seconds = static_cast<uint64_t>(now.total_seconds());
68    microseconds = static_cast<uint64_t>(now.total_microseconds() % 1000000);
69  }
70};
71
72struct handler_tracking::tracking_state
73{
74  static_mutex mutex_;
75  uint64_t next_id_;
76  tss_ptr<completion>* current_completion_;
77  tss_ptr<location>* current_location_;
78};
79
80handler_tracking::tracking_state* handler_tracking::get_state()
81{
82  static tracking_state state = { BOOST_ASIO_STATIC_MUTEX_INIT, 1, 0, 0 };
83  return &state;
84}
85
86void handler_tracking::init()
87{
88  static tracking_state* state = get_state();
89
90  state->mutex_.init();
91
92  static_mutex::scoped_lock lock(state->mutex_);
93  if (state->current_completion_ == 0)
94    state->current_completion_ = new tss_ptr<completion>;
95  if (state->current_location_ == 0)
96    state->current_location_ = new tss_ptr<location>;
97}
98
99handler_tracking::location::location(
100    const char* file, int line, const char* func)
101  : file_(file),
102    line_(line),
103    func_(func),
104    next_(*get_state()->current_location_)
105{
106  if (file_)
107    *get_state()->current_location_ = this;
108}
109
110handler_tracking::location::~location()
111{
112  if (file_)
113    *get_state()->current_location_ = next_;
114}
115
116void handler_tracking::creation(execution_context&,
117    handler_tracking::tracked_handler& h,
118    const char* object_type, void* object,
119    uintmax_t /*native_handle*/, const char* op_name)
120{
121  static tracking_state* state = get_state();
122
123  static_mutex::scoped_lock lock(state->mutex_);
124  h.id_ = state->next_id_++;
125  lock.unlock();
126
127  handler_tracking_timestamp timestamp;
128
129  uint64_t current_id = 0;
130  if (completion* current_completion = *state->current_completion_)
131    current_id = current_completion->id_;
132
133  for (location* current_location = *state->current_location_;
134      current_location; current_location = current_location->next_)
135  {
136    write_line(
137#if defined(BOOST_ASIO_WINDOWS)
138        "@asio|%I64u.%06I64u|%I64u^%I64u|%s%s%.80s%s(%.80s:%d)\n",
139#else // defined(BOOST_ASIO_WINDOWS)
140        "@asio|%llu.%06llu|%llu^%llu|%s%s%.80s%s(%.80s:%d)\n",
141#endif // defined(BOOST_ASIO_WINDOWS)
142        timestamp.seconds, timestamp.microseconds,
143        current_id, h.id_,
144        current_location == *state->current_location_ ? "in " : "called from ",
145        current_location->func_ ? "'" : "",
146        current_location->func_ ? current_location->func_ : "",
147        current_location->func_ ? "' " : "",
148        current_location->file_, current_location->line_);
149  }
150
151  write_line(
152#if defined(BOOST_ASIO_WINDOWS)
153      "@asio|%I64u.%06I64u|%I64u*%I64u|%.20s@%p.%.50s\n",
154#else // defined(BOOST_ASIO_WINDOWS)
155      "@asio|%llu.%06llu|%llu*%llu|%.20s@%p.%.50s\n",
156#endif // defined(BOOST_ASIO_WINDOWS)
157      timestamp.seconds, timestamp.microseconds,
158      current_id, h.id_, object_type, object, op_name);
159}
160
161handler_tracking::completion::completion(
162    const handler_tracking::tracked_handler& h)
163  : id_(h.id_),
164    invoked_(false),
165    next_(*get_state()->current_completion_)
166{
167  *get_state()->current_completion_ = this;
168}
169
170handler_tracking::completion::~completion()
171{
172  if (id_)
173  {
174    handler_tracking_timestamp timestamp;
175
176    write_line(
177#if defined(BOOST_ASIO_WINDOWS)
178        "@asio|%I64u.%06I64u|%c%I64u|\n",
179#else // defined(BOOST_ASIO_WINDOWS)
180        "@asio|%llu.%06llu|%c%llu|\n",
181#endif // defined(BOOST_ASIO_WINDOWS)
182        timestamp.seconds, timestamp.microseconds,
183        invoked_ ? '!' : '~', id_);
184  }
185
186  *get_state()->current_completion_ = next_;
187}
188
189void handler_tracking::completion::invocation_begin()
190{
191  handler_tracking_timestamp timestamp;
192
193  write_line(
194#if defined(BOOST_ASIO_WINDOWS)
195      "@asio|%I64u.%06I64u|>%I64u|\n",
196#else // defined(BOOST_ASIO_WINDOWS)
197      "@asio|%llu.%06llu|>%llu|\n",
198#endif // defined(BOOST_ASIO_WINDOWS)
199      timestamp.seconds, timestamp.microseconds, id_);
200
201  invoked_ = true;
202}
203
204void handler_tracking::completion::invocation_begin(
205    const boost::system::error_code& ec)
206{
207  handler_tracking_timestamp timestamp;
208
209  write_line(
210#if defined(BOOST_ASIO_WINDOWS)
211      "@asio|%I64u.%06I64u|>%I64u|ec=%.20s:%d\n",
212#else // defined(BOOST_ASIO_WINDOWS)
213      "@asio|%llu.%06llu|>%llu|ec=%.20s:%d\n",
214#endif // defined(BOOST_ASIO_WINDOWS)
215      timestamp.seconds, timestamp.microseconds,
216      id_, ec.category().name(), ec.value());
217
218  invoked_ = true;
219}
220
221void handler_tracking::completion::invocation_begin(
222    const boost::system::error_code& ec, std::size_t bytes_transferred)
223{
224  handler_tracking_timestamp timestamp;
225
226  write_line(
227#if defined(BOOST_ASIO_WINDOWS)
228      "@asio|%I64u.%06I64u|>%I64u|ec=%.20s:%d,bytes_transferred=%I64u\n",
229#else // defined(BOOST_ASIO_WINDOWS)
230      "@asio|%llu.%06llu|>%llu|ec=%.20s:%d,bytes_transferred=%llu\n",
231#endif // defined(BOOST_ASIO_WINDOWS)
232      timestamp.seconds, timestamp.microseconds,
233      id_, ec.category().name(), ec.value(),
234      static_cast<uint64_t>(bytes_transferred));
235
236  invoked_ = true;
237}
238
239void handler_tracking::completion::invocation_begin(
240    const boost::system::error_code& ec, int signal_number)
241{
242  handler_tracking_timestamp timestamp;
243
244  write_line(
245#if defined(BOOST_ASIO_WINDOWS)
246      "@asio|%I64u.%06I64u|>%I64u|ec=%.20s:%d,signal_number=%d\n",
247#else // defined(BOOST_ASIO_WINDOWS)
248      "@asio|%llu.%06llu|>%llu|ec=%.20s:%d,signal_number=%d\n",
249#endif // defined(BOOST_ASIO_WINDOWS)
250      timestamp.seconds, timestamp.microseconds,
251      id_, ec.category().name(), ec.value(), signal_number);
252
253  invoked_ = true;
254}
255
256void handler_tracking::completion::invocation_begin(
257    const boost::system::error_code& ec, const char* arg)
258{
259  handler_tracking_timestamp timestamp;
260
261  write_line(
262#if defined(BOOST_ASIO_WINDOWS)
263      "@asio|%I64u.%06I64u|>%I64u|ec=%.20s:%d,%.50s\n",
264#else // defined(BOOST_ASIO_WINDOWS)
265      "@asio|%llu.%06llu|>%llu|ec=%.20s:%d,%.50s\n",
266#endif // defined(BOOST_ASIO_WINDOWS)
267      timestamp.seconds, timestamp.microseconds,
268      id_, ec.category().name(), ec.value(), arg);
269
270  invoked_ = true;
271}
272
273void handler_tracking::completion::invocation_end()
274{
275  if (id_)
276  {
277    handler_tracking_timestamp timestamp;
278
279    write_line(
280#if defined(BOOST_ASIO_WINDOWS)
281        "@asio|%I64u.%06I64u|<%I64u|\n",
282#else // defined(BOOST_ASIO_WINDOWS)
283        "@asio|%llu.%06llu|<%llu|\n",
284#endif // defined(BOOST_ASIO_WINDOWS)
285        timestamp.seconds, timestamp.microseconds, id_);
286
287    id_ = 0;
288  }
289}
290
291void handler_tracking::operation(execution_context&,
292    const char* object_type, void* object,
293    uintmax_t /*native_handle*/, const char* op_name)
294{
295  static tracking_state* state = get_state();
296
297  handler_tracking_timestamp timestamp;
298
299  unsigned long long current_id = 0;
300  if (completion* current_completion = *state->current_completion_)
301    current_id = current_completion->id_;
302
303  write_line(
304#if defined(BOOST_ASIO_WINDOWS)
305      "@asio|%I64u.%06I64u|%I64u|%.20s@%p.%.50s\n",
306#else // defined(BOOST_ASIO_WINDOWS)
307      "@asio|%llu.%06llu|%llu|%.20s@%p.%.50s\n",
308#endif // defined(BOOST_ASIO_WINDOWS)
309      timestamp.seconds, timestamp.microseconds,
310      current_id, object_type, object, op_name);
311}
312
313void handler_tracking::reactor_registration(execution_context& /*context*/,
314    uintmax_t /*native_handle*/, uintmax_t /*registration*/)
315{
316}
317
318void handler_tracking::reactor_deregistration(execution_context& /*context*/,
319    uintmax_t /*native_handle*/, uintmax_t /*registration*/)
320{
321}
322
323void handler_tracking::reactor_events(execution_context& /*context*/,
324    uintmax_t /*native_handle*/, unsigned /*events*/)
325{
326}
327
328void handler_tracking::reactor_operation(
329    const tracked_handler& h, const char* op_name,
330    const boost::system::error_code& ec)
331{
332  handler_tracking_timestamp timestamp;
333
334  write_line(
335#if defined(BOOST_ASIO_WINDOWS)
336      "@asio|%I64u.%06I64u|.%I64u|%s,ec=%.20s:%d\n",
337#else // defined(BOOST_ASIO_WINDOWS)
338      "@asio|%llu.%06llu|.%llu|%s,ec=%.20s:%d\n",
339#endif // defined(BOOST_ASIO_WINDOWS)
340      timestamp.seconds, timestamp.microseconds,
341      h.id_, op_name, ec.category().name(), ec.value());
342}
343
344void handler_tracking::reactor_operation(
345    const tracked_handler& h, const char* op_name,
346    const boost::system::error_code& ec, std::size_t bytes_transferred)
347{
348  handler_tracking_timestamp timestamp;
349
350  write_line(
351#if defined(BOOST_ASIO_WINDOWS)
352      "@asio|%I64u.%06I64u|.%I64u|%s,ec=%.20s:%d,bytes_transferred=%I64u\n",
353#else // defined(BOOST_ASIO_WINDOWS)
354      "@asio|%llu.%06llu|.%llu|%s,ec=%.20s:%d,bytes_transferred=%llu\n",
355#endif // defined(BOOST_ASIO_WINDOWS)
356      timestamp.seconds, timestamp.microseconds,
357      h.id_, op_name, ec.category().name(), ec.value(),
358      static_cast<uint64_t>(bytes_transferred));
359}
360
361void handler_tracking::write_line(const char* format, ...)
362{
363  using namespace std; // For sprintf (or equivalent).
364
365  va_list args;
366  va_start(args, format);
367
368  char line[256] = "";
369#if defined(BOOST_ASIO_HAS_SECURE_RTL)
370  int length = vsprintf_s(line, sizeof(line), format, args);
371#else // defined(BOOST_ASIO_HAS_SECURE_RTL)
372  int length = vsprintf(line, format, args);
373#endif // defined(BOOST_ASIO_HAS_SECURE_RTL)
374
375  va_end(args);
376
377#if defined(BOOST_ASIO_WINDOWS_RUNTIME)
378  wchar_t wline[256] = L"";
379  mbstowcs_s(0, wline, sizeof(wline) / sizeof(wchar_t), line, length);
380  ::OutputDebugStringW(wline);
381#elif defined(BOOST_ASIO_WINDOWS)
382  HANDLE stderr_handle = ::GetStdHandle(STD_ERROR_HANDLE);
383  DWORD bytes_written = 0;
384  ::WriteFile(stderr_handle, line, length, &bytes_written, 0);
385#else // defined(BOOST_ASIO_WINDOWS)
386  ::write(STDERR_FILENO, line, length);
387#endif // defined(BOOST_ASIO_WINDOWS)
388}
389
390} // namespace detail
391} // namespace asio
392} // namespace boost
393
394#include <boost/asio/detail/pop_options.hpp>
395
396#endif // defined(BOOST_ASIO_ENABLE_HANDLER_TRACKING)
397
398#endif // BOOST_ASIO_DETAIL_IMPL_HANDLER_TRACKING_IPP
399