diff --git a/src/quic/node_quic.cc b/src/quic/node_quic.cc index 9f9b4cbf66..b176e10342 100644 --- a/src/quic/node_quic.cc +++ b/src/quic/node_quic.cc @@ -193,17 +193,17 @@ void Initialize(Local target, V(QUICSTREAM_HEADERS_KIND_TRAILING) \ V(UV_EBADF) -#define V(name, _) \ +#define V(name, _, __) \ NODE_DEFINE_CONSTANT(constants, IDX_QUIC_SESSION_STATS_##name); SESSION_STATS(V) #undef V -#define V(name, _) \ +#define V(name, _, __) \ NODE_DEFINE_CONSTANT(constants, IDX_QUIC_SOCKET_STATS_##name); SOCKET_STATS(V) #undef V -#define V(name, _) \ +#define V(name, _, __) \ NODE_DEFINE_CONSTANT(constants, IDX_QUIC_STREAM_STATS_##name); STREAM_STATS(V) #undef V diff --git a/src/quic/node_quic_session.cc b/src/quic/node_quic_session.cc index 13c35a9703..b0f5598ff4 100644 --- a/src/quic/node_quic_session.cc +++ b/src/quic/node_quic_session.cc @@ -1351,34 +1351,10 @@ QuicSession::QuicSession( QuicSession::~QuicSession() { CHECK(!Ngtcp2CallbackScope::InNgtcp2CallbackScope(this)); + StatsDebug stats_debug(this); + Debug(this, "Destroyed. %s", stats_debug.ToString().c_str()); - uint64_t handshake_length = crypto_context_->Cancel(); - - Debug(this, - "Destroyed.\n" - " Duration: %" PRIu64 "\n" - " Handshake Started: %" PRIu64 "\n" - " Handshake Completed: %" PRIu64 "\n" - " Bytes Received: %" PRIu64 "\n" - " Bytes Sent: %" PRIu64 "\n" - " Bidi Stream Count: %" PRIu64 "\n" - " Uni Stream Count: %" PRIu64 "\n" - " Streams In Count: %" PRIu64 "\n" - " Streams Out Count: %" PRIu64 "\n" - " Remaining handshake_: %" PRIu64 "\n" - " Max In Flight Bytes: %" PRIu64 "\n", - uv_hrtime() - GetStat(&QuicSessionStats::created_at), - GetStat(&QuicSessionStats::handshake_start_at), - GetStat(&QuicSessionStats::handshake_completed_at), - GetStat(&QuicSessionStats::bytes_received), - GetStat(&QuicSessionStats::bytes_sent), - GetStat(&QuicSessionStats::bidi_stream_count), - GetStat(&QuicSessionStats::uni_stream_count), - GetStat(&QuicSessionStats::streams_in_count), - GetStat(&QuicSessionStats::streams_out_count), - handshake_length, - GetStat(&QuicSessionStats::max_bytes_in_flight)); - + crypto_context_->Cancel(); connection_.reset(); QuicSessionListener* listener_ = listener(); @@ -1387,6 +1363,21 @@ QuicSession::~QuicSession() { RemoveListener(listener_); } +std::string QuicSession::StatsDebug::ToString() { +#define V(_, name, label) \ + " "## label + ": " + \ + std::to_string(session_->GetStat(&QuicSessionStats::name)) + "\n" + + std::string out = "Statistics:\n"; + out += " Duration: " + + std::to_string(uv_hrtime() - + session_->GetStat(&QuicSessionStats::created_at)) + "\n" + + SESSION_STATS(V); + return out; + +#undef V +} + void QuicSession::PushListener(QuicSessionListener* listener) { CHECK_NOT_NULL(listener); CHECK(!listener->session_); @@ -2387,8 +2378,12 @@ void QuicSession::StreamReset( app_error_code, final_size); - if (HasStream(stream_id)) + BaseObjectPtr stream = FindStream(stream_id); + + if (stream) { + stream->set_final_size(final_size); application_->StreamReset(stream_id, final_size, app_error_code); + } } void QuicSession::UpdateConnectionID( diff --git a/src/quic/node_quic_session.h b/src/quic/node_quic_session.h index 3d484aeabf..6be9847263 100644 --- a/src/quic/node_quic_session.h +++ b/src/quic/node_quic_session.h @@ -188,41 +188,47 @@ enum QuicSessionState : int { }; #define SESSION_STATS(V) \ - V(CREATED_AT, created_at) \ - V(HANDSHAKE_START_AT, handshake_start_at) \ - V(HANDSHAKE_SEND_AT, handshake_send_at) \ - V(HANDSHAKE_CONTINUE_AT, handshake_continue_at) \ - V(HANDSHAKE_COMPLETED_AT, handshake_completed_at) \ - V(HANDSHAKE_ACKED_AT, handshake_acked_at) \ - V(SENT_AT, sent_at) \ - V(RECEIVED_AT, received_at) \ - V(CLOSING_AT, closing_at) \ - V(BYTES_RECEIVED, bytes_received) \ - V(BYTES_SENT, bytes_sent) \ - V(BIDI_STREAM_COUNT, bidi_stream_count) \ - V(UNI_STREAM_COUNT, uni_stream_count) \ - V(STREAMS_IN_COUNT, streams_in_count) \ - V(STREAMS_OUT_COUNT, streams_out_count) \ - V(KEYUPDATE_COUNT, keyupdate_count) \ - V(RETRY_COUNT, retry_count) \ - V(LOSS_RETRANSMIT_COUNT, loss_retransmit_count) \ - V(ACK_DELAY_RETRANSMIT_COUNT, ack_delay_retransmit_count) \ - V(PATH_VALIDATION_SUCCESS_COUNT, path_validation_success_count) \ - V(PATH_VALIDATION_FAILURE_COUNT, path_validation_failure_count) \ - V(MAX_BYTES_IN_FLIGHT, max_bytes_in_flight) \ - V(BLOCK_COUNT, block_count) \ - V(MIN_RTT, min_rtt) \ - V(LATEST_RTT, latest_rtt) \ - V(SMOOTHED_RTT, smoothed_rtt) - -#define V(name, _) IDX_QUIC_SESSION_STATS_##name, + V(CREATED_AT, created_at, "Created At") \ + V(HANDSHAKE_START_AT, handshake_start_at, "Handshake Started") \ + V(HANDSHAKE_SEND_AT, handshake_send_at, "Handshke Last Sent") \ + V(HANDSHAKE_CONTINUE_AT, handshake_continue_at, "Handshke Continued") \ + V(HANDSHAKE_COMPLETED_AT, handshake_completed_at, "Handshake Completed") \ + V(HANDSHAKE_ACKED_AT, handshake_acked_at, "Handshake Last Acknowledged") \ + V(SENT_AT, sent_at, "Last Sent At") \ + V(RECEIVED_AT, received_at, "Last Received At") \ + V(CLOSING_AT, closing_at, "Closing") \ + V(BYTES_RECEIVED, bytes_received, "Bytes Received") \ + V(BYTES_SENT, bytes_sent, "Bytes Sent") \ + V(BIDI_STREAM_COUNT, bidi_stream_count, "Bidi Stream Count") \ + V(UNI_STREAM_COUNT, uni_stream_count, "Uni Stream Count") \ + V(STREAMS_IN_COUNT, streams_in_count, "Streams In Count") \ + V(STREAMS_OUT_COUNT, streams_out_count, "Streams Out Count") \ + V(KEYUPDATE_COUNT, keyupdate_count, "Key Update Count") \ + V(RETRY_COUNT, retry_count, "Retry Count") \ + V(LOSS_RETRANSMIT_COUNT, loss_retransmit_count, "Loss Retransmit Count") \ + V(ACK_DELAY_RETRANSMIT_COUNT, \ + ack_delay_retransmit_count, \ + "Ack Delay Retransmit Count") \ + V(PATH_VALIDATION_SUCCESS_COUNT, \ + path_validation_success_count, \ + "Path Validation Success Count") \ + V(PATH_VALIDATION_FAILURE_COUNT, \ + path_validation_failure_count, \ + "Path Validation Failure Count") \ + V(MAX_BYTES_IN_FLIGHT, max_bytes_in_flight, "Max Bytes In Flight") \ + V(BLOCK_COUNT, block_count, "Block Count") \ + V(MIN_RTT, min_rtt, "Minimum RTT") \ + V(LATEST_RTT, latest_rtt, "Latest RTT") \ + V(SMOOTHED_RTT, smoothed_rtt, "Smoothed RTT") + +#define V(name, _, __) IDX_QUIC_SESSION_STATS_##name, enum QuicSessionStatsIdx : int { SESSION_STATS(V) IDX_QUIC_SESSION_STATS_COUNT }; #undef V -#define V(_, name) uint64_t name; +#define V(_, name, __) uint64_t name; struct QuicSessionStats { SESSION_STATS(V) }; @@ -1420,6 +1426,15 @@ class QuicSession : public AsyncWrap, static const ngtcp2_conn_callbacks callbacks[2]; + class StatsDebug { + public: + StatsDebug(QuicSession* session) : session_(session) {} + std::string ToString(); + private: + QuicSession* session_; + }; + + friend class QuicCryptoContext; friend class QuicSessionListener; friend class JSQuicSessionListener; diff --git a/src/quic/node_quic_socket.cc b/src/quic/node_quic_socket.cc index 69b3c6e02c..ae20d31c01 100644 --- a/src/quic/node_quic_socket.cc +++ b/src/quic/node_quic_socket.cc @@ -285,37 +285,29 @@ QuicSocket::QuicSocket( QuicSocket::~QuicSocket() { uint64_t now = uv_hrtime(); - Debug(this, - "QuicSocket destroyed.\n" - " Duration: %" PRIu64 "\n" - " Bound Duration: %" PRIu64 "\n" - " Listen Duration: %" PRIu64 "\n" - " Bytes Received: %" PRIu64 "\n" - " Bytes Sent: %" PRIu64 "\n" - " Packets Received: %" PRIu64 "\n" - " Packets Sent: %" PRIu64 "\n" - " Packets Ignored: %" PRIu64 "\n" - " Server Sessions: %" PRIu64 "\n" - " Client Sessions: %" PRIu64 "\n" - " Stateless Resets: %" PRIu64 "\n", - now - GetStat(&QuicSocketStats::created_at), - now - GetStat(&QuicSocketStats::bound_at), - now - GetStat(&QuicSocketStats::listen_at), - GetStat(&QuicSocketStats::bytes_received), - GetStat(&QuicSocketStats::bytes_sent), - GetStat(&QuicSocketStats::packets_received), - GetStat(&QuicSocketStats::packets_sent), - GetStat(&QuicSocketStats::packets_ignored), - GetStat(&QuicSocketStats::server_sessions), - GetStat(&QuicSocketStats::client_sessions), - GetStat(&QuicSocketStats::stateless_reset_count)); + StatsDebug stats_debug(this); + Debug(this, "Destroyed. %s", stats_debug.ToString().c_str()); QuicSocketListener* listener = listener_; listener_->OnDestroy(); - // Remove the listener if it didn't remove itself already. if (listener == listener_) RemoveListener(listener_); } +std::string QuicSocket::StatsDebug::ToString() { +#define V(_, name, label) \ + " "## label + ": " + \ + std::to_string(socket_->GetStat(&QuicSocketStats::name)) + "\n" + + std::string out = "Statistics:\n"; + out += " Duration: " + + std::to_string(uv_hrtime() - + socket_->GetStat(&QuicSocketStats::created_at)) + "\n" + + SOCKET_STATS(V); + return out; + +#undef V +} + void QuicSocket::MemoryInfo(MemoryTracker* tracker) const { tracker->TrackField("endpoints", endpoints_); tracker->TrackField("sessions", sessions_); diff --git a/src/quic/node_quic_socket.h b/src/quic/node_quic_socket.h index 38956b3f4f..9720030db6 100644 --- a/src/quic/node_quic_socket.h +++ b/src/quic/node_quic_socket.h @@ -44,27 +44,27 @@ enum QuicSocketOptions : uint32_t { }; #define SOCKET_STATS(V) \ - V(CREATED_AT, created_at) \ - V(BOUND_AT, bound_at) \ - V(LISTEN_AT, listen_at) \ - V(BYTES_RECEIVED, bytes_received) \ - V(BYTES_SENT, bytes_sent) \ - V(PACKETS_RECEIVED, packets_received) \ - V(PACKETS_IGNORED, packets_ignored) \ - V(PACKETS_SENT, packets_sent) \ - V(SERVER_SESSIONS, server_sessions) \ - V(CLIENT_SESSIONS, client_sessions) \ - V(STATELESS_RESET_COUNT, stateless_reset_count) \ - V(SERVER_BUSY_COUNT, server_busy_count) - -#define V(name, _) IDX_QUIC_SOCKET_STATS_##name, + V(CREATED_AT, created_at, "Created At") \ + V(BOUND_AT, bound_at, "Bound At") \ + V(LISTEN_AT, listen_at, "Listen At") \ + V(BYTES_RECEIVED, bytes_received, "Bytes Received") \ + V(BYTES_SENT, bytes_sent, "Bytes Sent") \ + V(PACKETS_RECEIVED, packets_received, "Packets Received") \ + V(PACKETS_IGNORED, packets_ignored, "Packets Ignored") \ + V(PACKETS_SENT, packets_sent, "Packets Sent") \ + V(SERVER_SESSIONS, server_sessions, "Server Sessions") \ + V(CLIENT_SESSIONS, client_sessions, "Client Sessions") \ + V(STATELESS_RESET_COUNT, stateless_reset_count, "Stateless Reset Count") \ + V(SERVER_BUSY_COUNT, server_busy_count, "Server Busy Count") + +#define V(name, _, __) IDX_QUIC_SOCKET_STATS_##name, enum QuicSocketStatsIdx : int { SOCKET_STATS(V) IDX_QUIC_SOCKET_STATS_COUNT }; #undef V -#define V(_, name) uint64_t name; +#define V(_, name, __) uint64_t name; struct QuicSocketStats { SOCKET_STATS(V) }; @@ -531,6 +531,14 @@ class QuicSocket : public AsyncWrap, SendWrap* last_created_send_wrap_ = nullptr; + class StatsDebug { + public: + StatsDebug(QuicSocket* socket) : socket_(socket) {} + std::string ToString(); + private: + QuicSocket* socket_; + }; + friend class QuicSocketListener; }; diff --git a/src/quic/node_quic_stream-inl.h b/src/quic/node_quic_stream-inl.h index ecb904a530..4e1f15ef4f 100644 --- a/src/quic/node_quic_stream-inl.h +++ b/src/quic/node_quic_stream-inl.h @@ -23,17 +23,21 @@ QuicStreamOrigin QuicStream::origin() const { QUIC_STREAM_CLIENT; } -inline bool QuicStream::is_flag_set(int32_t flag) const { +bool QuicStream::is_flag_set(int32_t flag) const { return flags_ & (1 << flag); } -inline void QuicStream::set_flag(int32_t flag, bool on) { +void QuicStream::set_flag(int32_t flag, bool on) { if (on) flags_ |= (1 << flag); else flags_ &= ~(1 << flag); } +void QuicStream::set_final_size(uint64_t final_size) { + SetStat(&QuicStreamStats::final_size, final_size); +} + bool QuicStream::is_destroyed() const { return is_flag_set(QUICSTREAM_FLAG_DESTROYED); } diff --git a/src/quic/node_quic_stream.cc b/src/quic/node_quic_stream.cc index 245bda46f5..b05b6f37ae 100644 --- a/src/quic/node_quic_stream.cc +++ b/src/quic/node_quic_stream.cc @@ -54,6 +54,26 @@ QuicStream::QuicStream( IncrementStat(&QuicStreamStats::max_offset, params.initial_max_data); } +QuicStream::~QuicStream() { + StatsDebug stats_debug(this); + Debug(this, "Destroyed. %s", stats_debug.ToString().c_str()); +} + +std::string QuicStream::StatsDebug::ToString() { +#define V(_, name, label) \ + " "## label + ": " + \ + std::to_string(stream_->GetStat(&QuicStreamStats::name)) + "\n" + + std::string out = "Statistics:\n"; + out += " Duration: " + + std::to_string(uv_hrtime() - + stream_->GetStat(&QuicStreamStats::created_at)) + "\n" + + STREAM_STATS(V); + return out; + +#undef V +} + // Acknowledge is called when ngtcp2 has received an acknowledgement // for one or more stream frames for this QuicStream. This will cause // data stored in the streambuf_ outbound queue to be consumed and may diff --git a/src/quic/node_quic_stream.h b/src/quic/node_quic_stream.h index 30ccde47d9..7b2f3bb02c 100644 --- a/src/quic/node_quic_stream.h +++ b/src/quic/node_quic_stream.h @@ -41,22 +41,23 @@ enum QuicStreamHeadersKind : int { }; #define STREAM_STATS(V) \ - V(CREATED_AT, created_at) \ - V(RECEIVED_AT, received_at) \ - V(ACKED_AT, acked_at) \ - V(CLOSING_AT, closing_at) \ - V(BYTES_RECEIVED, bytes_received) \ - V(BYTES_SENT, bytes_sent) \ - V(MAX_OFFSET, max_offset) - -#define V(name, _) IDX_QUIC_STREAM_STATS_##name, + V(CREATED_AT, created_at, "Created At") \ + V(RECEIVED_AT, received_at, "Last Received At") \ + V(ACKED_AT, acked_at, "Last Acknowledged At") \ + V(CLOSING_AT, closing_at, "Closing At") \ + V(BYTES_RECEIVED, bytes_received, "Bytes Received") \ + V(BYTES_SENT, bytes_sent, "Bytes Sent") \ + V(MAX_OFFSET, max_offset, "Max Offset") \ + V(FINAL_SIZE, final_size, "Final Size") + +#define V(name, _, __) IDX_QUIC_STREAM_STATS_##name, enum QuicStreamStatsIdx : int { STREAM_STATS(V) IDX_QUIC_STREAM_STATS_COUNT }; #undef V -#define V(_, name) uint64_t name; +#define V(_, name, __) uint64_t name; struct QuicStreamStats { STREAM_STATS(V) }; @@ -211,6 +212,8 @@ class QuicStream : public AsyncWrap, int64_t stream_id, int64_t push_id = 0); + ~QuicStream() override; + std::string diagnostic_name() const override; int64_t id() const { return stream_id_; } @@ -253,6 +256,13 @@ class QuicStream : public AsyncWrap, // Specifies the kind of headers currently being processed. inline void set_headers_kind(QuicStreamHeadersKind kind); + // Set the final size for the QuicStream + inline void set_final_size(uint64_t final_size); + + uint64_t final_size() const { + return GetStat(&QuicStreamStats::final_size); + } + // Marks the given data range as having been acknowledged. // This means that the data range may be released from // memory. @@ -371,6 +381,14 @@ class QuicStream : public AsyncWrap, ListNode stream_queue_; + class StatsDebug { + public: + StatsDebug(QuicStream* stream) : stream_(stream) {} + std::string ToString(); + private: + QuicStream* stream_; + }; + public: // Linked List of QuicStream objects using Queue = ListHead;