2025/04/30 09:37:47 Requesting https://server4:443/pprafbdtug.
2025/04/30 09:37:47 Increased receive buffer size to 14336 kiB
2025/04/30 09:37:47 Increased send buffer size to 14336 kiB
2025/04/30 09:37:47 Setting DF for IPv4 and IPv6.
2025/04/30 09:37:47 Activating reading of ECN bits for IPv4 and IPv6.
2025/04/30 09:37:47 Activating reading of packet info for IPv4 and IPv6.
2025/04/30 09:37:47 Created qlog file: /logs/qlog/a250d0fd226d79818fe31709a36be8c0d11a8e.sqlog
2025/04/30 09:37:47 client Starting new connection to server4 ([::]:45810 -> 193.167.100.100:443), source connection ID (empty), destination connection ID a250d0fd226d79818fe31709a36be8c0d11a8e, version v1
2025/04/30 09:37:47 Adding connection ID (empty).
2025/04/30 09:37:47 client Not doing 0-RTT. Has sealer: false, has params: false
2025/04/30 09:37:47 client -> Sending packet 0 (1280 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, Initial
2025/04/30 09:37:47 client 	Long Header{Type: Initial, DestConnectionID: a250d0fd226d79818fe31709a36be8c0d11a8e, SrcConnectionID: (empty), Token: (empty), PacketNumber: 0, PacketNumberLen: 2, Length: 1251, Version: v1}
2025/04/30 09:37:47 client 	-> &wire.CryptoFrame{Offset: 0, Data length: 272, Offset + Data length: 272}
2025/04/30 09:37:47 client 	updated RTT: 36.978955ms (σ: 18.489477ms)
2025/04/30 09:37:47 client <- Received Retry:
2025/04/30 09:37:47 client 	Long Header{Type: Retry, DestConnectionID: (empty), SrcConnectionID: 798a9538243b45b09052, Token: 0x526574727901006de99228a48c112ed6ea2b1df540beb09b40360cc235eb971da7a82cbad40af2a5ffd7b346b03d2ff82c89042d6a8e9b773d304092780b, Version: v1}
2025/04/30 09:37:47 client Switching destination connection ID to: 798a9538243b45b09052
2025/04/30 09:37:47 client -> Sending packet 1 (1280 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, Initial
2025/04/30 09:37:47 client 	Long Header{Type: Initial, DestConnectionID: 798a9538243b45b09052, SrcConnectionID: (empty), Token: 0x526574727901006de99228a48c112ed6ea2b1df540beb09b40360cc235eb971da7a82cbad40af2a5ffd7b346b03d2ff82c89042d6a8e9b773d304092780b, PacketNumber: 1, PacketNumberLen: 2, Length: 1198, Version: v1}
2025/04/30 09:37:47 client 	-> &wire.CryptoFrame{Offset: 0, Data length: 272, Offset + Data length: 272}
2025/04/30 09:37:47 client Parsed a coalesced packet. Part 1: 136 bytes. Remaining: 1096 bytes.
2025/04/30 09:37:47 client <- Reading packet 0 (136 bytes) for connection (empty), Initial
2025/04/30 09:37:47 client 	Long Header{Type: Initial, DestConnectionID: (empty), SrcConnectionID: ce920e958ba2c02a439f, Token: (empty), PacketNumber: 0, PacketNumberLen: 1, Length: 116, Version: v1}
2025/04/30 09:37:47 client Received first packet. Switching destination connection ID to: ce920e958ba2c02a439f
2025/04/30 09:37:47 client 	<- &wire.AckFrame{LargestAcked: 1, LowestAcked: 1, DelayTime: 0s}
2025/04/30 09:37:47 client 	newly acked packets (1): [1]
2025/04/30 09:37:47 client 	updated RTT: 36.769ms (σ: 14.284ms)
2025/04/30 09:37:47 client 	<- &wire.CryptoFrame{Offset: 0, Data length: 90, Offset + Data length: 90}
2025/04/30 09:37:47 client Installed Handshake Write keys (using TLS_AES_128_GCM_SHA256)
2025/04/30 09:37:47 client Installed Handshake Read keys (using TLS_AES_128_GCM_SHA256)
2025/04/30 09:37:47 client Parsed a coalesced packet. Part 2: 790 bytes. Remaining: 306 bytes.
2025/04/30 09:37:47 client <- Reading packet 0 (790 bytes) for connection (empty), Handshake
2025/04/30 09:37:47 client 	Long Header{Type: Handshake, DestConnectionID: (empty), SrcConnectionID: ce920e958ba2c02a439f, PacketNumber: 0, PacketNumberLen: 1, Length: 771, Version: v1}
2025/04/30 09:37:47 client 	<- &wire.CryptoFrame{Offset: 0, Data length: 750, Offset + Data length: 750}
2025/04/30 09:37:47 client Installed 1-RTT Write keys (using TLS_AES_128_GCM_SHA256)
2025/04/30 09:37:47 client Installed 1-RTT Read keys (using TLS_AES_128_GCM_SHA256)
2025/04/30 09:37:47 client Processed Transport Parameters: &wire.TransportParameters{OriginalDestinationConnectionID: a250d0fd226d79818fe31709a36be8c0d11a8e, InitialSourceConnectionID: ce920e958ba2c02a439f, RetrySourceConnectionID: 798a9538243b45b09052, InitialMaxStreamDataBidiLocal: 1048576, InitialMaxStreamDataBidiRemote: 1048576, InitialMaxStreamDataUni: 1048576, InitialMaxData: 4611686018427387903, MaxBidiStreamNum: 16, MaxUniStreamNum: 16, MaxIdleTimeout: 30s, AckDelayExponent: 3, MaxAckDelay: 20ms, ActiveConnectionIDLimit: 8, MaxDatagramFrameSize: 0}
2025/04/30 09:37:47 client Dropping %!s(logging.PacketType=5) packet (306 bytes) for which we couldn't unpack the header. Error: not a QUIC packet
2025/04/30 09:37:47 client -> Sending coalesced packet (2 parts, 1280 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e
2025/04/30 09:37:47 client 	Long Header{Type: Initial, DestConnectionID: ce920e958ba2c02a439f, SrcConnectionID: (empty), Token: 0x526574727901006de99228a48c112ed6ea2b1df540beb09b40360cc235eb971da7a82cbad40af2a5ffd7b346b03d2ff82c89042d6a8e9b773d304092780b, PacketNumber: 2, PacketNumberLen: 2, Length: 1122, Version: v1}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 0, LowestAcked: 0, DelayTime: 0s, ECT0: 1, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client 	Long Header{Type: Handshake, DestConnectionID: ce920e958ba2c02a439f, SrcConnectionID: (empty), PacketNumber: 0, PacketNumberLen: 2, Length: 57, Version: v1}
2025/04/30 09:37:47 client 	-> &wire.CryptoFrame{Offset: 0, Data length: 36, Offset + Data length: 36}
2025/04/30 09:37:47 client Dropping Initial keys.
2025/04/30 09:37:47 client -> Sending packet 1 (93 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, Handshake
2025/04/30 09:37:47 client 	Long Header{Type: Handshake, DestConnectionID: ce920e958ba2c02a439f, SrcConnectionID: (empty), PacketNumber: 1, PacketNumberLen: 2, Length: 26, Version: v1}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 0, LowestAcked: 0, DelayTime: 0s, ECT0: 1, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: ce920e958ba2c02a439f, PacketNumber: 0, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.StreamFrame{StreamID: 0, Fin: true, Offset: 0, Data length: 17, Offset + Data length: 17}
2025/04/30 09:37:47 client Parsed a coalesced packet. Part 1: 41 bytes. Remaining: 1291 bytes.
2025/04/30 09:37:47 client <- Reading packet 1 (41 bytes) for connection (empty), Handshake
2025/04/30 09:37:47 client 	Long Header{Type: Handshake, DestConnectionID: (empty), SrcConnectionID: ce920e958ba2c02a439f, PacketNumber: 1, PacketNumberLen: 1, Length: 22, Version: v1}
2025/04/30 09:37:47 client 	<- &wire.AckFrame{LargestAcked: 0, LowestAcked: 0, DelayTime: 0s}
2025/04/30 09:37:47 client Peer doesn't await address validation any longer.
2025/04/30 09:37:47 client 	newly acked packets (1): [0]
2025/04/30 09:37:47 client 	updated RTT: 36.326ms (σ: 11.598ms)
2025/04/30 09:37:47 client Canceling loss detection timer.
2025/04/30 09:37:47 client <- Reading packet 0 (1291 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 0, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.HandshakeDoneFrame{}
2025/04/30 09:37:47 client Dropping Handshake keys.
2025/04/30 09:37:47 client 	<- &wire.NewConnectionIDFrame{SequenceNumber: 1, RetirePriorTo: 0, ConnectionID: 8a136bd01ccc7d216f3d, StatelessResetToken: 0x7c3a51afdc1fa86a21bff0eb4b90b00d}
2025/04/30 09:37:47 client 	<- &wire.NewConnectionIDFrame{SequenceNumber: 2, RetirePriorTo: 0, ConnectionID: a105967b0848e4e45c62, StatelessResetToken: 0xe6c9f2422b4a81dc3a5174daee96ea8d}
2025/04/30 09:37:47 client 	<- &wire.NewConnectionIDFrame{SequenceNumber: 3, RetirePriorTo: 0, ConnectionID: 5a59aa73e38bde4d5bb3, StatelessResetToken: 0x989a79918415ab87f4d3efc65ef9e393}
2025/04/30 09:37:47 client 	Queueing ACK because the first packet should be acknowledged.
2025/04/30 09:37:47 client -> Sending packet 1 (39 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 1, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 0, LowestAcked: 0, DelayTime: 148.64µs, ECT0: 1, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client 	-> &wire.RetireConnectionIDFrame{SequenceNumber: 0}
2025/04/30 09:37:47 client <- Reading packet 1 (1332 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 1, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.PingFrame{}
2025/04/30 09:37:47 client 	Setting ACK timer to max ack delay: 25ms
2025/04/30 09:37:47 client <- Reading packet 2 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 2, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 0, Data length: 1212, Offset + Data length: 1212}
2025/04/30 09:37:47 client 	Queueing ACK because packet 2 packets were received after the last ACK (using initial threshold: 2).
2025/04/30 09:37:47 client -> Sending packet 2 (37 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 2, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 2, LowestAcked: 0, DelayTime: 50.465µs, ECT0: 3, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client <- Reading packet 3 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 3, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 1212, Data length: 1210, Offset + Data length: 2422}
2025/04/30 09:37:47 client 	Setting ACK timer to max ack delay: 25ms
2025/04/30 09:37:47 client <- Reading packet 4 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 4, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 2422, Data length: 1210, Offset + Data length: 3632}
2025/04/30 09:37:47 client 	Queueing ACK because packet 2 packets were received after the last ACK (using initial threshold: 2).
2025/04/30 09:37:47 client -> Sending packet 3 (37 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 3, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 4, LowestAcked: 0, DelayTime: 53.54µs, ECT0: 5, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client <- Reading packet 5 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 5, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 3632, Data length: 1210, Offset + Data length: 4842}
2025/04/30 09:37:47 client 	Setting ACK timer to max ack delay: 25ms
2025/04/30 09:37:47 client <- Reading packet 6 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 6, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 4842, Data length: 1210, Offset + Data length: 6052}
2025/04/30 09:37:47 client 	Queueing ACK because packet 2 packets were received after the last ACK (using initial threshold: 2).
2025/04/30 09:37:47 client -> Sending packet 4 (37 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 4, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 6, LowestAcked: 0, DelayTime: 59.542µs, ECT0: 7, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client <- Reading packet 7 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 7, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 6052, Data length: 1210, Offset + Data length: 7262}
2025/04/30 09:37:47 client 	Setting ACK timer to max ack delay: 25ms
2025/04/30 09:37:47 client <- Reading packet 8 (1232 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 8, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 7262, Data length: 1210, Offset + Data length: 8472}
2025/04/30 09:37:47 client 	Queueing ACK because packet 2 packets were received after the last ACK (using initial threshold: 2).
2025/04/30 09:37:47 client -> Sending packet 5 (37 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 5, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 8, LowestAcked: 0, DelayTime: 37.28µs, ECT0: 9, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client <- Reading packet 9 (1073 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 9, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: false, Offset: 8472, Data length: 1051, Offset + Data length: 9523}
2025/04/30 09:37:47 client 	Setting ACK timer to max ack delay: 25ms
2025/04/30 09:37:47 client <- Reading packet 10 (24 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 10, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.AckFrame{LargestAcked: 0, LowestAcked: 0, DelayTime: 21.184ms}
2025/04/30 09:37:47 client 	newly acked packets (1): [0]
2025/04/30 09:37:47 client 	updated RTT: 35.945ms (σ: 9.459ms)
2025/04/30 09:37:47 client <- Reading packet 11 (1157 bytes) for connection (empty), 1-RTT
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: (empty), PacketNumber: 11, PacketNumberLen: 1, KeyPhase: 0}
2025/04/30 09:37:47 client 	<- &wire.NewConnectionIDFrame{SequenceNumber: 4, RetirePriorTo: 0, ConnectionID: c6970e6d402ece68a066, StatelessResetToken: 0x4d98977cc830fce12f7a915fc6098425}
2025/04/30 09:37:47 client 	<- &wire.StreamFrame{StreamID: 0, Fin: true, Offset: 9523, Data length: 717, Offset + Data length: 10240}
2025/04/30 09:37:47 client 	<- &wire.CryptoFrame{Offset: 0, Data length: 337, Offset + Data length: 337}
2025/04/30 09:37:47 client 	<- &wire.NewTokenFrame{Token: 0xad9a8b8d86010021a6d6273508b66e7595f9fb592d862d8a9bc5433d9a876dc122872c8e702b16686343c5}
2025/04/30 09:37:47 client 	Queueing ACK because packet 2 packets were received after the last ACK (using initial threshold: 2).
2025/04/30 09:37:47 client -> Sending packet 6 (37 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 6, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.AckFrame{LargestAcked: 11, LowestAcked: 0, DelayTime: 89.198µs, ECT0: 9, ECT1: 0, CE: 0}
2025/04/30 09:37:47 client Closing connection with error: Application error 0x0 (local)
2025/04/30 09:37:47 client -> Sending packet 7 (32 bytes) for connection a250d0fd226d79818fe31709a36be8c0d11a8e, 1-RTT (ECN: ECT(0))
2025/04/30 09:37:47 client 	Short Header{DestConnectionID: 8a136bd01ccc7d216f3d, PacketNumber: 7, PacketNumberLen: 2, KeyPhase: 0}
2025/04/30 09:37:47 client 	-> &wire.ConnectionCloseFrame{IsApplicationError:true, ErrorCode:0x0, FrameType:0x0, ReasonPhrase:""}
2025/04/30 09:37:47 Replacing connection for connection IDs [(empty)] with a closed connection.
2025/04/30 09:37:47 client Connection a250d0fd226d79818fe31709a36be8c0d11a8e closed.