lsquic_ev_log.c revision 9626cfc2
110c492f0SDmitri Tikhonov/* Copyright (c) 2017 - 2018 LiteSpeed Technologies Inc.  See LICENSE. */
2461e84d8SAmol Deshpande#ifndef WIN32
350aadb33SDmitri Tikhonov#include <arpa/inet.h>
4461e84d8SAmol Deshpande#else
5461e84d8SAmol Deshpande#include <vc_compat.h>
6461e84d8SAmol Deshpande#endif
750aadb33SDmitri Tikhonov#include <errno.h>
850aadb33SDmitri Tikhonov#include <inttypes.h>
950aadb33SDmitri Tikhonov#include <stdlib.h>
1050aadb33SDmitri Tikhonov#include <string.h>
11461e84d8SAmol Deshpande#include <sys/queue.h>
1250aadb33SDmitri Tikhonov
1350aadb33SDmitri Tikhonov#include "lsquic.h"
1450aadb33SDmitri Tikhonov#include "lsquic_types.h"
1550aadb33SDmitri Tikhonov#include "lsquic_int_types.h"
1650aadb33SDmitri Tikhonov#include "lsquic_packet_common.h"
1750aadb33SDmitri Tikhonov#include "lsquic_packet_in.h"
1850aadb33SDmitri Tikhonov#include "lsquic_packet_out.h"
1950aadb33SDmitri Tikhonov#include "lsquic_parse.h"
2050aadb33SDmitri Tikhonov#include "lsquic_frame_common.h"
2150aadb33SDmitri Tikhonov#include "lsquic_frame_reader.h"
229626cfc2SDmitri Tikhonov#include "lsquic_str.h"
239626cfc2SDmitri Tikhonov#include "lsquic_handshake.h"
2450aadb33SDmitri Tikhonov#include "lsquic_ev_log.h"
2550aadb33SDmitri Tikhonov
2650aadb33SDmitri Tikhonov#define LSQUIC_LOGGER_MODULE LSQLM_EVENT
2750aadb33SDmitri Tikhonov#include "lsquic_logger.h"
2850aadb33SDmitri Tikhonov
2950aadb33SDmitri Tikhonov
3050aadb33SDmitri Tikhonov/*  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^  */
3150aadb33SDmitri Tikhonov/*  ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||  */
3250aadb33SDmitri Tikhonov/* Messages that do not include connection ID go above this point */
3350aadb33SDmitri Tikhonov
3450aadb33SDmitri Tikhonov#define LSQUIC_LOG_CONN_ID cid
35461e84d8SAmol Deshpande#define LCID(...) LSQ_LOG2(LSQ_LOG_DEBUG, __VA_ARGS__)   /* LCID: log with CID */
3650aadb33SDmitri Tikhonov
3750aadb33SDmitri Tikhonov/* Messages that are to include connection ID go below this point */
3850aadb33SDmitri Tikhonov/*  ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||  */
3950aadb33SDmitri Tikhonov/*  VVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVV  */
4050aadb33SDmitri Tikhonov
4150aadb33SDmitri Tikhonovvoid
4250aadb33SDmitri Tikhonovlsquic_ev_log_packet_in (lsquic_cid_t cid, const lsquic_packet_in_t *packet_in)
4350aadb33SDmitri Tikhonov{
449626cfc2SDmitri Tikhonov    switch (packet_in->pi_flags & (
459626cfc2SDmitri Tikhonov                                                PI_GQUIC))
469626cfc2SDmitri Tikhonov    {
479626cfc2SDmitri Tikhonov    case PI_GQUIC:
489626cfc2SDmitri Tikhonov        LCID("packet in: %"PRIu64, packet_in->pi_packno);
499626cfc2SDmitri Tikhonov        break;
509626cfc2SDmitri Tikhonov    default:
519626cfc2SDmitri Tikhonov        LCID("packet in: %"PRIu64", type: %s",
529626cfc2SDmitri Tikhonov            packet_in->pi_packno, lsquic_hety2str[packet_in->pi_header_type]);
539626cfc2SDmitri Tikhonov        break;
549626cfc2SDmitri Tikhonov    }
5550aadb33SDmitri Tikhonov}
5650aadb33SDmitri Tikhonov
5750aadb33SDmitri Tikhonov
5850aadb33SDmitri Tikhonovvoid
5950aadb33SDmitri Tikhonovlsquic_ev_log_ack_frame_in (lsquic_cid_t cid, const struct ack_info *acki)
6050aadb33SDmitri Tikhonov{
6150aadb33SDmitri Tikhonov    size_t sz;
6250aadb33SDmitri Tikhonov    char *buf;
6350aadb33SDmitri Tikhonov
6450aadb33SDmitri Tikhonov    if ((buf = acki2str(acki, &sz)))
6550aadb33SDmitri Tikhonov    {
6650aadb33SDmitri Tikhonov        LCID("ACK frame in: %.*s", (int) sz, buf);
6750aadb33SDmitri Tikhonov        free(buf);
6850aadb33SDmitri Tikhonov    }
6950aadb33SDmitri Tikhonov}
7050aadb33SDmitri Tikhonov
7150aadb33SDmitri Tikhonov
7250aadb33SDmitri Tikhonovvoid
7350aadb33SDmitri Tikhonovlsquic_ev_log_stream_frame_in (lsquic_cid_t cid,
7450aadb33SDmitri Tikhonov                                        const struct stream_frame *frame)
7550aadb33SDmitri Tikhonov{
7650aadb33SDmitri Tikhonov    LCID("STREAM frame in: stream %u; offset %"PRIu64"; size %"PRIu16
7750aadb33SDmitri Tikhonov        "; fin: %d", frame->stream_id, frame->data_frame.df_offset,
7850aadb33SDmitri Tikhonov        frame->data_frame.df_size, (int) frame->data_frame.df_fin);
7950aadb33SDmitri Tikhonov}
8050aadb33SDmitri Tikhonov
8150aadb33SDmitri Tikhonov
8250aadb33SDmitri Tikhonovvoid
8350aadb33SDmitri Tikhonovlsquic_ev_log_stop_waiting_frame_in (lsquic_cid_t cid, lsquic_packno_t least)
8450aadb33SDmitri Tikhonov{
8550aadb33SDmitri Tikhonov    LCID("STOP_WAITING frame in: least unacked packno %"PRIu64, least);
8650aadb33SDmitri Tikhonov}
8750aadb33SDmitri Tikhonov
8850aadb33SDmitri Tikhonov
8950aadb33SDmitri Tikhonovvoid
9050aadb33SDmitri Tikhonovlsquic_ev_log_window_update_frame_in (lsquic_cid_t cid, uint32_t stream_id,
9150aadb33SDmitri Tikhonov                                                            uint64_t offset)
9250aadb33SDmitri Tikhonov{
9350aadb33SDmitri Tikhonov    LCID("WINDOW_UPDATE frame in: stream %"PRIu32"; offset %"PRIu64,
9450aadb33SDmitri Tikhonov        stream_id, offset);
9550aadb33SDmitri Tikhonov}
9650aadb33SDmitri Tikhonov
9750aadb33SDmitri Tikhonov
9850aadb33SDmitri Tikhonovvoid
9950aadb33SDmitri Tikhonovlsquic_ev_log_blocked_frame_in (lsquic_cid_t cid, uint32_t stream_id)
10050aadb33SDmitri Tikhonov{
10150aadb33SDmitri Tikhonov    LCID("BLOCKED frame in: stream %"PRIu32, stream_id);
10250aadb33SDmitri Tikhonov}
10350aadb33SDmitri Tikhonov
10450aadb33SDmitri Tikhonov
10550aadb33SDmitri Tikhonovvoid
10650aadb33SDmitri Tikhonovlsquic_ev_log_connection_close_frame_in (lsquic_cid_t cid,
10750aadb33SDmitri Tikhonov                    uint32_t error_code, int reason_len, const char *reason)
10850aadb33SDmitri Tikhonov{
10950aadb33SDmitri Tikhonov    LCID("CONNECTION_CLOSE frame in: error code %"PRIu32", reason: %.*s",
11050aadb33SDmitri Tikhonov        error_code, reason_len, reason);
11150aadb33SDmitri Tikhonov}
11250aadb33SDmitri Tikhonov
11350aadb33SDmitri Tikhonov
11450aadb33SDmitri Tikhonovvoid
11550aadb33SDmitri Tikhonovlsquic_ev_log_goaway_frame_in (lsquic_cid_t cid, uint32_t error_code,
11650aadb33SDmitri Tikhonov                    uint32_t stream_id, int reason_len, const char *reason)
11750aadb33SDmitri Tikhonov{
11850aadb33SDmitri Tikhonov    LCID("GOAWAY frame in: error code %"PRIu32", stream %"PRIu32
11950aadb33SDmitri Tikhonov        ", reason: %.*s", error_code, stream_id, reason_len, reason);
12050aadb33SDmitri Tikhonov}
12150aadb33SDmitri Tikhonov
12250aadb33SDmitri Tikhonov
12350aadb33SDmitri Tikhonovvoid
12450aadb33SDmitri Tikhonovlsquic_ev_log_rst_stream_frame_in (lsquic_cid_t cid, uint32_t stream_id,
12550aadb33SDmitri Tikhonov                                        uint64_t offset, uint32_t error_code)
12650aadb33SDmitri Tikhonov{
12750aadb33SDmitri Tikhonov    LCID("RST_FRAME frame in: error code %"PRIu32", stream %"PRIu32
12850aadb33SDmitri Tikhonov        ", offset: %"PRIu64, error_code, stream_id, offset);
12950aadb33SDmitri Tikhonov}
13050aadb33SDmitri Tikhonov
13150aadb33SDmitri Tikhonov
13250aadb33SDmitri Tikhonovvoid
13350aadb33SDmitri Tikhonovlsquic_ev_log_padding_frame_in (lsquic_cid_t cid, size_t len)
13450aadb33SDmitri Tikhonov{
13550aadb33SDmitri Tikhonov    LCID("PADDING frame in of %zd bytes", len);
13650aadb33SDmitri Tikhonov}
13750aadb33SDmitri Tikhonov
13850aadb33SDmitri Tikhonov
13950aadb33SDmitri Tikhonovvoid
14050aadb33SDmitri Tikhonovlsquic_ev_log_ping_frame_in (lsquic_cid_t cid)
14150aadb33SDmitri Tikhonov{
14250aadb33SDmitri Tikhonov    LCID("PING frame in");
14350aadb33SDmitri Tikhonov}
14450aadb33SDmitri Tikhonov
14550aadb33SDmitri Tikhonov
14650aadb33SDmitri Tikhonovvoid
14750aadb33SDmitri Tikhonovlsquic_ev_log_packet_created (lsquic_cid_t cid,
14850aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
14950aadb33SDmitri Tikhonov{
15050aadb33SDmitri Tikhonov    LCID("created packet %"PRIu64"; flags: version=%d, nonce=%d, conn_id=%d",
15150aadb33SDmitri Tikhonov        packet_out->po_packno,
15250aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_VERSION),
15350aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_NONCE),
15450aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_CONN_ID));
15550aadb33SDmitri Tikhonov}
15650aadb33SDmitri Tikhonov
15750aadb33SDmitri Tikhonov
15850aadb33SDmitri Tikhonovvoid
15950aadb33SDmitri Tikhonovlsquic_ev_log_packet_sent (lsquic_cid_t cid,
16050aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
16150aadb33SDmitri Tikhonov{
16250aadb33SDmitri Tikhonov    char frames[lsquic_frame_types_str_sz];
16350aadb33SDmitri Tikhonov    if (lsquic_packet_out_verneg(packet_out))
16450aadb33SDmitri Tikhonov        LCID("sent version negotiation packet, size %hu",
16550aadb33SDmitri Tikhonov                                                    packet_out->po_data_sz);
16650aadb33SDmitri Tikhonov    else if (lsquic_packet_out_pubres(packet_out))
16750aadb33SDmitri Tikhonov        LCID("sent public reset packet, size %hu", packet_out->po_data_sz);
1689626cfc2SDmitri Tikhonov    else if (packet_out->po_flags & PO_GQUIC)
16950aadb33SDmitri Tikhonov        LCID("sent packet %"PRIu64", size %hu, frame types: %s",
17050aadb33SDmitri Tikhonov            packet_out->po_packno, packet_out->po_enc_data_sz,
17150aadb33SDmitri Tikhonov                /* Frame types is a list of different frames types contained
17250aadb33SDmitri Tikhonov                 * in the packet, no more.  Count and order of frames is not
17350aadb33SDmitri Tikhonov                 * printed.
17450aadb33SDmitri Tikhonov                 */
17550aadb33SDmitri Tikhonov                lsquic_frame_types_to_str(frames, sizeof(frames),
17650aadb33SDmitri Tikhonov                                                packet_out->po_frame_types));
1779626cfc2SDmitri Tikhonov    else
1789626cfc2SDmitri Tikhonov        LCID("sent packet %"PRIu64", type %s, crypto: %s, size %hu, frame "
1799626cfc2SDmitri Tikhonov            "types: %s",
1809626cfc2SDmitri Tikhonov            packet_out->po_packno, lsquic_hety2str[packet_out->po_header_type],
1819626cfc2SDmitri Tikhonov            lsquic_enclev2str[ lsquic_packet_out_enc_level(packet_out) ],
1829626cfc2SDmitri Tikhonov            packet_out->po_enc_data_sz,
1839626cfc2SDmitri Tikhonov                /* Frame types is a list of different frames types contained
1849626cfc2SDmitri Tikhonov                 * in the packet, no more.  Count and order of frames is not
1859626cfc2SDmitri Tikhonov                 * printed.
1869626cfc2SDmitri Tikhonov                 */
1879626cfc2SDmitri Tikhonov                lsquic_frame_types_to_str(frames, sizeof(frames),
1889626cfc2SDmitri Tikhonov                                                packet_out->po_frame_types));
18950aadb33SDmitri Tikhonov}
19050aadb33SDmitri Tikhonov
19150aadb33SDmitri Tikhonov
19250aadb33SDmitri Tikhonovvoid
19350aadb33SDmitri Tikhonovlsquic_ev_log_packet_not_sent (lsquic_cid_t cid,
19450aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
19550aadb33SDmitri Tikhonov{
19650aadb33SDmitri Tikhonov    char frames[lsquic_frame_types_str_sz];
19750aadb33SDmitri Tikhonov    LCID("unsent packet %"PRIu64", size %hu, frame types: %s",
19850aadb33SDmitri Tikhonov        packet_out->po_packno, packet_out->po_enc_data_sz,
19950aadb33SDmitri Tikhonov            /* Frame types is a list of different frames types contained in
20050aadb33SDmitri Tikhonov             * the packet, no more.  Count and order of frames is not printed.
20150aadb33SDmitri Tikhonov             */
20250aadb33SDmitri Tikhonov            lsquic_frame_types_to_str(frames, sizeof(frames),
20350aadb33SDmitri Tikhonov                                                packet_out->po_frame_types));
20450aadb33SDmitri Tikhonov}
20550aadb33SDmitri Tikhonov
20650aadb33SDmitri Tikhonov
20750aadb33SDmitri Tikhonovvoid
20850aadb33SDmitri Tikhonovlsquic_ev_log_http_headers_in (lsquic_cid_t cid, int is_server,
20950aadb33SDmitri Tikhonov                                        const struct uncompressed_headers *uh)
21050aadb33SDmitri Tikhonov{
21150aadb33SDmitri Tikhonov    const char *cr, *p;
21250aadb33SDmitri Tikhonov
21350aadb33SDmitri Tikhonov    if (uh->uh_flags & UH_PP)
21450aadb33SDmitri Tikhonov        LCID("read push promise; stream %"PRIu32", promised stream %"PRIu32,
21550aadb33SDmitri Tikhonov            uh->uh_stream_id, uh->uh_oth_stream_id);
21650aadb33SDmitri Tikhonov    else
21750aadb33SDmitri Tikhonov        LCID("read %s headers; stream: %"PRIu32", depends on stream: %"PRIu32
21850aadb33SDmitri Tikhonov            ", weight: %hu, exclusive: %d, fin: %d",
21950aadb33SDmitri Tikhonov            is_server ? "request" : "response",
22050aadb33SDmitri Tikhonov            uh->uh_stream_id, uh->uh_oth_stream_id, uh->uh_weight,
22150aadb33SDmitri Tikhonov            (int) uh->uh_exclusive, !!(uh->uh_flags & UH_FIN));
22250aadb33SDmitri Tikhonov
22350aadb33SDmitri Tikhonov    for (p = uh->uh_headers; p < uh->uh_headers + uh->uh_size; p = cr + 2)
22450aadb33SDmitri Tikhonov    {
22550aadb33SDmitri Tikhonov        cr = strchr(p, '\r');
22650aadb33SDmitri Tikhonov        if (cr && cr > p)
22750aadb33SDmitri Tikhonov            LCID("  %.*s", (int) (cr - p), p);
22850aadb33SDmitri Tikhonov        else
22950aadb33SDmitri Tikhonov            break;
23050aadb33SDmitri Tikhonov    }
23150aadb33SDmitri Tikhonov}
23250aadb33SDmitri Tikhonov
23350aadb33SDmitri Tikhonov
23450aadb33SDmitri Tikhonovvoid
235c51ce338SDmitri Tikhonovlsquic_ev_log_action_stream_frame (lsquic_cid_t cid,
236c51ce338SDmitri Tikhonov    const struct parse_funcs *pf, const unsigned char *buf, size_t bufsz,
237c51ce338SDmitri Tikhonov    const char *what)
23850aadb33SDmitri Tikhonov{
23950aadb33SDmitri Tikhonov    struct stream_frame frame;
24050aadb33SDmitri Tikhonov    int len;
24150aadb33SDmitri Tikhonov
24250aadb33SDmitri Tikhonov    len = pf->pf_parse_stream_frame(buf, bufsz, &frame);
24350aadb33SDmitri Tikhonov    if (len > 0)
244c51ce338SDmitri Tikhonov        LCID("%s STREAM frame: stream %"PRIu32", offset: %"PRIu64
245c51ce338SDmitri Tikhonov            ", size: %"PRIu16", fin: %d", what, frame.stream_id,
24650aadb33SDmitri Tikhonov            frame.data_frame.df_offset, frame.data_frame.df_size,
24750aadb33SDmitri Tikhonov            frame.data_frame.df_fin);
24850aadb33SDmitri Tikhonov    else
24950aadb33SDmitri Tikhonov        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse STREAM frame");
25050aadb33SDmitri Tikhonov}
25150aadb33SDmitri Tikhonov
25250aadb33SDmitri Tikhonov
25350aadb33SDmitri Tikhonovvoid
25450aadb33SDmitri Tikhonovlsquic_ev_log_generated_ack_frame (lsquic_cid_t cid, const struct parse_funcs *pf,
25550aadb33SDmitri Tikhonov                                   const unsigned char *ack_buf, size_t ack_buf_sz)
25650aadb33SDmitri Tikhonov{
25750aadb33SDmitri Tikhonov    struct ack_info acki;
25850aadb33SDmitri Tikhonov    size_t sz;
25950aadb33SDmitri Tikhonov    char *buf;
26050aadb33SDmitri Tikhonov    int len;
26150aadb33SDmitri Tikhonov
26250aadb33SDmitri Tikhonov    len = pf->pf_parse_ack_frame(ack_buf, ack_buf_sz, &acki);
26350aadb33SDmitri Tikhonov    if (len < 0)
26450aadb33SDmitri Tikhonov    {
26550aadb33SDmitri Tikhonov        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse ACK frame");
26650aadb33SDmitri Tikhonov        return;
26750aadb33SDmitri Tikhonov    }
26850aadb33SDmitri Tikhonov
26950aadb33SDmitri Tikhonov    if ((buf = acki2str(&acki, &sz)))
27050aadb33SDmitri Tikhonov    {
27150aadb33SDmitri Tikhonov        LCID("generated ACK frame: %.*s", (int) sz, buf);
27250aadb33SDmitri Tikhonov        free(buf);
27350aadb33SDmitri Tikhonov    }
27450aadb33SDmitri Tikhonov}
27550aadb33SDmitri Tikhonov
27650aadb33SDmitri Tikhonov
27750aadb33SDmitri Tikhonovvoid
27850aadb33SDmitri Tikhonovlsquic_ev_log_generated_stop_waiting_frame (lsquic_cid_t cid,
27950aadb33SDmitri Tikhonov                                            lsquic_packno_t lunack)
28050aadb33SDmitri Tikhonov{
28150aadb33SDmitri Tikhonov    LCID("generated STOP_WAITING frame; least unacked: %"PRIu64, lunack);
28250aadb33SDmitri Tikhonov}
28350aadb33SDmitri Tikhonov
28450aadb33SDmitri Tikhonov
28550aadb33SDmitri Tikhonovvoid
28650aadb33SDmitri Tikhonovlsquic_ev_log_generated_http_headers (lsquic_cid_t cid, uint32_t stream_id,
28750aadb33SDmitri Tikhonov                    int is_server, const struct http_prio_frame *prio_frame,
28850aadb33SDmitri Tikhonov                    const struct lsquic_http_headers *headers)
28950aadb33SDmitri Tikhonov{
29050aadb33SDmitri Tikhonov    uint32_t dep_stream_id;
29150aadb33SDmitri Tikhonov    int exclusive, i;
29250aadb33SDmitri Tikhonov    unsigned short weight;
29350aadb33SDmitri Tikhonov
29450aadb33SDmitri Tikhonov    if (is_server)
29550aadb33SDmitri Tikhonov        LCID("generated HTTP response HEADERS for stream %"PRIu32, stream_id);
29650aadb33SDmitri Tikhonov    else
29750aadb33SDmitri Tikhonov    {
29850aadb33SDmitri Tikhonov        memcpy(&dep_stream_id, prio_frame->hpf_stream_id, 4);
29950aadb33SDmitri Tikhonov        dep_stream_id = htonl(dep_stream_id);
30050aadb33SDmitri Tikhonov        exclusive = dep_stream_id >> 31;
30150aadb33SDmitri Tikhonov        dep_stream_id &= ~(1 << 31);
30250aadb33SDmitri Tikhonov        weight = prio_frame->hpf_weight + 1;
30350aadb33SDmitri Tikhonov        LCID("generated HTTP request HEADERS for stream %"PRIu32
30450aadb33SDmitri Tikhonov            ", dep stream: %"PRIu32", weight: %hu, exclusive: %d", stream_id,
30550aadb33SDmitri Tikhonov            dep_stream_id, weight, exclusive);
30650aadb33SDmitri Tikhonov    }
30750aadb33SDmitri Tikhonov
30850aadb33SDmitri Tikhonov    for (i = 0; i < headers->count; ++i)
30950aadb33SDmitri Tikhonov        LCID("  %.*s: %.*s",
31050aadb33SDmitri Tikhonov            (int)    headers->headers[i].name.iov_len,
31150aadb33SDmitri Tikhonov            (char *) headers->headers[i].name.iov_base,
31250aadb33SDmitri Tikhonov            (int)    headers->headers[i].value.iov_len,
31350aadb33SDmitri Tikhonov            (char *) headers->headers[i].value.iov_base);
31450aadb33SDmitri Tikhonov}
31550aadb33SDmitri Tikhonov
31650aadb33SDmitri Tikhonov
31750aadb33SDmitri Tikhonovvoid
31850aadb33SDmitri Tikhonovlsquic_ev_log_generated_http_push_promise (lsquic_cid_t cid,
31950aadb33SDmitri Tikhonov                            uint32_t stream_id, uint32_t promised_stream_id,
32050aadb33SDmitri Tikhonov                            const struct lsquic_http_headers *headers,
32150aadb33SDmitri Tikhonov                            const struct lsquic_http_headers *extra_headers)
32250aadb33SDmitri Tikhonov{
32350aadb33SDmitri Tikhonov    int i;
32450aadb33SDmitri Tikhonov
32550aadb33SDmitri Tikhonov    LCID("generated HTTP PUSH_PROMISE for stream %"PRIu32"; promised stream %"
32650aadb33SDmitri Tikhonov        PRIu32, stream_id, promised_stream_id);
32750aadb33SDmitri Tikhonov
32850aadb33SDmitri Tikhonov    for (i = 0; i < headers->count; ++i)
32950aadb33SDmitri Tikhonov        LCID("  %.*s: %.*s",
33050aadb33SDmitri Tikhonov            (int)    headers->headers[i].name.iov_len,
33150aadb33SDmitri Tikhonov            (char *) headers->headers[i].name.iov_base,
33250aadb33SDmitri Tikhonov            (int)    headers->headers[i].value.iov_len,
33350aadb33SDmitri Tikhonov            (char *) headers->headers[i].value.iov_base);
33450aadb33SDmitri Tikhonov
33550aadb33SDmitri Tikhonov    if (extra_headers)
33650aadb33SDmitri Tikhonov        for (i = 0; i < extra_headers->count; ++i)
33750aadb33SDmitri Tikhonov            LCID("  %.*s: %.*s",
33850aadb33SDmitri Tikhonov                (int)    extra_headers->headers[i].name.iov_len,
33950aadb33SDmitri Tikhonov                (char *) extra_headers->headers[i].name.iov_base,
34050aadb33SDmitri Tikhonov                (int)    extra_headers->headers[i].value.iov_len,
34150aadb33SDmitri Tikhonov                (char *) extra_headers->headers[i].value.iov_base);
34250aadb33SDmitri Tikhonov}
343