ngtcp2_log.c 30 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834
  1. /*
  2. * ngtcp2
  3. *
  4. * Copyright (c) 2018 ngtcp2 contributors
  5. *
  6. * Permission is hereby granted, free of charge, to any person obtaining
  7. * a copy of this software and associated documentation files (the
  8. * "Software"), to deal in the Software without restriction, including
  9. * without limitation the rights to use, copy, modify, merge, publish,
  10. * distribute, sublicense, and/or sell copies of the Software, and to
  11. * permit persons to whom the Software is furnished to do so, subject to
  12. * the following conditions:
  13. *
  14. * The above copyright notice and this permission notice shall be
  15. * included in all copies or substantial portions of the Software.
  16. *
  17. * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
  18. * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
  19. * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
  20. * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
  21. * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
  22. * OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
  23. * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  24. */
  25. #include "ngtcp2_log.h"
  26. #include <stdio.h>
  27. #ifdef HAVE_UNISTD_H
  28. # include <unistd.h>
  29. #endif /* defined(HAVE_UNISTD_H) */
  30. #include <assert.h>
  31. #include <string.h>
  32. #include "ngtcp2_str.h"
  33. #include "ngtcp2_vec.h"
  34. #include "ngtcp2_macro.h"
  35. #include "ngtcp2_conv.h"
  36. #include "ngtcp2_unreachable.h"
  37. #include "ngtcp2_net.h"
  38. void ngtcp2_log_init(ngtcp2_log *log, const ngtcp2_cid *scid,
  39. ngtcp2_printf log_printf, ngtcp2_tstamp ts,
  40. void *user_data) {
  41. if (scid) {
  42. ngtcp2_encode_hex(log->scid, scid->data, scid->datalen);
  43. } else {
  44. log->scid[0] = '\0';
  45. }
  46. log->log_printf = log_printf;
  47. log->events = 0xff;
  48. log->ts = log->last_ts = ts;
  49. log->user_data = user_data;
  50. }
  51. /*
  52. * # Log header
  53. *
  54. * <LEVEL><TIMESTAMP> <SCID> <EVENT>
  55. *
  56. * <LEVEL>:
  57. * Log level. I=Info, W=Warning, E=Error
  58. *
  59. * <TIMESTAMP>:
  60. * Timestamp relative to ngtcp2_log.ts field in milliseconds
  61. * resolution.
  62. *
  63. * <SCID>:
  64. * Source Connection ID in hex string.
  65. *
  66. * <EVENT>:
  67. * Event. See ngtcp2_log_event.
  68. *
  69. * # Frame event
  70. *
  71. * <DIR> <PKN> <PKTNAME> <FRAMENAME>(<FRAMETYPE>)
  72. *
  73. * <DIR>:
  74. * Flow direction. tx=transmission, rx=reception
  75. *
  76. * <PKN>:
  77. * Packet number.
  78. *
  79. * <PKTNAME>:
  80. * Packet name. (e.g., Initial, Handshake, 1RTT)
  81. *
  82. * <FRAMENAME>:
  83. * Frame name. (e.g., STREAM, ACK, PING)
  84. *
  85. * <FRAMETYPE>:
  86. * Frame type in hex string.
  87. */
  88. #define NGTCP2_LOG_BUFLEN 4096
  89. /* TODO Split second and remaining fraction with comma */
  90. #define NGTCP2_LOG_HD "I%08" PRIu64 " 0x%s %s"
  91. #define NGTCP2_LOG_PKT NGTCP2_LOG_HD " %s %" PRId64 " %s"
  92. #define NGTCP2_LOG_TP NGTCP2_LOG_HD " remote transport_parameters"
  93. #define NGTCP2_LOG_FRM_HD_FIELDS(DIR) \
  94. timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "frm", \
  95. (DIR), hd->pkt_num, strpkttype(hd)
  96. #define NGTCP2_LOG_PKT_HD_FIELDS(DIR) \
  97. timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "pkt", \
  98. (DIR), hd->pkt_num, strpkttype(hd)
  99. #define NGTCP2_LOG_TP_HD_FIELDS \
  100. timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "cry"
  101. static const char *strerrorcode(uint64_t error_code) {
  102. switch (error_code) {
  103. case NGTCP2_NO_ERROR:
  104. return "NO_ERROR";
  105. case NGTCP2_INTERNAL_ERROR:
  106. return "INTERNAL_ERROR";
  107. case NGTCP2_CONNECTION_REFUSED:
  108. return "CONNECTION_REFUSED";
  109. case NGTCP2_FLOW_CONTROL_ERROR:
  110. return "FLOW_CONTROL_ERROR";
  111. case NGTCP2_STREAM_LIMIT_ERROR:
  112. return "STREAM_LIMIT_ERROR";
  113. case NGTCP2_STREAM_STATE_ERROR:
  114. return "STREAM_STATE_ERROR";
  115. case NGTCP2_FINAL_SIZE_ERROR:
  116. return "FINAL_SIZE_ERROR";
  117. case NGTCP2_FRAME_ENCODING_ERROR:
  118. return "FRAME_ENCODING_ERROR";
  119. case NGTCP2_TRANSPORT_PARAMETER_ERROR:
  120. return "TRANSPORT_PARAMETER_ERROR";
  121. case NGTCP2_CONNECTION_ID_LIMIT_ERROR:
  122. return "CONNECTION_ID_LIMIT_ERROR";
  123. case NGTCP2_PROTOCOL_VIOLATION:
  124. return "PROTOCOL_VIOLATION";
  125. case NGTCP2_INVALID_TOKEN:
  126. return "INVALID_TOKEN";
  127. case NGTCP2_APPLICATION_ERROR:
  128. return "APPLICATION_ERROR";
  129. case NGTCP2_CRYPTO_BUFFER_EXCEEDED:
  130. return "CRYPTO_BUFFER_EXCEEDED";
  131. case NGTCP2_KEY_UPDATE_ERROR:
  132. return "KEY_UPDATE_ERROR";
  133. case NGTCP2_VERSION_NEGOTIATION_ERROR:
  134. return "VERSION_NEGOTIATION_ERROR";
  135. default:
  136. if (0x100u <= error_code && error_code <= 0x1ffu) {
  137. return "CRYPTO_ERROR";
  138. }
  139. return "(unknown)";
  140. }
  141. }
  142. static const char *strapperrorcode(uint64_t app_error_code) {
  143. (void)app_error_code;
  144. return "(unknown)";
  145. }
  146. static const char *strpkttype_long(uint8_t type) {
  147. switch (type) {
  148. case NGTCP2_PKT_INITIAL:
  149. return "Initial";
  150. case NGTCP2_PKT_RETRY:
  151. return "Retry";
  152. case NGTCP2_PKT_HANDSHAKE:
  153. return "Handshake";
  154. case NGTCP2_PKT_0RTT:
  155. return "0RTT";
  156. default:
  157. return "(unknown)";
  158. }
  159. }
  160. static const char *strpkttype(const ngtcp2_pkt_hd *hd) {
  161. if (hd->flags & NGTCP2_PKT_FLAG_LONG_FORM) {
  162. return strpkttype_long(hd->type);
  163. }
  164. switch (hd->type) {
  165. case NGTCP2_PKT_VERSION_NEGOTIATION:
  166. return "VN";
  167. case NGTCP2_PKT_STATELESS_RESET:
  168. return "SR";
  169. case NGTCP2_PKT_1RTT:
  170. return "1RTT";
  171. default:
  172. return "(unknown)";
  173. }
  174. }
  175. static const char *strpkttype_type_flags(uint8_t type, uint8_t flags) {
  176. ngtcp2_pkt_hd hd = {0};
  177. hd.type = type;
  178. hd.flags = flags;
  179. return strpkttype(&hd);
  180. }
  181. static const char *strevent(ngtcp2_log_event ev) {
  182. switch (ev) {
  183. case NGTCP2_LOG_EVENT_CON:
  184. return "con";
  185. case NGTCP2_LOG_EVENT_PKT:
  186. return "pkt";
  187. case NGTCP2_LOG_EVENT_FRM:
  188. return "frm";
  189. case NGTCP2_LOG_EVENT_LDC:
  190. return "ldc";
  191. case NGTCP2_LOG_EVENT_CRY:
  192. return "cry";
  193. case NGTCP2_LOG_EVENT_PTV:
  194. return "ptv";
  195. case NGTCP2_LOG_EVENT_CCA:
  196. return "cca";
  197. case NGTCP2_LOG_EVENT_NONE:
  198. default:
  199. return "non";
  200. }
  201. }
  202. static uint64_t timestamp_cast(uint64_t ns) { return ns / NGTCP2_MILLISECONDS; }
  203. static void log_fr_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  204. const ngtcp2_stream *fr, const char *dir) {
  205. log->log_printf(
  206. log->user_data,
  207. (NGTCP2_LOG_PKT " STREAM(0x%02" PRIx64 ") id=0x%" PRIx64
  208. " fin=%d offset=%" PRIu64 " len=%" PRIu64 " uni=%d"),
  209. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type | fr->flags, fr->stream_id, fr->fin,
  210. fr->offset, ngtcp2_vec_len(fr->data, fr->datacnt),
  211. (fr->stream_id & 0x2) != 0);
  212. }
  213. static void log_fr_ack(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  214. const ngtcp2_ack *fr, const char *dir) {
  215. int64_t largest_ack, min_ack;
  216. size_t i;
  217. log->log_printf(
  218. log->user_data,
  219. (NGTCP2_LOG_PKT " ACK(0x%02" PRIx64 ") largest_ack=%" PRId64
  220. " ack_delay=%" PRIu64 "(%" PRIu64 ") ack_range_count=%zu"),
  221. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->largest_ack,
  222. fr->ack_delay_unscaled / NGTCP2_MILLISECONDS, fr->ack_delay, fr->rangecnt);
  223. largest_ack = fr->largest_ack;
  224. min_ack = fr->largest_ack - (int64_t)fr->first_ack_range;
  225. log->log_printf(log->user_data,
  226. (NGTCP2_LOG_PKT " ACK(0x%02" PRIx64 ") range=[%" PRId64
  227. "..%" PRId64 "] len=%" PRIu64),
  228. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack, min_ack,
  229. fr->first_ack_range);
  230. for (i = 0; i < fr->rangecnt; ++i) {
  231. const ngtcp2_ack_range *range = &fr->ranges[i];
  232. largest_ack = min_ack - (int64_t)range->gap - 2;
  233. min_ack = largest_ack - (int64_t)range->len;
  234. log->log_printf(log->user_data,
  235. (NGTCP2_LOG_PKT " ACK(0x%02" PRIx64 ") range=[%" PRId64
  236. "..%" PRId64 "] gap=%" PRIu64
  237. " len=%" PRIu64),
  238. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack,
  239. min_ack, range->gap, range->len);
  240. }
  241. if (fr->type == NGTCP2_FRAME_ACK_ECN) {
  242. log->log_printf(log->user_data,
  243. (NGTCP2_LOG_PKT " ACK(0x%02" PRIx64 ") ect0=%" PRIu64
  244. " ect1=%" PRIu64 " ce=%" PRIu64),
  245. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->ecn.ect0,
  246. fr->ecn.ect1, fr->ecn.ce);
  247. }
  248. }
  249. static void log_fr_padding(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  250. const ngtcp2_padding *fr, const char *dir) {
  251. log->log_printf(log->user_data,
  252. (NGTCP2_LOG_PKT " PADDING(0x%02" PRIx64 ") len=%zu"),
  253. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->len);
  254. }
  255. static void log_fr_reset_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  256. const ngtcp2_reset_stream *fr,
  257. const char *dir) {
  258. log->log_printf(
  259. log->user_data,
  260. (NGTCP2_LOG_PKT " RESET_STREAM(0x%02" PRIx64 ") id=0x%" PRIx64
  261. " app_error_code=%s(0x%" PRIx64 ") final_size=%" PRIu64),
  262. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id,
  263. strapperrorcode(fr->app_error_code), fr->app_error_code, fr->final_size);
  264. }
  265. static void log_fr_connection_close(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  266. const ngtcp2_connection_close *fr,
  267. const char *dir) {
  268. char reason[256];
  269. size_t reasonlen = ngtcp2_min_size(sizeof(reason) - 1, fr->reasonlen);
  270. log->log_printf(
  271. log->user_data,
  272. (NGTCP2_LOG_PKT " CONNECTION_CLOSE(0x%02" PRIx64
  273. ") error_code=%s(0x%" PRIx64 ") "
  274. "frame_type=%" PRIx64 " reason_len=%zu reason=[%s]"),
  275. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type,
  276. fr->type == NGTCP2_FRAME_CONNECTION_CLOSE ? strerrorcode(fr->error_code)
  277. : strapperrorcode(fr->error_code),
  278. fr->error_code, fr->frame_type, fr->reasonlen,
  279. ngtcp2_encode_printable_ascii(reason, fr->reason, reasonlen));
  280. }
  281. static void log_fr_max_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  282. const ngtcp2_max_data *fr, const char *dir) {
  283. log->log_printf(
  284. log->user_data,
  285. (NGTCP2_LOG_PKT " MAX_DATA(0x%02" PRIx64 ") max_data=%" PRIu64),
  286. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_data);
  287. }
  288. static void log_fr_max_stream_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  289. const ngtcp2_max_stream_data *fr,
  290. const char *dir) {
  291. log->log_printf(log->user_data,
  292. (NGTCP2_LOG_PKT " MAX_STREAM_DATA(0x%02" PRIx64
  293. ") id=0x%" PRIx64
  294. " max_stream_data=%" PRIu64),
  295. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id,
  296. fr->max_stream_data);
  297. }
  298. static void log_fr_max_streams(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  299. const ngtcp2_max_streams *fr, const char *dir) {
  300. log->log_printf(
  301. log->user_data,
  302. (NGTCP2_LOG_PKT " MAX_STREAMS(0x%02" PRIx64 ") max_streams=%" PRIu64),
  303. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams);
  304. }
  305. static void log_fr_ping(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  306. const ngtcp2_ping *fr, const char *dir) {
  307. log->log_printf(log->user_data, (NGTCP2_LOG_PKT " PING(0x%02" PRIx64 ")"),
  308. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type);
  309. }
  310. static void log_fr_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  311. const ngtcp2_data_blocked *fr,
  312. const char *dir) {
  313. log->log_printf(
  314. log->user_data,
  315. (NGTCP2_LOG_PKT " DATA_BLOCKED(0x%02" PRIx64 ") offset=%" PRIu64),
  316. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset);
  317. }
  318. static void log_fr_stream_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  319. const ngtcp2_stream_data_blocked *fr,
  320. const char *dir) {
  321. log->log_printf(log->user_data,
  322. (NGTCP2_LOG_PKT " STREAM_DATA_BLOCKED(0x%02" PRIx64
  323. ") id=0x%" PRIx64 " offset=%" PRIu64),
  324. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id,
  325. fr->offset);
  326. }
  327. static void log_fr_streams_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  328. const ngtcp2_streams_blocked *fr,
  329. const char *dir) {
  330. log->log_printf(
  331. log->user_data,
  332. (NGTCP2_LOG_PKT " STREAMS_BLOCKED(0x%02" PRIx64 ") max_streams=%" PRIu64),
  333. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams);
  334. }
  335. static void log_fr_new_connection_id(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  336. const ngtcp2_new_connection_id *fr,
  337. const char *dir) {
  338. uint8_t buf[sizeof(fr->stateless_reset_token) * 2 + 1];
  339. uint8_t cid[sizeof(fr->cid.data) * 2 + 1];
  340. log->log_printf(
  341. log->user_data,
  342. (NGTCP2_LOG_PKT " NEW_CONNECTION_ID(0x%02" PRIx64 ") seq=%" PRIu64
  343. " cid=0x%s retire_prior_to=%" PRIu64
  344. " stateless_reset_token=0x%s"),
  345. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq,
  346. (const char *)ngtcp2_encode_hex(cid, fr->cid.data, fr->cid.datalen),
  347. fr->retire_prior_to,
  348. (const char *)ngtcp2_encode_hex(buf, fr->stateless_reset_token,
  349. sizeof(fr->stateless_reset_token)));
  350. }
  351. static void log_fr_stop_sending(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  352. const ngtcp2_stop_sending *fr,
  353. const char *dir) {
  354. log->log_printf(log->user_data,
  355. (NGTCP2_LOG_PKT " STOP_SENDING(0x%02" PRIx64 ") id=0x%" PRIx64
  356. " app_error_code=%s(0x%" PRIx64 ")"),
  357. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id,
  358. strapperrorcode(fr->app_error_code), fr->app_error_code);
  359. }
  360. static void log_fr_path_challenge(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  361. const ngtcp2_path_challenge *fr,
  362. const char *dir) {
  363. uint8_t buf[sizeof(fr->data) * 2 + 1];
  364. log->log_printf(
  365. log->user_data,
  366. (NGTCP2_LOG_PKT " PATH_CHALLENGE(0x%02" PRIx64 ") data=0x%s"),
  367. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type,
  368. (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data)));
  369. }
  370. static void log_fr_path_response(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  371. const ngtcp2_path_response *fr,
  372. const char *dir) {
  373. uint8_t buf[sizeof(fr->data) * 2 + 1];
  374. log->log_printf(
  375. log->user_data,
  376. (NGTCP2_LOG_PKT " PATH_RESPONSE(0x%02" PRIx64 ") data=0x%s"),
  377. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type,
  378. (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data)));
  379. }
  380. static void log_fr_crypto(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  381. const ngtcp2_stream *fr, const char *dir) {
  382. log->log_printf(
  383. log->user_data,
  384. (NGTCP2_LOG_PKT " CRYPTO(0x%02" PRIx64 ") offset=%" PRIu64 " len=%" PRIu64),
  385. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset,
  386. ngtcp2_vec_len(fr->data, fr->datacnt));
  387. }
  388. static void log_fr_new_token(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  389. const ngtcp2_new_token *fr, const char *dir) {
  390. /* Show at most first 64 bytes of token. If token is longer than 64
  391. bytes, log first 64 bytes and then append "*" */
  392. uint8_t buf[128 + 1 + 1];
  393. uint8_t *p;
  394. if (fr->tokenlen > 64) {
  395. p = ngtcp2_encode_hex(buf, fr->token, 64);
  396. p[128] = '*';
  397. p[129] = '\0';
  398. } else {
  399. p = ngtcp2_encode_hex(buf, fr->token, fr->tokenlen);
  400. }
  401. log->log_printf(
  402. log->user_data,
  403. (NGTCP2_LOG_PKT " NEW_TOKEN(0x%02" PRIx64 ") token=0x%s len=%zu"),
  404. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, (const char *)p, fr->tokenlen);
  405. }
  406. static void log_fr_retire_connection_id(ngtcp2_log *log,
  407. const ngtcp2_pkt_hd *hd,
  408. const ngtcp2_retire_connection_id *fr,
  409. const char *dir) {
  410. log->log_printf(
  411. log->user_data,
  412. (NGTCP2_LOG_PKT " RETIRE_CONNECTION_ID(0x%02" PRIx64 ") seq=%" PRIu64),
  413. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq);
  414. }
  415. static void log_fr_handshake_done(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  416. const ngtcp2_handshake_done *fr,
  417. const char *dir) {
  418. log->log_printf(log->user_data,
  419. (NGTCP2_LOG_PKT " HANDSHAKE_DONE(0x%02" PRIx64 ")"),
  420. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type);
  421. }
  422. static void log_fr_datagram(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  423. const ngtcp2_datagram *fr, const char *dir) {
  424. log->log_printf(log->user_data,
  425. (NGTCP2_LOG_PKT " DATAGRAM(0x%02" PRIx64 ") len=%" PRIu64),
  426. NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type,
  427. ngtcp2_vec_len(fr->data, fr->datacnt));
  428. }
  429. static void log_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  430. const ngtcp2_frame *fr, const char *dir) {
  431. switch (fr->type) {
  432. case NGTCP2_FRAME_STREAM:
  433. log_fr_stream(log, hd, &fr->stream, dir);
  434. break;
  435. case NGTCP2_FRAME_ACK:
  436. case NGTCP2_FRAME_ACK_ECN:
  437. log_fr_ack(log, hd, &fr->ack, dir);
  438. break;
  439. case NGTCP2_FRAME_PADDING:
  440. log_fr_padding(log, hd, &fr->padding, dir);
  441. break;
  442. case NGTCP2_FRAME_RESET_STREAM:
  443. log_fr_reset_stream(log, hd, &fr->reset_stream, dir);
  444. break;
  445. case NGTCP2_FRAME_CONNECTION_CLOSE:
  446. case NGTCP2_FRAME_CONNECTION_CLOSE_APP:
  447. log_fr_connection_close(log, hd, &fr->connection_close, dir);
  448. break;
  449. case NGTCP2_FRAME_MAX_DATA:
  450. log_fr_max_data(log, hd, &fr->max_data, dir);
  451. break;
  452. case NGTCP2_FRAME_MAX_STREAM_DATA:
  453. log_fr_max_stream_data(log, hd, &fr->max_stream_data, dir);
  454. break;
  455. case NGTCP2_FRAME_MAX_STREAMS_BIDI:
  456. case NGTCP2_FRAME_MAX_STREAMS_UNI:
  457. log_fr_max_streams(log, hd, &fr->max_streams, dir);
  458. break;
  459. case NGTCP2_FRAME_PING:
  460. log_fr_ping(log, hd, &fr->ping, dir);
  461. break;
  462. case NGTCP2_FRAME_DATA_BLOCKED:
  463. log_fr_data_blocked(log, hd, &fr->data_blocked, dir);
  464. break;
  465. case NGTCP2_FRAME_STREAM_DATA_BLOCKED:
  466. log_fr_stream_data_blocked(log, hd, &fr->stream_data_blocked, dir);
  467. break;
  468. case NGTCP2_FRAME_STREAMS_BLOCKED_BIDI:
  469. case NGTCP2_FRAME_STREAMS_BLOCKED_UNI:
  470. log_fr_streams_blocked(log, hd, &fr->streams_blocked, dir);
  471. break;
  472. case NGTCP2_FRAME_NEW_CONNECTION_ID:
  473. log_fr_new_connection_id(log, hd, &fr->new_connection_id, dir);
  474. break;
  475. case NGTCP2_FRAME_STOP_SENDING:
  476. log_fr_stop_sending(log, hd, &fr->stop_sending, dir);
  477. break;
  478. case NGTCP2_FRAME_PATH_CHALLENGE:
  479. log_fr_path_challenge(log, hd, &fr->path_challenge, dir);
  480. break;
  481. case NGTCP2_FRAME_PATH_RESPONSE:
  482. log_fr_path_response(log, hd, &fr->path_response, dir);
  483. break;
  484. case NGTCP2_FRAME_CRYPTO:
  485. log_fr_crypto(log, hd, &fr->stream, dir);
  486. break;
  487. case NGTCP2_FRAME_NEW_TOKEN:
  488. log_fr_new_token(log, hd, &fr->new_token, dir);
  489. break;
  490. case NGTCP2_FRAME_RETIRE_CONNECTION_ID:
  491. log_fr_retire_connection_id(log, hd, &fr->retire_connection_id, dir);
  492. break;
  493. case NGTCP2_FRAME_HANDSHAKE_DONE:
  494. log_fr_handshake_done(log, hd, &fr->handshake_done, dir);
  495. break;
  496. case NGTCP2_FRAME_DATAGRAM:
  497. case NGTCP2_FRAME_DATAGRAM_LEN:
  498. log_fr_datagram(log, hd, &fr->datagram, dir);
  499. break;
  500. default:
  501. ngtcp2_unreachable();
  502. }
  503. }
  504. void ngtcp2_log_rx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  505. const ngtcp2_frame *fr) {
  506. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_FRM)) {
  507. return;
  508. }
  509. log_fr(log, hd, fr, "rx");
  510. }
  511. void ngtcp2_log_tx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  512. const ngtcp2_frame *fr) {
  513. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_FRM)) {
  514. return;
  515. }
  516. log_fr(log, hd, fr, "tx");
  517. }
  518. void ngtcp2_log_rx_vn(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  519. const uint32_t *sv, size_t nsv) {
  520. size_t i;
  521. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_PKT)) {
  522. return;
  523. }
  524. for (i = 0; i < nsv; ++i) {
  525. log->log_printf(log->user_data, (NGTCP2_LOG_PKT " v=0x%08x"),
  526. NGTCP2_LOG_PKT_HD_FIELDS("rx"), sv[i]);
  527. }
  528. }
  529. void ngtcp2_log_rx_sr(ngtcp2_log *log, const ngtcp2_pkt_stateless_reset *sr) {
  530. uint8_t buf[sizeof(sr->stateless_reset_token) * 2 + 1];
  531. ngtcp2_pkt_hd shd;
  532. ngtcp2_pkt_hd *hd = &shd;
  533. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_PKT)) {
  534. return;
  535. }
  536. memset(&shd, 0, sizeof(shd));
  537. shd.type = NGTCP2_PKT_STATELESS_RESET;
  538. log->log_printf(
  539. log->user_data, (NGTCP2_LOG_PKT " token=0x%s randlen=%zu"),
  540. NGTCP2_LOG_PKT_HD_FIELDS("rx"),
  541. (const char *)ngtcp2_encode_hex(buf, sr->stateless_reset_token,
  542. sizeof(sr->stateless_reset_token)),
  543. sr->randlen);
  544. }
  545. void ngtcp2_log_remote_tp(ngtcp2_log *log,
  546. const ngtcp2_transport_params *params) {
  547. uint8_t token[NGTCP2_STATELESS_RESET_TOKENLEN * 2 + 1];
  548. uint8_t addr[16 * 2 + 7 + 1];
  549. uint8_t cid[NGTCP2_MAX_CIDLEN * 2 + 1];
  550. size_t i;
  551. const ngtcp2_sockaddr_in *sa_in;
  552. const ngtcp2_sockaddr_in6 *sa_in6;
  553. const uint8_t *p;
  554. uint32_t version;
  555. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_CRY)) {
  556. return;
  557. }
  558. if (params->stateless_reset_token_present) {
  559. log->log_printf(
  560. log->user_data, (NGTCP2_LOG_TP " stateless_reset_token=0x%s"),
  561. NGTCP2_LOG_TP_HD_FIELDS,
  562. (const char *)ngtcp2_encode_hex(token, params->stateless_reset_token,
  563. sizeof(params->stateless_reset_token)));
  564. }
  565. if (params->preferred_addr_present) {
  566. if (params->preferred_addr.ipv4_present) {
  567. sa_in = &params->preferred_addr.ipv4;
  568. log->log_printf(log->user_data,
  569. (NGTCP2_LOG_TP " preferred_address.ipv4_addr=%s"),
  570. NGTCP2_LOG_TP_HD_FIELDS,
  571. (const char *)ngtcp2_encode_ipv4(
  572. addr, (const uint8_t *)&sa_in->sin_addr));
  573. log->log_printf(log->user_data,
  574. (NGTCP2_LOG_TP " preferred_address.ipv4_port=%u"),
  575. NGTCP2_LOG_TP_HD_FIELDS, ngtcp2_ntohs(sa_in->sin_port));
  576. }
  577. if (params->preferred_addr.ipv6_present) {
  578. sa_in6 = &params->preferred_addr.ipv6;
  579. log->log_printf(log->user_data,
  580. (NGTCP2_LOG_TP " preferred_address.ipv6_addr=%s"),
  581. NGTCP2_LOG_TP_HD_FIELDS,
  582. (const char *)ngtcp2_encode_ipv6(
  583. addr, (const uint8_t *)&sa_in6->sin6_addr));
  584. log->log_printf(log->user_data,
  585. (NGTCP2_LOG_TP " preferred_address.ipv6_port=%u"),
  586. NGTCP2_LOG_TP_HD_FIELDS, ngtcp2_ntohs(sa_in6->sin6_port));
  587. }
  588. log->log_printf(
  589. log->user_data, (NGTCP2_LOG_TP " preferred_address.cid=0x%s"),
  590. NGTCP2_LOG_TP_HD_FIELDS,
  591. (const char *)ngtcp2_encode_hex(cid, params->preferred_addr.cid.data,
  592. params->preferred_addr.cid.datalen));
  593. log->log_printf(
  594. log->user_data,
  595. (NGTCP2_LOG_TP " preferred_address.stateless_reset_token=0x%s"),
  596. NGTCP2_LOG_TP_HD_FIELDS,
  597. (const char *)ngtcp2_encode_hex(
  598. token, params->preferred_addr.stateless_reset_token,
  599. sizeof(params->preferred_addr.stateless_reset_token)));
  600. }
  601. if (params->original_dcid_present) {
  602. log->log_printf(
  603. log->user_data,
  604. (NGTCP2_LOG_TP " original_destination_connection_id=0x%s"),
  605. NGTCP2_LOG_TP_HD_FIELDS,
  606. (const char *)ngtcp2_encode_hex(cid, params->original_dcid.data,
  607. params->original_dcid.datalen));
  608. }
  609. if (params->retry_scid_present) {
  610. log->log_printf(
  611. log->user_data, (NGTCP2_LOG_TP " retry_source_connection_id=0x%s"),
  612. NGTCP2_LOG_TP_HD_FIELDS,
  613. (const char *)ngtcp2_encode_hex(cid, params->retry_scid.data,
  614. params->retry_scid.datalen));
  615. }
  616. if (params->initial_scid_present) {
  617. log->log_printf(
  618. log->user_data, (NGTCP2_LOG_TP " initial_source_connection_id=0x%s"),
  619. NGTCP2_LOG_TP_HD_FIELDS,
  620. (const char *)ngtcp2_encode_hex(cid, params->initial_scid.data,
  621. params->initial_scid.datalen));
  622. }
  623. log->log_printf(
  624. log->user_data,
  625. (NGTCP2_LOG_TP " initial_max_stream_data_bidi_local=%" PRIu64),
  626. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_local);
  627. log->log_printf(
  628. log->user_data,
  629. (NGTCP2_LOG_TP " initial_max_stream_data_bidi_remote=%" PRIu64),
  630. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_remote);
  631. log->log_printf(log->user_data,
  632. (NGTCP2_LOG_TP " initial_max_stream_data_uni=%" PRIu64),
  633. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_uni);
  634. log->log_printf(log->user_data, (NGTCP2_LOG_TP " initial_max_data=%" PRIu64),
  635. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_data);
  636. log->log_printf(log->user_data,
  637. (NGTCP2_LOG_TP " initial_max_streams_bidi=%" PRIu64),
  638. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_bidi);
  639. log->log_printf(log->user_data,
  640. (NGTCP2_LOG_TP " initial_max_streams_uni=%" PRIu64),
  641. NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_uni);
  642. log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_idle_timeout=%" PRIu64),
  643. NGTCP2_LOG_TP_HD_FIELDS,
  644. params->max_idle_timeout / NGTCP2_MILLISECONDS);
  645. log->log_printf(log->user_data,
  646. (NGTCP2_LOG_TP " max_udp_payload_size=%" PRIu64),
  647. NGTCP2_LOG_TP_HD_FIELDS, params->max_udp_payload_size);
  648. log->log_printf(log->user_data,
  649. (NGTCP2_LOG_TP " ack_delay_exponent=%" PRIu64),
  650. NGTCP2_LOG_TP_HD_FIELDS, params->ack_delay_exponent);
  651. log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_ack_delay=%" PRIu64),
  652. NGTCP2_LOG_TP_HD_FIELDS,
  653. params->max_ack_delay / NGTCP2_MILLISECONDS);
  654. log->log_printf(log->user_data,
  655. (NGTCP2_LOG_TP " active_connection_id_limit=%" PRIu64),
  656. NGTCP2_LOG_TP_HD_FIELDS, params->active_connection_id_limit);
  657. log->log_printf(log->user_data,
  658. (NGTCP2_LOG_TP " disable_active_migration=%d"),
  659. NGTCP2_LOG_TP_HD_FIELDS, params->disable_active_migration);
  660. log->log_printf(log->user_data,
  661. (NGTCP2_LOG_TP " max_datagram_frame_size=%" PRIu64),
  662. NGTCP2_LOG_TP_HD_FIELDS, params->max_datagram_frame_size);
  663. log->log_printf(log->user_data, (NGTCP2_LOG_TP " grease_quic_bit=%d"),
  664. NGTCP2_LOG_TP_HD_FIELDS, params->grease_quic_bit);
  665. if (params->version_info_present) {
  666. log->log_printf(
  667. log->user_data,
  668. (NGTCP2_LOG_TP " version_information.chosen_version=0x%08x"),
  669. NGTCP2_LOG_TP_HD_FIELDS, params->version_info.chosen_version);
  670. assert(!(params->version_info.available_versionslen & 0x3));
  671. for (i = 0, p = params->version_info.available_versions;
  672. i < params->version_info.available_versionslen;
  673. i += sizeof(uint32_t)) {
  674. p = ngtcp2_get_uint32be(&version, p);
  675. log->log_printf(
  676. log->user_data,
  677. (NGTCP2_LOG_TP " version_information.available_versions[%zu]=0x%08x"),
  678. NGTCP2_LOG_TP_HD_FIELDS, i >> 2, version);
  679. }
  680. }
  681. }
  682. void ngtcp2_log_pkt_lost(ngtcp2_log *log, int64_t pkt_num, uint8_t type,
  683. uint8_t flags, ngtcp2_tstamp sent_ts) {
  684. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_LDC)) {
  685. return;
  686. }
  687. ngtcp2_log_info(log, NGTCP2_LOG_EVENT_LDC,
  688. "pkn=%" PRId64 " lost type=%s sent_ts=%" PRIu64, pkt_num,
  689. strpkttype_type_flags(type, flags), sent_ts);
  690. }
  691. static void log_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd,
  692. const char *dir) {
  693. uint8_t dcid[sizeof(hd->dcid.data) * 2 + 1];
  694. uint8_t scid[sizeof(hd->scid.data) * 2 + 1];
  695. if (!log->log_printf || !(log->events & NGTCP2_LOG_EVENT_PKT)) {
  696. return;
  697. }
  698. if (hd->type == NGTCP2_PKT_1RTT) {
  699. ngtcp2_log_info(
  700. log, NGTCP2_LOG_EVENT_PKT, "%s pkn=%" PRId64 " dcid=0x%s type=%s k=%d",
  701. dir, hd->pkt_num,
  702. (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen),
  703. strpkttype(hd), (hd->flags & NGTCP2_PKT_FLAG_KEY_PHASE) != 0);
  704. } else {
  705. ngtcp2_log_info(
  706. log, NGTCP2_LOG_EVENT_PKT,
  707. "%s pkn=%" PRId64 " dcid=0x%s scid=0x%s version=0x%08x type=%s len=%zu",
  708. dir, hd->pkt_num,
  709. (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen),
  710. (const char *)ngtcp2_encode_hex(scid, hd->scid.data, hd->scid.datalen),
  711. hd->version, strpkttype(hd), hd->len);
  712. }
  713. }
  714. void ngtcp2_log_rx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) {
  715. log_pkt_hd(log, hd, "rx");
  716. }
  717. void ngtcp2_log_tx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) {
  718. log_pkt_hd(log, hd, "tx");
  719. }
  720. void ngtcp2_log_info(ngtcp2_log *log, ngtcp2_log_event ev, const char *fmt,
  721. ...) {
  722. va_list ap;
  723. int n;
  724. char buf[NGTCP2_LOG_BUFLEN];
  725. if (!log->log_printf || !(log->events & ev)) {
  726. return;
  727. }
  728. va_start(ap, fmt);
  729. n = vsnprintf(buf, sizeof(buf), fmt, ap);
  730. va_end(ap);
  731. if (n < 0 || (size_t)n >= sizeof(buf)) {
  732. return;
  733. }
  734. log->log_printf(log->user_data, (NGTCP2_LOG_HD " %s"),
  735. timestamp_cast(log->last_ts - log->ts), log->scid,
  736. strevent(ev), buf);
  737. }
  738. void ngtcp2_log_tx_cancel(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) {
  739. ngtcp2_log_info(log, NGTCP2_LOG_EVENT_PKT,
  740. "cancel tx pkn=%" PRId64 " type=%s", hd->pkt_num,
  741. strpkttype(hd));
  742. }