Source code
Revision control
Copy as Markdown
Other Tools
// Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
// option. This file may not be copied, modified, or distributed
// except according to those terms.
// Functions that handle capturing QLOG traces.
use std::{
ops::{Deref, RangeInclusive},
time::Duration,
};
use neqo_common::{hex, qinfo, qlog::NeqoQlog, Decoder, IpTosEcn};
use qlog::events::{
connectivity::{ConnectionStarted, ConnectionState, ConnectionStateUpdated},
quic::{
AckedRanges, ErrorSpace, MetricsUpdated, PacketDropped, PacketHeader, PacketLost,
PacketReceived, PacketSent, QuicFrame, StreamType, VersionInformation,
},
EventData, RawInfo,
};
use smallvec::SmallVec;
use crate::{
connection::State,
frame::{CloseError, Frame},
packet::{DecryptedPacket, PacketNumber, PacketType, PublicPacket},
path::PathRef,
recovery::SentPacket,
stream_id::StreamType as NeqoStreamType,
tparams::{self, TransportParametersHandler},
version::{Version, VersionConfig, WireVersion},
};
pub fn connection_tparams_set(qlog: &NeqoQlog, tph: &TransportParametersHandler) {
qlog.add_event_data(|| {
let remote = tph.remote();
#[allow(clippy::cast_possible_truncation)] // Nope.
let ev_data = EventData::TransportParametersSet(
qlog::events::quic::TransportParametersSet {
owner: None,
resumption_allowed: None,
early_data_enabled: None,
tls_cipher: None,
aead_tag_length: None,
original_destination_connection_id: remote
.get_bytes(tparams::ORIGINAL_DESTINATION_CONNECTION_ID)
.map(hex),
initial_source_connection_id: None,
retry_source_connection_id: None,
stateless_reset_token: remote.get_bytes(tparams::STATELESS_RESET_TOKEN).map(hex),
disable_active_migration: if remote.get_empty(tparams::DISABLE_MIGRATION) {
Some(true)
} else {
None
},
max_idle_timeout: Some(remote.get_integer(tparams::IDLE_TIMEOUT)),
max_udp_payload_size: Some(remote.get_integer(tparams::MAX_UDP_PAYLOAD_SIZE) as u32),
ack_delay_exponent: Some(remote.get_integer(tparams::ACK_DELAY_EXPONENT) as u16),
max_ack_delay: Some(remote.get_integer(tparams::MAX_ACK_DELAY) as u16),
active_connection_id_limit: Some(remote.get_integer(tparams::ACTIVE_CONNECTION_ID_LIMIT) as u32),
initial_max_data: Some(remote.get_integer(tparams::INITIAL_MAX_DATA)),
initial_max_stream_data_bidi_local: Some(remote.get_integer(tparams::INITIAL_MAX_STREAM_DATA_BIDI_LOCAL)),
initial_max_stream_data_bidi_remote: Some(remote.get_integer(tparams::INITIAL_MAX_STREAM_DATA_BIDI_REMOTE)),
initial_max_stream_data_uni: Some(remote.get_integer(tparams::INITIAL_MAX_STREAM_DATA_UNI)),
initial_max_streams_bidi: Some(remote.get_integer(tparams::INITIAL_MAX_STREAMS_BIDI)),
initial_max_streams_uni: Some(remote.get_integer(tparams::INITIAL_MAX_STREAMS_UNI)),
preferred_address: remote.get_preferred_address().and_then(|(paddr, cid)| {
Some(qlog::events::quic::PreferredAddress {
ip_v4: paddr.ipv4()?.ip().to_string(),
ip_v6: paddr.ipv6()?.ip().to_string(),
port_v4: paddr.ipv4()?.port(),
port_v6: paddr.ipv6()?.port(),
connection_id: cid.connection_id().to_string(),
stateless_reset_token: hex(cid.reset_token()),
})
}),
});
Some(ev_data)
});
}
pub fn server_connection_started(qlog: &NeqoQlog, path: &PathRef) {
connection_started(qlog, path);
}
pub fn client_connection_started(qlog: &NeqoQlog, path: &PathRef) {
connection_started(qlog, path);
}
fn connection_started(qlog: &NeqoQlog, path: &PathRef) {
qlog.add_event_data(|| {
let p = path.deref().borrow();
let ev_data = EventData::ConnectionStarted(ConnectionStarted {
ip_version: if p.local_address().ip().is_ipv4() {
Some("ipv4".into())
} else {
Some("ipv6".into())
},
src_ip: format!("{}", p.local_address().ip()),
dst_ip: format!("{}", p.remote_address().ip()),
protocol: Some("QUIC".into()),
src_port: p.local_address().port().into(),
dst_port: p.remote_address().port().into(),
src_cid: p.local_cid().map(ToString::to_string),
dst_cid: p.remote_cid().map(ToString::to_string),
});
Some(ev_data)
});
}
pub fn connection_state_updated(qlog: &NeqoQlog, new: &State) {
qlog.add_event_data(|| {
let ev_data = EventData::ConnectionStateUpdated(ConnectionStateUpdated {
old: None,
new: match new {
State::Init | State::WaitInitial => ConnectionState::Attempted,
State::WaitVersion | State::Handshaking => ConnectionState::HandshakeStarted,
State::Connected => ConnectionState::HandshakeCompleted,
State::Confirmed => ConnectionState::HandshakeConfirmed,
State::Closing { .. } => ConnectionState::Closing,
State::Draining { .. } => ConnectionState::Draining,
State::Closed { .. } => ConnectionState::Closed,
},
});
Some(ev_data)
});
}
pub fn client_version_information_initiated(qlog: &NeqoQlog, version_config: &VersionConfig) {
qlog.add_event_data(|| {
Some(EventData::VersionInformation(VersionInformation {
client_versions: Some(
version_config
.all()
.iter()
.map(|v| format!("{:02x}", v.wire_version()))
.collect(),
),
server_versions: None,
chosen_version: Some(format!("{:02x}", version_config.initial().wire_version())),
}))
});
}
pub fn client_version_information_negotiated(
qlog: &NeqoQlog,
client: &[Version],
server: &[WireVersion],
chosen: Version,
) {
qlog.add_event_data(|| {
Some(EventData::VersionInformation(VersionInformation {
client_versions: Some(
client
.iter()
.map(|v| format!("{:02x}", v.wire_version()))
.collect(),
),
server_versions: Some(server.iter().map(|v| format!("{v:02x}")).collect()),
chosen_version: Some(format!("{:02x}", chosen.wire_version())),
}))
});
}
pub fn server_version_information_failed(qlog: &NeqoQlog, server: &[Version], client: WireVersion) {
qlog.add_event_data(|| {
Some(EventData::VersionInformation(VersionInformation {
client_versions: Some(vec![format!("{client:02x}")]),
server_versions: Some(
server
.iter()
.map(|v| format!("{:02x}", v.wire_version()))
.collect(),
),
chosen_version: None,
}))
});
}
pub fn packet_sent(qlog: &NeqoQlog, pt: PacketType, pn: PacketNumber, plen: usize, body: &[u8]) {
qlog.add_event_with_stream(|stream| {
let mut d = Decoder::from(body);
let header = PacketHeader::with_type(pt.into(), Some(pn), None, None, None);
let raw = RawInfo {
length: Some(plen as u64),
payload_length: None,
data: None,
};
let mut frames = SmallVec::new();
while d.remaining() > 0 {
if let Ok(f) = Frame::decode(&mut d) {
frames.push(QuicFrame::from(f));
} else {
qinfo!("qlog: invalid frame");
break;
}
}
let ev_data = EventData::PacketSent(PacketSent {
header,
frames: Some(frames),
is_coalesced: None,
retry_token: None,
stateless_reset_token: None,
supported_versions: None,
raw: Some(raw),
datagram_id: None,
send_at_time: None,
trigger: None,
});
stream.add_event_data_now(ev_data)
});
}
pub fn packet_dropped(qlog: &NeqoQlog, public_packet: &PublicPacket) {
qlog.add_event_data(|| {
let header =
PacketHeader::with_type(public_packet.packet_type().into(), None, None, None, None);
let raw = RawInfo {
length: Some(public_packet.len() as u64),
payload_length: None,
data: None,
};
let ev_data = EventData::PacketDropped(PacketDropped {
header: Some(header),
raw: Some(raw),
datagram_id: None,
details: None,
trigger: None,
});
Some(ev_data)
});
}
pub fn packets_lost(qlog: &NeqoQlog, pkts: &[SentPacket]) {
qlog.add_event_with_stream(|stream| {
for pkt in pkts {
let header =
PacketHeader::with_type(pkt.packet_type().into(), Some(pkt.pn()), None, None, None);
let ev_data = EventData::PacketLost(PacketLost {
header: Some(header),
trigger: None,
frames: None,
});
stream.add_event_data_now(ev_data)?;
}
Ok(())
});
}
pub fn packet_received(qlog: &NeqoQlog, public_packet: &PublicPacket, payload: &DecryptedPacket) {
qlog.add_event_with_stream(|stream| {
let mut d = Decoder::from(&payload[..]);
let header = PacketHeader::with_type(
public_packet.packet_type().into(),
Some(payload.pn()),
None,
None,
None,
);
let raw = RawInfo {
length: Some(public_packet.len() as u64),
payload_length: None,
data: None,
};
let mut frames = Vec::new();
while d.remaining() > 0 {
if let Ok(f) = Frame::decode(&mut d) {
frames.push(QuicFrame::from(f));
} else {
qinfo!("qlog: invalid frame");
break;
}
}
let ev_data = EventData::PacketReceived(PacketReceived {
header,
frames: Some(frames),
is_coalesced: None,
retry_token: None,
stateless_reset_token: None,
supported_versions: None,
raw: Some(raw),
datagram_id: None,
trigger: None,
});
stream.add_event_data_now(ev_data)
});
}
#[allow(dead_code)]
pub enum QlogMetric {
MinRtt(Duration),
SmoothedRtt(Duration),
LatestRtt(Duration),
RttVariance(Duration),
MaxAckDelay(u64),
PtoCount(usize),
CongestionWindow(usize),
BytesInFlight(usize),
SsThresh(usize),
PacketsInFlight(u64),
InRecovery(bool),
PacingRate(u64),
}
pub fn metrics_updated(qlog: &NeqoQlog, updated_metrics: &[QlogMetric]) {
debug_assert!(!updated_metrics.is_empty());
qlog.add_event_data(|| {
let mut min_rtt: Option<f32> = None;
let mut smoothed_rtt: Option<f32> = None;
let mut latest_rtt: Option<f32> = None;
let mut rtt_variance: Option<f32> = None;
let mut pto_count: Option<u16> = None;
let mut congestion_window: Option<u64> = None;
let mut bytes_in_flight: Option<u64> = None;
let mut ssthresh: Option<u64> = None;
let mut packets_in_flight: Option<u64> = None;
let mut pacing_rate: Option<u64> = None;
for metric in updated_metrics {
#[allow(clippy::cast_precision_loss)] // Nought to do here.
match metric {
QlogMetric::MinRtt(v) => min_rtt = Some(v.as_secs_f32() * 1000.0),
QlogMetric::SmoothedRtt(v) => smoothed_rtt = Some(v.as_secs_f32() * 1000.0),
QlogMetric::LatestRtt(v) => latest_rtt = Some(v.as_secs_f32() * 1000.0),
QlogMetric::RttVariance(v) => rtt_variance = Some(v.as_secs_f32() * 1000.0),
QlogMetric::PtoCount(v) => pto_count = Some(u16::try_from(*v).unwrap()),
QlogMetric::CongestionWindow(v) => {
congestion_window = Some(u64::try_from(*v).unwrap());
}
QlogMetric::BytesInFlight(v) => bytes_in_flight = Some(u64::try_from(*v).unwrap()),
QlogMetric::SsThresh(v) => ssthresh = Some(u64::try_from(*v).unwrap()),
QlogMetric::PacketsInFlight(v) => packets_in_flight = Some(*v),
QlogMetric::PacingRate(v) => pacing_rate = Some(*v),
_ => (),
}
}
let ev_data = EventData::MetricsUpdated(MetricsUpdated {
min_rtt,
smoothed_rtt,
latest_rtt,
rtt_variance,
pto_count,
congestion_window,
bytes_in_flight,
ssthresh,
packets_in_flight,
pacing_rate,
});
Some(ev_data)
});
}
// Helper functions
#[allow(clippy::too_many_lines)] // Yeah, but it's a nice match.
#[allow(clippy::cast_possible_truncation, clippy::cast_precision_loss)] // No choice here.
impl From<Frame<'_>> for QuicFrame {
fn from(frame: Frame) -> Self {
match frame {
Frame::Padding(len) => Self::Padding {
length: None,
payload_length: u32::from(len),
},
Frame::Ping => Self::Ping {
length: None,
payload_length: None,
},
Frame::Ack {
largest_acknowledged,
ack_delay,
first_ack_range,
ack_ranges,
ecn_count,
} => {
let ranges =
Frame::decode_ack_frame(largest_acknowledged, first_ack_range, &ack_ranges)
.ok();
let acked_ranges = ranges.map(|all| {
AckedRanges::Double(
all.into_iter()
.map(RangeInclusive::into_inner)
.collect::<Vec<_>>(),
)
});
Self::Ack {
ack_delay: Some(ack_delay as f32 / 1000.0),
acked_ranges,
ect1: ecn_count.map(|c| c[IpTosEcn::Ect1]),
ect0: ecn_count.map(|c| c[IpTosEcn::Ect0]),
ce: ecn_count.map(|c| c[IpTosEcn::Ce]),
length: None,
payload_length: None,
}
}
Frame::ResetStream {
stream_id,
application_error_code,
final_size,
} => Self::ResetStream {
stream_id: stream_id.as_u64(),
error_code: application_error_code,
final_size,
length: None,
payload_length: None,
},
Frame::StopSending {
stream_id,
application_error_code,
} => Self::StopSending {
stream_id: stream_id.as_u64(),
error_code: application_error_code,
length: None,
payload_length: None,
},
Frame::Crypto { offset, data } => Self::Crypto {
offset,
length: data.len() as u64,
},
Frame::NewToken { token } => Self::NewToken {
token: qlog::Token {
ty: Some(qlog::TokenType::Retry),
details: None,
raw: Some(RawInfo {
data: Some(hex(token)),
length: Some(token.len() as u64),
payload_length: None,
}),
},
},
Frame::Stream {
fin,
stream_id,
offset,
data,
..
} => Self::Stream {
stream_id: stream_id.as_u64(),
offset,
length: data.len() as u64,
fin: Some(fin),
raw: None,
},
Frame::MaxData { maximum_data } => Self::MaxData {
maximum: maximum_data,
},
Frame::MaxStreamData {
stream_id,
maximum_stream_data,
} => Self::MaxStreamData {
stream_id: stream_id.as_u64(),
maximum: maximum_stream_data,
},
Frame::MaxStreams {
stream_type,
maximum_streams,
} => Self::MaxStreams {
stream_type: match stream_type {
NeqoStreamType::BiDi => StreamType::Bidirectional,
NeqoStreamType::UniDi => StreamType::Unidirectional,
},
maximum: maximum_streams,
},
Frame::DataBlocked { data_limit } => Self::DataBlocked { limit: data_limit },
Frame::StreamDataBlocked {
stream_id,
stream_data_limit,
} => Self::StreamDataBlocked {
stream_id: stream_id.as_u64(),
limit: stream_data_limit,
},
Frame::StreamsBlocked {
stream_type,
stream_limit,
} => Self::StreamsBlocked {
stream_type: match stream_type {
NeqoStreamType::BiDi => StreamType::Bidirectional,
NeqoStreamType::UniDi => StreamType::Unidirectional,
},
limit: stream_limit,
},
Frame::NewConnectionId {
sequence_number,
retire_prior,
connection_id,
stateless_reset_token,
} => Self::NewConnectionId {
sequence_number: sequence_number as u32,
retire_prior_to: retire_prior as u32,
connection_id_length: Some(connection_id.len() as u8),
connection_id: hex(connection_id),
stateless_reset_token: Some(hex(stateless_reset_token)),
},
Frame::RetireConnectionId { sequence_number } => Self::RetireConnectionId {
sequence_number: sequence_number as u32,
},
Frame::PathChallenge { data } => Self::PathChallenge {
data: Some(hex(data)),
},
Frame::PathResponse { data } => Self::PathResponse {
data: Some(hex(data)),
},
Frame::ConnectionClose {
error_code,
frame_type,
reason_phrase,
} => Self::ConnectionClose {
error_space: match error_code {
CloseError::Transport(_) => Some(ErrorSpace::TransportError),
CloseError::Application(_) => Some(ErrorSpace::ApplicationError),
},
error_code: Some(error_code.code()),
error_code_value: Some(0),
reason: Some(reason_phrase),
trigger_frame_type: Some(frame_type),
},
Frame::HandshakeDone => Self::HandshakeDone,
Frame::AckFrequency { .. } => Self::Unknown {
frame_type_value: None,
raw_frame_type: frame.get_type(),
raw: None,
},
Frame::Datagram { data, .. } => Self::Datagram {
length: data.len() as u64,
raw: None,
},
}
}
}
impl From<PacketType> for qlog::events::quic::PacketType {
fn from(value: PacketType) -> Self {
match value {
PacketType::Initial => Self::Initial,
PacketType::Handshake => Self::Handshake,
PacketType::ZeroRtt => Self::ZeroRtt,
PacketType::Short => Self::OneRtt,
PacketType::Retry => Self::Retry,
PacketType::VersionNegotiation => Self::VersionNegotiation,
PacketType::OtherVersion => Self::Unknown,
}
}
}