Nov 17 21:58:28.566 INFO testing srt-transport-0.2.0 against master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c for pr-55982 Nov 17 21:58:28.566 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-7/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 17 21:58:28.831 INFO [stdout] 16533751cbd4ba7c2c19d2ee5513b27e88b9a83e75767b1ad35f299c27475467 Nov 17 21:58:28.833 INFO running `"docker" "start" "-a" "16533751cbd4ba7c2c19d2ee5513b27e88b9a83e75767b1ad35f299c27475467"` Nov 17 21:58:29.302 INFO [stderr] usermod: no changes Nov 17 21:58:29.461 INFO [stderr] Compiling futures-timer v0.1.1 Nov 17 21:58:29.463 INFO [stderr] Compiling simple_logger v0.5.0 Nov 17 21:58:30.719 INFO [stderr] Compiling srt-transport v0.2.0 (/source) Nov 17 21:58:33.383 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.383 INFO [stderr] --> src/packet.rs:175:39 Nov 17 21:58:33.383 INFO [stderr] | Nov 17 21:58:33.383 INFO [stderr] 175 | let udt_version = buf.get_i32::(); Nov 17 21:58:33.384 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.384 INFO [stderr] | Nov 17 21:58:33.384 INFO [stderr] = note: #[warn(deprecated)] on by default Nov 17 21:58:33.384 INFO [stderr] Nov 17 21:58:33.384 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.384 INFO [stderr] --> src/packet.rs:176:58 Nov 17 21:58:33.384 INFO [stderr] | Nov 17 21:58:33.384 INFO [stderr] 176 | let sock_type = SocketType::from_i32(buf.get_i32::())?; Nov 17 21:58:33.384 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.384 INFO [stderr] Nov 17 21:58:33.384 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.385 INFO [stderr] --> src/packet.rs:177:50 Nov 17 21:58:33.385 INFO [stderr] | Nov 17 21:58:33.385 INFO [stderr] 177 | let init_seq_num = SeqNumber(buf.get_i32::()); Nov 17 21:58:33.385 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.385 INFO [stderr] Nov 17 21:58:33.385 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.385 INFO [stderr] --> src/packet.rs:178:43 Nov 17 21:58:33.385 INFO [stderr] | Nov 17 21:58:33.385 INFO [stderr] 178 | let max_packet_size = buf.get_i32::(); Nov 17 21:58:33.385 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.386 INFO [stderr] Nov 17 21:58:33.386 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.386 INFO [stderr] --> src/packet.rs:179:41 Nov 17 21:58:33.386 INFO [stderr] | Nov 17 21:58:33.386 INFO [stderr] 179 | let max_flow_size = buf.get_i32::(); Nov 17 21:58:33.386 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.386 INFO [stderr] Nov 17 21:58:33.386 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.386 INFO [stderr] --> src/packet.rs:180:68 Nov 17 21:58:33.386 INFO [stderr] | Nov 17 21:58:33.386 INFO [stderr] 180 | let connection_type = ConnectionType::from_i32(buf.get_i32::())?; Nov 17 21:58:33.387 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.387 INFO [stderr] Nov 17 21:58:33.387 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.387 INFO [stderr] --> src/packet.rs:181:46 Nov 17 21:58:33.387 INFO [stderr] | Nov 17 21:58:33.387 INFO [stderr] 181 | let socket_id = SocketID(buf.get_i32::()); Nov 17 21:58:33.387 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.387 INFO [stderr] Nov 17 21:58:33.387 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.387 INFO [stderr] --> src/packet.rs:182:38 Nov 17 21:58:33.387 INFO [stderr] | Nov 17 21:58:33.387 INFO [stderr] 182 | let syn_cookie = buf.get_i32::(); Nov 17 21:58:33.388 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.388 INFO [stderr] Nov 17 21:58:33.401 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.401 INFO [stderr] --> src/packet.rs:212:48 Nov 17 21:58:33.401 INFO [stderr] | Nov 17 21:58:33.401 INFO [stderr] 212 | let ack_number = SeqNumber(buf.get_i32::()); Nov 17 21:58:33.401 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.401 INFO [stderr] Nov 17 21:58:33.401 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.401 INFO [stderr] --> src/packet.rs:217:34 Nov 17 21:58:33.401 INFO [stderr] | Nov 17 21:58:33.401 INFO [stderr] 217 | Some(buf.get_i32::()) Nov 17 21:58:33.401 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.401 INFO [stderr] Nov 17 21:58:33.403 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.403 INFO [stderr] --> src/packet.rs:245:40 Nov 17 21:58:33.403 INFO [stderr] | Nov 17 21:58:33.403 INFO [stderr] 245 | loss_info.push(buf.get_i32::()); Nov 17 21:58:33.403 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.403 INFO [stderr] Nov 17 21:58:33.407 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.407 INFO [stderr] --> src/packet.rs:295:22 Nov 17 21:58:33.407 INFO [stderr] | Nov 17 21:58:33.407 INFO [stderr] 295 | into.put_i32::(c.udt_version); Nov 17 21:58:33.407 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.407 INFO [stderr] Nov 17 21:58:33.407 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.407 INFO [stderr] --> src/packet.rs:296:22 Nov 17 21:58:33.407 INFO [stderr] | Nov 17 21:58:33.407 INFO [stderr] 296 | into.put_i32::(c.sock_type.to_i32()); Nov 17 21:58:33.407 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.407 INFO [stderr] Nov 17 21:58:33.407 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.407 INFO [stderr] --> src/packet.rs:297:22 Nov 17 21:58:33.407 INFO [stderr] | Nov 17 21:58:33.407 INFO [stderr] 297 | into.put_i32::(c.init_seq_num.0); Nov 17 21:58:33.407 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.407 INFO [stderr] Nov 17 21:58:33.407 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.408 INFO [stderr] --> src/packet.rs:298:22 Nov 17 21:58:33.408 INFO [stderr] | Nov 17 21:58:33.408 INFO [stderr] 298 | into.put_i32::(c.max_packet_size); Nov 17 21:58:33.408 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.408 INFO [stderr] Nov 17 21:58:33.408 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.408 INFO [stderr] --> src/packet.rs:299:22 Nov 17 21:58:33.408 INFO [stderr] | Nov 17 21:58:33.408 INFO [stderr] 299 | into.put_i32::(c.max_flow_size); Nov 17 21:58:33.408 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.408 INFO [stderr] Nov 17 21:58:33.408 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.408 INFO [stderr] --> src/packet.rs:300:22 Nov 17 21:58:33.408 INFO [stderr] | Nov 17 21:58:33.408 INFO [stderr] 300 | into.put_i32::(c.connection_type.to_i32()); Nov 17 21:58:33.408 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.408 INFO [stderr] Nov 17 21:58:33.408 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.408 INFO [stderr] --> src/packet.rs:301:22 Nov 17 21:58:33.408 INFO [stderr] | Nov 17 21:58:33.408 INFO [stderr] 301 | into.put_i32::(c.socket_id.0); Nov 17 21:58:33.408 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.408 INFO [stderr] Nov 17 21:58:33.408 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.408 INFO [stderr] --> src/packet.rs:302:22 Nov 17 21:58:33.408 INFO [stderr] | Nov 17 21:58:33.408 INFO [stderr] 302 | into.put_i32::(c.syn_cookie); Nov 17 21:58:33.408 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.408 INFO [stderr] Nov 17 21:58:33.409 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.409 INFO [stderr] --> src/packet.rs:315:22 Nov 17 21:58:33.409 INFO [stderr] | Nov 17 21:58:33.409 INFO [stderr] 315 | into.put_i32::(c.ack_number.0); Nov 17 21:58:33.409 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.409 INFO [stderr] Nov 17 21:58:33.409 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.409 INFO [stderr] --> src/packet.rs:316:22 Nov 17 21:58:33.409 INFO [stderr] | Nov 17 21:58:33.409 INFO [stderr] 316 | into.put_i32::(c.rtt.unwrap_or(10_000)); Nov 17 21:58:33.409 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.409 INFO [stderr] Nov 17 21:58:33.410 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.410 INFO [stderr] --> src/packet.rs:317:22 Nov 17 21:58:33.410 INFO [stderr] | Nov 17 21:58:33.410 INFO [stderr] 317 | into.put_i32::(c.rtt_variance.unwrap_or(50_000)); Nov 17 21:58:33.410 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.410 INFO [stderr] Nov 17 21:58:33.410 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.410 INFO [stderr] --> src/packet.rs:318:22 Nov 17 21:58:33.410 INFO [stderr] | Nov 17 21:58:33.410 INFO [stderr] 318 | into.put_i32::(c.buffer_available.unwrap_or(8175)); // TODO: better defaults Nov 17 21:58:33.410 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.410 INFO [stderr] Nov 17 21:58:33.410 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.410 INFO [stderr] --> src/packet.rs:319:22 Nov 17 21:58:33.410 INFO [stderr] | Nov 17 21:58:33.410 INFO [stderr] 319 | into.put_i32::(c.packet_recv_rate.unwrap_or(10_000)); Nov 17 21:58:33.411 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.411 INFO [stderr] Nov 17 21:58:33.411 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.411 INFO [stderr] --> src/packet.rs:320:22 Nov 17 21:58:33.411 INFO [stderr] | Nov 17 21:58:33.411 INFO [stderr] 320 | into.put_i32::(c.est_link_cap.unwrap_or(1_000)); Nov 17 21:58:33.411 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.411 INFO [stderr] Nov 17 21:58:33.412 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.412 INFO [stderr] --> src/packet.rs:323:22 Nov 17 21:58:33.412 INFO [stderr] | Nov 17 21:58:33.412 INFO [stderr] 323 | into.put_i32::(loss); Nov 17 21:58:33.412 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.412 INFO [stderr] Nov 17 21:58:33.438 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.438 INFO [stderr] --> src/packet.rs:507:60 Nov 17 21:58:33.438 INFO [stderr] | Nov 17 21:58:33.438 INFO [stderr] 507 | let seq_number = SeqNumber(Cursor::new(first4).get_i32::()); Nov 17 21:58:33.438 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.438 INFO [stderr] Nov 17 21:58:33.438 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.438 INFO [stderr] --> src/packet.rs:510:35 Nov 17 21:58:33.438 INFO [stderr] | Nov 17 21:58:33.438 INFO [stderr] 510 | let second_line = buf.get_i32::(); Nov 17 21:58:33.438 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.438 INFO [stderr] Nov 17 21:58:33.439 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.439 INFO [stderr] --> src/packet.rs:519:33 Nov 17 21:58:33.439 INFO [stderr] | Nov 17 21:58:33.439 INFO [stderr] 519 | let timestamp = buf.get_i32::(); Nov 17 21:58:33.439 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.439 INFO [stderr] Nov 17 21:58:33.439 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.439 INFO [stderr] --> src/packet.rs:520:44 Nov 17 21:58:33.439 INFO [stderr] | Nov 17 21:58:33.439 INFO [stderr] 520 | let dest_sockid = SocketID(buf.get_i32::()); Nov 17 21:58:33.439 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.439 INFO [stderr] Nov 17 21:58:33.440 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.440 INFO [stderr] --> src/packet.rs:534:32 Nov 17 21:58:33.440 INFO [stderr] | Nov 17 21:58:33.440 INFO [stderr] 534 | let add_info = buf.get_i32::(); Nov 17 21:58:33.440 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.440 INFO [stderr] Nov 17 21:58:33.440 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.440 INFO [stderr] --> src/packet.rs:535:33 Nov 17 21:58:33.440 INFO [stderr] | Nov 17 21:58:33.440 INFO [stderr] 535 | let timestamp = buf.get_i32::(); Nov 17 21:58:33.440 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.440 INFO [stderr] Nov 17 21:58:33.440 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:33.440 INFO [stderr] --> src/packet.rs:536:35 Nov 17 21:58:33.440 INFO [stderr] | Nov 17 21:58:33.440 INFO [stderr] 536 | let dest_sockid = buf.get_i32::(); Nov 17 21:58:33.440 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.440 INFO [stderr] Nov 17 21:58:33.441 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i16': use put_i16_be or put_i16_le Nov 17 21:58:33.442 INFO [stderr] --> src/packet.rs:555:22 Nov 17 21:58:33.442 INFO [stderr] | Nov 17 21:58:33.442 INFO [stderr] 555 | into.put_i16::((i16::from(control_type.id_byte())) | (0b1 << 15)); Nov 17 21:58:33.442 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.442 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i16': use put_i16_be or put_i16_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:558:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 558 | into.put_i16::(0); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:561:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 561 | into.put_i32::(control_type.additional_info()); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:564:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 564 | into.put_i32::(*timestamp); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:567:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 567 | into.put_i32::(dest_sockid.0); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:581:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 581 | into.put_i32::(seq_number.0); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:582:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 582 | into.put_i32::( Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:587:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 587 | into.put_i32::(*timestamp); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.452 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:33.452 INFO [stderr] --> src/packet.rs:588:22 Nov 17 21:58:33.452 INFO [stderr] | Nov 17 21:58:33.452 INFO [stderr] 588 | into.put_i32::(dest_sockid.0); Nov 17 21:58:33.452 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.452 INFO [stderr] Nov 17 21:58:33.765 INFO [stderr] warning: field is never used: `local_public` Nov 17 21:58:33.765 INFO [stderr] --> src/pending_connection/rendezvous.rs:10:5 Nov 17 21:58:33.765 INFO [stderr] | Nov 17 21:58:33.765 INFO [stderr] 10 | local_public: SocketAddr, Nov 17 21:58:33.765 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:33.765 INFO [stderr] | Nov 17 21:58:33.765 INFO [stderr] = note: #[warn(dead_code)] on by default Nov 17 21:58:33.765 INFO [stderr] Nov 17 21:58:33.765 INFO [stderr] warning: field is never used: `remote_public` Nov 17 21:58:33.765 INFO [stderr] --> src/pending_connection/rendezvous.rs:11:5 Nov 17 21:58:33.765 INFO [stderr] | Nov 17 21:58:33.765 INFO [stderr] 11 | remote_public: SocketAddr, Nov 17 21:58:33.765 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:33.765 INFO [stderr] Nov 17 21:58:33.765 INFO [stderr] warning: field is never used: `sock` Nov 17 21:58:33.765 INFO [stderr] --> src/pending_connection/rendezvous.rs:12:5 Nov 17 21:58:33.765 INFO [stderr] | Nov 17 21:58:33.765 INFO [stderr] 12 | sock: T, Nov 17 21:58:33.765 INFO [stderr] | ^^^^^^^ Nov 17 21:58:33.765 INFO [stderr] Nov 17 21:58:37.239 INFO [stderr] warning: use of deprecated item 'tokio::executor::current_thread': use tokio-current-thread crate or functions in tokio::runtime::current_thread instead Nov 17 21:58:37.239 INFO [stderr] --> src/bin.rs:18:13 Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] 18 | use tokio::{executor::current_thread, net::{UdpFramed, UdpSocket}}; Nov 17 21:58:37.239 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] = note: #[warn(deprecated)] on by default Nov 17 21:58:37.239 INFO [stderr] Nov 17 21:58:37.239 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:37.239 INFO [stderr] --> src/bin.rs:19:5 Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] 19 | use tokio_io::codec::BytesCodec; Nov 17 21:58:37.239 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:37.239 INFO [stderr] Nov 17 21:58:37.239 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:37.239 INFO [stderr] --> src/bin.rs:89:25 Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] 89 | BytesCodec::new(), Nov 17 21:58:37.239 INFO [stderr] | ^^^^^^^^^^^^^^^ Nov 17 21:58:37.239 INFO [stderr] Nov 17 21:58:37.239 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:37.239 INFO [stderr] --> src/bin.rs:142:21 Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] 142 | BytesCodec::new(), Nov 17 21:58:37.239 INFO [stderr] | ^^^^^^^^^^^^^^^ Nov 17 21:58:37.239 INFO [stderr] Nov 17 21:58:37.239 INFO [stderr] warning: use of deprecated item 'tokio::executor::current_thread::run': use block_on_all instead Nov 17 21:58:37.239 INFO [stderr] --> src/bin.rs:159:5 Nov 17 21:58:37.239 INFO [stderr] | Nov 17 21:58:37.239 INFO [stderr] 159 | current_thread::run(|_| { Nov 17 21:58:37.239 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:37.239 INFO [stderr] Nov 17 21:58:41.128 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 11.80s Nov 17 21:58:41.143 INFO [stderr] su: No module specific data is present Nov 17 21:58:42.344 INFO running `"docker" "inspect" "16533751cbd4ba7c2c19d2ee5513b27e88b9a83e75767b1ad35f299c27475467"` Nov 17 21:58:42.727 INFO running `"docker" "rm" "-f" "16533751cbd4ba7c2c19d2ee5513b27e88b9a83e75767b1ad35f299c27475467"` Nov 17 21:58:42.999 INFO [stdout] 16533751cbd4ba7c2c19d2ee5513b27e88b9a83e75767b1ad35f299c27475467 Nov 17 21:58:43.003 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-7/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 17 21:58:43.545 INFO [stdout] 1e083cc588ebcd14d74671f2c5e8889526750efb709d2712f060303770c61f1b Nov 17 21:58:43.548 INFO running `"docker" "start" "-a" "1e083cc588ebcd14d74671f2c5e8889526750efb709d2712f060303770c61f1b"` Nov 17 21:58:44.479 INFO [stderr] usermod: no changes Nov 17 21:58:44.651 INFO [stderr] Compiling srt-transport v0.2.0 (/source) Nov 17 21:58:47.763 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.763 INFO [stderr] --> src/packet.rs:175:39 Nov 17 21:58:47.763 INFO [stderr] | Nov 17 21:58:47.763 INFO [stderr] 175 | let udt_version = buf.get_i32::(); Nov 17 21:58:47.763 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.763 INFO [stderr] | Nov 17 21:58:47.763 INFO [stderr] = note: #[warn(deprecated)] on by default Nov 17 21:58:47.763 INFO [stderr] Nov 17 21:58:47.763 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.763 INFO [stderr] --> src/packet.rs:176:58 Nov 17 21:58:47.763 INFO [stderr] | Nov 17 21:58:47.763 INFO [stderr] 176 | let sock_type = SocketType::from_i32(buf.get_i32::())?; Nov 17 21:58:47.763 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.764 INFO [stderr] Nov 17 21:58:47.764 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.764 INFO [stderr] --> src/packet.rs:177:50 Nov 17 21:58:47.764 INFO [stderr] | Nov 17 21:58:47.764 INFO [stderr] 177 | let init_seq_num = SeqNumber(buf.get_i32::()); Nov 17 21:58:47.764 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.764 INFO [stderr] Nov 17 21:58:47.764 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.764 INFO [stderr] --> src/packet.rs:178:43 Nov 17 21:58:47.764 INFO [stderr] | Nov 17 21:58:47.764 INFO [stderr] 178 | let max_packet_size = buf.get_i32::(); Nov 17 21:58:47.764 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.764 INFO [stderr] Nov 17 21:58:47.764 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.764 INFO [stderr] --> src/packet.rs:179:41 Nov 17 21:58:47.764 INFO [stderr] | Nov 17 21:58:47.764 INFO [stderr] 179 | let max_flow_size = buf.get_i32::(); Nov 17 21:58:47.764 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.764 INFO [stderr] Nov 17 21:58:47.765 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.765 INFO [stderr] --> src/packet.rs:180:68 Nov 17 21:58:47.765 INFO [stderr] | Nov 17 21:58:47.765 INFO [stderr] 180 | let connection_type = ConnectionType::from_i32(buf.get_i32::())?; Nov 17 21:58:47.765 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.765 INFO [stderr] Nov 17 21:58:47.765 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.765 INFO [stderr] --> src/packet.rs:181:46 Nov 17 21:58:47.765 INFO [stderr] | Nov 17 21:58:47.765 INFO [stderr] 181 | let socket_id = SocketID(buf.get_i32::()); Nov 17 21:58:47.765 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.765 INFO [stderr] Nov 17 21:58:47.765 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.765 INFO [stderr] --> src/packet.rs:182:38 Nov 17 21:58:47.765 INFO [stderr] | Nov 17 21:58:47.765 INFO [stderr] 182 | let syn_cookie = buf.get_i32::(); Nov 17 21:58:47.765 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.765 INFO [stderr] Nov 17 21:58:47.787 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.787 INFO [stderr] --> src/packet.rs:212:48 Nov 17 21:58:47.787 INFO [stderr] | Nov 17 21:58:47.787 INFO [stderr] 212 | let ack_number = SeqNumber(buf.get_i32::()); Nov 17 21:58:47.787 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.787 INFO [stderr] Nov 17 21:58:47.787 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.787 INFO [stderr] --> src/packet.rs:217:34 Nov 17 21:58:47.787 INFO [stderr] | Nov 17 21:58:47.787 INFO [stderr] 217 | Some(buf.get_i32::()) Nov 17 21:58:47.787 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.787 INFO [stderr] Nov 17 21:58:47.787 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.787 INFO [stderr] --> src/packet.rs:245:40 Nov 17 21:58:47.788 INFO [stderr] | Nov 17 21:58:47.788 INFO [stderr] 245 | loss_info.push(buf.get_i32::()); Nov 17 21:58:47.789 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.789 INFO [stderr] Nov 17 21:58:47.803 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.803 INFO [stderr] --> src/packet.rs:295:22 Nov 17 21:58:47.803 INFO [stderr] | Nov 17 21:58:47.803 INFO [stderr] 295 | into.put_i32::(c.udt_version); Nov 17 21:58:47.803 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.803 INFO [stderr] Nov 17 21:58:47.803 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.803 INFO [stderr] --> src/packet.rs:296:22 Nov 17 21:58:47.804 INFO [stderr] | Nov 17 21:58:47.804 INFO [stderr] 296 | into.put_i32::(c.sock_type.to_i32()); Nov 17 21:58:47.804 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.804 INFO [stderr] Nov 17 21:58:47.804 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.804 INFO [stderr] --> src/packet.rs:297:22 Nov 17 21:58:47.804 INFO [stderr] | Nov 17 21:58:47.804 INFO [stderr] 297 | into.put_i32::(c.init_seq_num.0); Nov 17 21:58:47.804 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.804 INFO [stderr] Nov 17 21:58:47.804 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.804 INFO [stderr] --> src/packet.rs:298:22 Nov 17 21:58:47.804 INFO [stderr] | Nov 17 21:58:47.804 INFO [stderr] 298 | into.put_i32::(c.max_packet_size); Nov 17 21:58:47.804 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.804 INFO [stderr] Nov 17 21:58:47.804 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.804 INFO [stderr] --> src/packet.rs:299:22 Nov 17 21:58:47.804 INFO [stderr] | Nov 17 21:58:47.804 INFO [stderr] 299 | into.put_i32::(c.max_flow_size); Nov 17 21:58:47.805 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.805 INFO [stderr] Nov 17 21:58:47.805 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.805 INFO [stderr] --> src/packet.rs:300:22 Nov 17 21:58:47.805 INFO [stderr] | Nov 17 21:58:47.805 INFO [stderr] 300 | into.put_i32::(c.connection_type.to_i32()); Nov 17 21:58:47.805 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.805 INFO [stderr] Nov 17 21:58:47.805 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.805 INFO [stderr] --> src/packet.rs:301:22 Nov 17 21:58:47.805 INFO [stderr] | Nov 17 21:58:47.805 INFO [stderr] 301 | into.put_i32::(c.socket_id.0); Nov 17 21:58:47.805 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.805 INFO [stderr] Nov 17 21:58:47.805 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.805 INFO [stderr] --> src/packet.rs:302:22 Nov 17 21:58:47.805 INFO [stderr] | Nov 17 21:58:47.805 INFO [stderr] 302 | into.put_i32::(c.syn_cookie); Nov 17 21:58:47.805 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.806 INFO [stderr] Nov 17 21:58:47.806 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.806 INFO [stderr] --> src/packet.rs:315:22 Nov 17 21:58:47.806 INFO [stderr] | Nov 17 21:58:47.806 INFO [stderr] 315 | into.put_i32::(c.ack_number.0); Nov 17 21:58:47.806 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.806 INFO [stderr] Nov 17 21:58:47.806 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.806 INFO [stderr] --> src/packet.rs:316:22 Nov 17 21:58:47.806 INFO [stderr] | Nov 17 21:58:47.806 INFO [stderr] 316 | into.put_i32::(c.rtt.unwrap_or(10_000)); Nov 17 21:58:47.806 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.806 INFO [stderr] Nov 17 21:58:47.806 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.806 INFO [stderr] --> src/packet.rs:317:22 Nov 17 21:58:47.806 INFO [stderr] | Nov 17 21:58:47.806 INFO [stderr] 317 | into.put_i32::(c.rtt_variance.unwrap_or(50_000)); Nov 17 21:58:47.806 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.806 INFO [stderr] Nov 17 21:58:47.807 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.807 INFO [stderr] --> src/packet.rs:318:22 Nov 17 21:58:47.807 INFO [stderr] | Nov 17 21:58:47.807 INFO [stderr] 318 | into.put_i32::(c.buffer_available.unwrap_or(8175)); // TODO: better defaults Nov 17 21:58:47.807 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.807 INFO [stderr] Nov 17 21:58:47.807 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.807 INFO [stderr] --> src/packet.rs:319:22 Nov 17 21:58:47.807 INFO [stderr] | Nov 17 21:58:47.807 INFO [stderr] 319 | into.put_i32::(c.packet_recv_rate.unwrap_or(10_000)); Nov 17 21:58:47.807 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.807 INFO [stderr] Nov 17 21:58:47.807 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.807 INFO [stderr] --> src/packet.rs:320:22 Nov 17 21:58:47.807 INFO [stderr] | Nov 17 21:58:47.807 INFO [stderr] 320 | into.put_i32::(c.est_link_cap.unwrap_or(1_000)); Nov 17 21:58:47.807 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.807 INFO [stderr] Nov 17 21:58:47.815 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.815 INFO [stderr] --> src/packet.rs:323:22 Nov 17 21:58:47.815 INFO [stderr] | Nov 17 21:58:47.815 INFO [stderr] 323 | into.put_i32::(loss); Nov 17 21:58:47.815 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.815 INFO [stderr] Nov 17 21:58:47.846 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.846 INFO [stderr] --> src/packet.rs:507:60 Nov 17 21:58:47.846 INFO [stderr] | Nov 17 21:58:47.846 INFO [stderr] 507 | let seq_number = SeqNumber(Cursor::new(first4).get_i32::()); Nov 17 21:58:47.846 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.846 INFO [stderr] Nov 17 21:58:47.847 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.847 INFO [stderr] --> src/packet.rs:510:35 Nov 17 21:58:47.847 INFO [stderr] | Nov 17 21:58:47.847 INFO [stderr] 510 | let second_line = buf.get_i32::(); Nov 17 21:58:47.847 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.847 INFO [stderr] Nov 17 21:58:47.848 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.848 INFO [stderr] --> src/packet.rs:519:33 Nov 17 21:58:47.848 INFO [stderr] | Nov 17 21:58:47.848 INFO [stderr] 519 | let timestamp = buf.get_i32::(); Nov 17 21:58:47.848 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.848 INFO [stderr] Nov 17 21:58:47.849 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.849 INFO [stderr] --> src/packet.rs:520:44 Nov 17 21:58:47.849 INFO [stderr] | Nov 17 21:58:47.849 INFO [stderr] 520 | let dest_sockid = SocketID(buf.get_i32::()); Nov 17 21:58:47.849 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.849 INFO [stderr] Nov 17 21:58:47.849 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.849 INFO [stderr] --> src/packet.rs:534:32 Nov 17 21:58:47.849 INFO [stderr] | Nov 17 21:58:47.849 INFO [stderr] 534 | let add_info = buf.get_i32::(); Nov 17 21:58:47.850 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.850 INFO [stderr] Nov 17 21:58:47.850 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.850 INFO [stderr] --> src/packet.rs:535:33 Nov 17 21:58:47.850 INFO [stderr] | Nov 17 21:58:47.850 INFO [stderr] 535 | let timestamp = buf.get_i32::(); Nov 17 21:58:47.850 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.850 INFO [stderr] Nov 17 21:58:47.851 INFO [stderr] warning: use of deprecated item 'bytes::Buf::get_i32': use get_i32_be or get_i32_le Nov 17 21:58:47.851 INFO [stderr] --> src/packet.rs:536:35 Nov 17 21:58:47.851 INFO [stderr] | Nov 17 21:58:47.851 INFO [stderr] 536 | let dest_sockid = buf.get_i32::(); Nov 17 21:58:47.851 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.851 INFO [stderr] Nov 17 21:58:47.854 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i16': use put_i16_be or put_i16_le Nov 17 21:58:47.854 INFO [stderr] --> src/packet.rs:555:22 Nov 17 21:58:47.854 INFO [stderr] | Nov 17 21:58:47.854 INFO [stderr] 555 | into.put_i16::((i16::from(control_type.id_byte())) | (0b1 << 15)); Nov 17 21:58:47.854 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.854 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i16': use put_i16_be or put_i16_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:558:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 558 | into.put_i16::(0); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:561:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 561 | into.put_i32::(control_type.additional_info()); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:564:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 564 | into.put_i32::(*timestamp); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:567:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 567 | into.put_i32::(dest_sockid.0); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:581:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 581 | into.put_i32::(seq_number.0); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:582:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 582 | into.put_i32::( Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.867 INFO [stderr] Nov 17 21:58:47.867 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.867 INFO [stderr] --> src/packet.rs:587:22 Nov 17 21:58:47.867 INFO [stderr] | Nov 17 21:58:47.867 INFO [stderr] 587 | into.put_i32::(*timestamp); Nov 17 21:58:47.867 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.868 INFO [stderr] Nov 17 21:58:47.868 INFO [stderr] warning: use of deprecated item 'bytes::BufMut::put_i32': use put_i32_be or put_i32_le Nov 17 21:58:47.868 INFO [stderr] --> src/packet.rs:588:22 Nov 17 21:58:47.868 INFO [stderr] | Nov 17 21:58:47.868 INFO [stderr] 588 | into.put_i32::(dest_sockid.0); Nov 17 21:58:47.868 INFO [stderr] | ^^^^^^^ Nov 17 21:58:47.868 INFO [stderr] Nov 17 21:58:48.198 INFO [stderr] warning: unused import: `DefaultReceiverCongestionCtrl` Nov 17 21:58:48.199 INFO [stderr] --> tests/tests.rs:22:31 Nov 17 21:58:48.199 INFO [stderr] | Nov 17 21:58:48.199 INFO [stderr] 22 | use srt::{ConnectionSettings, DefaultReceiverCongestionCtrl, DefaultSenderCongestionCtrl, Nov 17 21:58:48.199 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.199 INFO [stderr] | Nov 17 21:58:48.199 INFO [stderr] = note: #[warn(unused_imports)] on by default Nov 17 21:58:48.199 INFO [stderr] Nov 17 21:58:48.199 INFO [stderr] warning: unused import: `tokio::executor::current_thread` Nov 17 21:58:48.199 INFO [stderr] --> tests/tests.rs:25:5 Nov 17 21:58:48.199 INFO [stderr] | Nov 17 21:58:48.199 INFO [stderr] 25 | use tokio::executor::current_thread; Nov 17 21:58:48.199 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.199 INFO [stderr] Nov 17 21:58:48.199 INFO [stderr] warning: unnecessary parentheses around function argument Nov 17 21:58:48.199 INFO [stderr] --> tests/tests.rs:216:35 Nov 17 21:58:48.199 INFO [stderr] | Nov 17 21:58:48.199 INFO [stderr] 216 | let counting_stream = iter_ok((init_seq_num as u64..(init_seq_num + iters))) Nov 17 21:58:48.199 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ help: remove these parentheses Nov 17 21:58:48.199 INFO [stderr] | Nov 17 21:58:48.199 INFO [stderr] = note: #[warn(unused_parens)] on by default Nov 17 21:58:48.199 INFO [stderr] Nov 17 21:58:48.215 INFO [stderr] warning: use of deprecated item 'tokio::executor::current_thread': use tokio-current-thread crate or functions in tokio::runtime::current_thread instead Nov 17 21:58:48.215 INFO [stderr] --> tests/tests.rs:25:5 Nov 17 21:58:48.215 INFO [stderr] | Nov 17 21:58:48.215 INFO [stderr] 25 | use tokio::executor::current_thread; Nov 17 21:58:48.215 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.215 INFO [stderr] | Nov 17 21:58:48.215 INFO [stderr] = note: #[warn(deprecated)] on by default Nov 17 21:58:48.215 INFO [stderr] Nov 17 21:58:48.329 INFO [stderr] warning: field is never used: `local_public` Nov 17 21:58:48.330 INFO [stderr] --> src/pending_connection/rendezvous.rs:10:5 Nov 17 21:58:48.330 INFO [stderr] | Nov 17 21:58:48.330 INFO [stderr] 10 | local_public: SocketAddr, Nov 17 21:58:48.330 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.330 INFO [stderr] | Nov 17 21:58:48.330 INFO [stderr] = note: #[warn(dead_code)] on by default Nov 17 21:58:48.330 INFO [stderr] Nov 17 21:58:48.330 INFO [stderr] warning: field is never used: `remote_public` Nov 17 21:58:48.330 INFO [stderr] --> src/pending_connection/rendezvous.rs:11:5 Nov 17 21:58:48.330 INFO [stderr] | Nov 17 21:58:48.330 INFO [stderr] 11 | remote_public: SocketAddr, Nov 17 21:58:48.330 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.330 INFO [stderr] Nov 17 21:58:48.330 INFO [stderr] warning: field is never used: `sock` Nov 17 21:58:48.330 INFO [stderr] --> src/pending_connection/rendezvous.rs:12:5 Nov 17 21:58:48.330 INFO [stderr] | Nov 17 21:58:48.330 INFO [stderr] 12 | sock: T, Nov 17 21:58:48.330 INFO [stderr] | ^^^^^^^ Nov 17 21:58:48.330 INFO [stderr] Nov 17 21:58:48.359 INFO [stderr] warning: constant `init_seq_num` should have an upper case name such as `INIT_SEQ_NUM` Nov 17 21:58:48.359 INFO [stderr] --> tests/tests.rs:212:5 Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] 212 | const init_seq_num: u64 = 812731; Nov 17 21:58:48.359 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.359 INFO [stderr] Nov 17 21:58:48.359 INFO [stderr] warning: constant `iters` should have an upper case name such as `ITERS` Nov 17 21:58:48.359 INFO [stderr] --> tests/tests.rs:213:5 Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] 213 | const iters: u64 = 1_000_000; Nov 17 21:58:48.359 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.359 INFO [stderr] Nov 17 21:58:48.359 INFO [stderr] warning: unused `std::result::Result` that must be used Nov 17 21:58:48.359 INFO [stderr] --> tests/tests.rs:253:9 Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] 253 | / counting_stream Nov 17 21:58:48.359 INFO [stderr] 254 | | .forward(sender) Nov 17 21:58:48.359 INFO [stderr] 255 | | .map_err(|e: Error| panic!("{:?}", e)) Nov 17 21:58:48.359 INFO [stderr] 256 | | .map(|_| ()) Nov 17 21:58:48.359 INFO [stderr] 257 | | .wait(); Nov 17 21:58:48.359 INFO [stderr] | |____________________^ Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] = note: #[warn(unused_must_use)] on by default Nov 17 21:58:48.359 INFO [stderr] = note: this `Result` may be an `Err` variant, which should be handled Nov 17 21:58:48.359 INFO [stderr] Nov 17 21:58:48.359 INFO [stderr] warning: unused `std::result::Result` that must be used Nov 17 21:58:48.359 INFO [stderr] --> tests/tests.rs:261:9 Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] 261 | / recvr Nov 17 21:58:48.359 INFO [stderr] 262 | | .forward(CounterChecker { Nov 17 21:58:48.359 INFO [stderr] 263 | | current: init_seq_num, Nov 17 21:58:48.359 INFO [stderr] 264 | | }) Nov 17 21:58:48.359 INFO [stderr] 265 | | .map_err(|e| panic!(e)) Nov 17 21:58:48.359 INFO [stderr] 266 | | .map(move |(_, c)| assert_eq!(c.current, init_seq_num + iters)) Nov 17 21:58:48.359 INFO [stderr] 267 | | .wait(); Nov 17 21:58:48.359 INFO [stderr] | |____________________^ Nov 17 21:58:48.359 INFO [stderr] | Nov 17 21:58:48.359 INFO [stderr] = note: this `Result` may be an `Err` variant, which should be handled Nov 17 21:58:48.360 INFO [stderr] Nov 17 21:58:48.360 INFO [stderr] warning: unused `std::result::Result` that must be used Nov 17 21:58:48.360 INFO [stderr] --> tests/tests.rs:270:5 Nov 17 21:58:48.360 INFO [stderr] | Nov 17 21:58:48.360 INFO [stderr] 270 | t1.join(); Nov 17 21:58:48.360 INFO [stderr] | ^^^^^^^^^^ Nov 17 21:58:48.360 INFO [stderr] | Nov 17 21:58:48.360 INFO [stderr] = note: this `Result` may be an `Err` variant, which should be handled Nov 17 21:58:48.360 INFO [stderr] Nov 17 21:58:48.360 INFO [stderr] warning: unused `std::result::Result` that must be used Nov 17 21:58:48.360 INFO [stderr] --> tests/tests.rs:271:5 Nov 17 21:58:48.360 INFO [stderr] | Nov 17 21:58:48.360 INFO [stderr] 271 | t2.join(); Nov 17 21:58:48.360 INFO [stderr] | ^^^^^^^^^^ Nov 17 21:58:48.360 INFO [stderr] | Nov 17 21:58:48.360 INFO [stderr] = note: this `Result` may be an `Err` variant, which should be handled Nov 17 21:58:48.360 INFO [stderr] Nov 17 21:58:48.398 INFO [stderr] warning: use of deprecated item 'tokio::executor::current_thread': use tokio-current-thread crate or functions in tokio::runtime::current_thread instead Nov 17 21:58:48.399 INFO [stderr] --> src/bin.rs:18:13 Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] 18 | use tokio::{executor::current_thread, net::{UdpFramed, UdpSocket}}; Nov 17 21:58:48.399 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] = note: #[warn(deprecated)] on by default Nov 17 21:58:48.399 INFO [stderr] Nov 17 21:58:48.399 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:48.399 INFO [stderr] --> src/bin.rs:19:5 Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] 19 | use tokio_io::codec::BytesCodec; Nov 17 21:58:48.399 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.399 INFO [stderr] Nov 17 21:58:48.399 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:48.399 INFO [stderr] --> src/bin.rs:89:25 Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] 89 | BytesCodec::new(), Nov 17 21:58:48.399 INFO [stderr] | ^^^^^^^^^^^^^^^ Nov 17 21:58:48.399 INFO [stderr] Nov 17 21:58:48.399 INFO [stderr] warning: use of deprecated item 'tokio_io::codec::BytesCodec': Moved to tokio-codec Nov 17 21:58:48.399 INFO [stderr] --> src/bin.rs:142:21 Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] 142 | BytesCodec::new(), Nov 17 21:58:48.399 INFO [stderr] | ^^^^^^^^^^^^^^^ Nov 17 21:58:48.399 INFO [stderr] Nov 17 21:58:48.399 INFO [stderr] warning: use of deprecated item 'tokio::executor::current_thread::run': use block_on_all instead Nov 17 21:58:48.399 INFO [stderr] --> src/bin.rs:159:5 Nov 17 21:58:48.399 INFO [stderr] | Nov 17 21:58:48.399 INFO [stderr] 159 | current_thread::run(|_| { Nov 17 21:58:48.399 INFO [stderr] | ^^^^^^^^^^^^^^^^^^^ Nov 17 21:58:48.399 INFO [stderr] Nov 17 21:58:50.835 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 6.31s Nov 17 21:58:50.842 INFO [stderr] su: No module specific data is present Nov 17 21:58:51.093 INFO running `"docker" "inspect" "1e083cc588ebcd14d74671f2c5e8889526750efb709d2712f060303770c61f1b"` Nov 17 21:58:51.352 INFO running `"docker" "rm" "-f" "1e083cc588ebcd14d74671f2c5e8889526750efb709d2712f060303770c61f1b"` Nov 17 21:58:51.519 INFO [stdout] 1e083cc588ebcd14d74671f2c5e8889526750efb709d2712f060303770c61f1b Nov 17 21:58:51.523 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-7/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"` Nov 17 21:58:51.899 INFO [stdout] d29dd707fa1bcc649ada7f9e2fb97cdf923f555f93585f7eb54582f8fac30048 Nov 17 21:58:51.901 INFO running `"docker" "start" "-a" "d29dd707fa1bcc649ada7f9e2fb97cdf923f555f93585f7eb54582f8fac30048"` Nov 17 21:58:53.350 INFO [stderr] usermod: no changes Nov 17 21:58:53.555 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 0.17s Nov 17 21:58:53.575 INFO [stderr] Running /target/debug/deps/srt-9bccfc19c18a2646 Nov 17 21:58:53.583 INFO [stdout] Nov 17 21:58:53.583 INFO [stdout] running 5 tests Nov 17 21:58:53.601 INFO [stdout] test seq_number::seq_num_test ... ok Nov 17 21:58:53.601 INFO [stdout] test packet::packet_location_to_i32_test ... ok Nov 17 21:58:53.601 INFO [stdout] test packet::packet_location_from_i32_test ... ok Nov 17 21:58:53.601 INFO [stdout] test loss_compression::loss_compression_test ... ok Nov 17 21:58:53.601 INFO [stdout] test packet::handshake_ser_des_test ... ok Nov 17 21:58:53.601 INFO [stdout] Nov 17 21:58:53.601 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 17 21:58:53.601 INFO [stdout] Nov 17 21:58:53.603 INFO [stderr] Running /target/debug/deps/stransmit_rs-690abfdac31baed6 Nov 17 21:58:53.609 INFO [stdout] Nov 17 21:58:53.609 INFO [stdout] running 0 tests Nov 17 21:58:53.609 INFO [stdout] Nov 17 21:58:53.609 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 17 21:58:53.609 INFO [stdout] Nov 17 21:58:53.613 INFO [stderr] Running /target/debug/deps/tests-aafe9b73919ef1eb Nov 17 21:58:53.613 INFO [stdout] Nov 17 21:58:53.614 INFO [stdout] running 1 test Nov 17 21:58:53.614 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812731 Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812730, buffer=[812731] Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812732 Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812731) Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812731, buffer=[812732] Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812733 Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812732) Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812732, buffer=[812733] Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812734 Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812733) Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812733, buffer=[812734] Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812735 Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812734) Nov 17 21:58:53.619 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812734, buffer=[812735] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812735) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812736), lr_ack_acked=SeqNumber(812731) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 14324, dest_sockid: SocketID(13), control_type: Ack(1, AckControlInfo { ack_number: SeqNumber(812736), rtt: Some(10000), rtt_variance: Some(1000), buffer_available: None, packet_recv_rate: Some(0), est_link_cap: Some(0) }) } Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::default_congestion_ctrl::sender] New window size: 16 Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812736 Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812737), message_loc: Only, in_order_delivery: false, message_number: 6, timestamp: 14795, dest_sockid: SocketID(81), payload: b"812737" }, V4(0.0.0.0:0)) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812735, buffer=[812736] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812738 Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812736) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812737)] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812736, buffer=[812738] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 15886, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812737] }) } Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812737] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812737) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812736, buffer=[812738, 812737] Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812739 Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812737) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812738) Nov 17 21:58:53.631 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812738, buffer=[812739] Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812740 Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812739) Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812739, buffer=[812740] Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812741 Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812741), message_loc: Only, in_order_delivery: false, message_number: 10, timestamp: 27484, dest_sockid: SocketID(81), payload: b"812741" }, V4(0.0.0.0:0)) Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812742 Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812742), message_loc: Only, in_order_delivery: false, message_number: 11, timestamp: 28645, dest_sockid: SocketID(81), payload: b"812742" }, V4(0.0.0.0:0)) Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812743 Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812740) Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812741), SeqNumber(812742)] Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Control { timestamp: 29882, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670907, 812742] }) }, V4(0.0.0.0:0)) Nov 17 21:58:53.643 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812743] Nov 17 21:58:53.647 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812744 Nov 17 21:58:53.647 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812744, 812743] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812745 Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812745, 812744, 812743] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812746 Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812746, 812745, 812744, 812743] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812747 Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812747, 812746, 812745, 812744, 812743] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812748 Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812748), message_loc: Only, in_order_delivery: false, message_number: 17, timestamp: 36144, dest_sockid: SocketID(81), payload: b"812748" }, V4(0.0.0.0:0)) Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812749 Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812748)] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812749, 812747, 812746, 812745, 812744, 812743] Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 37357, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812748] }) } Nov 17 21:58:53.651 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812748] Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812748) Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812749, 812748, 812747, 812746, 812745, 812744, 812743] Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812750 Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812750, 812749, 812748, 812747, 812746, 812745, 812744, 812743] Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812751 Nov 17 21:58:53.655 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812751), message_loc: Only, in_order_delivery: false, message_number: 20, timestamp: 41592, dest_sockid: SocketID(81), payload: b"812751" }, V4(0.0.0.0:0)) Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812752 Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812753), message_loc: Only, in_order_delivery: false, message_number: 22, timestamp: 50391, dest_sockid: SocketID(81), payload: b"812753" }, V4(0.0.0.0:0)) Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812752, 812750, 812749, 812748, 812747, 812746, 812745, 812744, 812743] Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 50495, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) } Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812751] Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812751) Nov 17 21:58:53.665 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812751), message_loc: Only, in_order_delivery: false, message_number: 20, timestamp: 41592, dest_sockid: SocketID(81), payload: b"812751" }, V4(0.0.0.0:0)) Nov 17 21:58:53.678 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812741), lr_ack_acked=SeqNumber(812736) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK with lost packets: ll=[812741, 812742, 812751] [SeqNumber(812741), SeqNumber(812742)] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812741), SeqNumber(812742)] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 61082, dest_sockid: SocketID(13), control_type: Ack(2, AckControlInfo { ack_number: SeqNumber(812741), rtt: Some(8814), rtt_variance: Some(870), buffer_available: None, packet_recv_rate: Some(26977), est_link_cap: Some(0) }) } Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::default_congestion_ctrl::sender] New window size: 16 Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 61147, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670907, 812742] }) } Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812741, 812742] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812741) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812740, buffer=[812752, 812750, 812749, 812748, 812747, 812746, 812745, 812744, 812743, 812741] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812742) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812741) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812741, buffer=[812752, 812750, 812749, 812748, 812747, 812746, 812745, 812744, 812743, 812742] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812754 Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812742) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812743) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812744) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812745) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812746) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812747) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812748) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812749) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Releasing SeqNumber(812750) Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812753)] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812754, 812752] Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 65428, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812753] }) } Nov 17 21:58:53.679 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812753] Nov 17 21:58:53.681 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812753) Nov 17 21:58:53.682 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812754, 812753, 812752] Nov 17 21:58:53.723 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812751), lr_ack_acked=SeqNumber(812741) Nov 17 21:58:53.723 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Control { timestamp: 103538, dest_sockid: SocketID(13), control_type: Ack(3, AckControlInfo { ack_number: SeqNumber(812751), rtt: Some(7764), rtt_variance: Some(765), buffer_available: None, packet_recv_rate: Some(40630), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:53.723 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:53.723 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:53.771 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812751), lr_ack_acked=SeqNumber(812741) Nov 17 21:58:53.771 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Control { timestamp: 145253, dest_sockid: SocketID(13), control_type: Ack(4, AckControlInfo { ack_number: SeqNumber(812751), rtt: Some(7764), rtt_variance: Some(765), buffer_available: None, packet_recv_rate: Some(40630), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:53.771 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:53.771 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:53.771 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Control { timestamp: 145339, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) }, V4(0.0.0.0:0)) Nov 17 21:58:53.876 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 103628, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) } Nov 17 21:58:53.876 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812751] Nov 17 21:58:53.876 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812751) Nov 17 21:58:53.876 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812751), message_loc: Only, in_order_delivery: false, message_number: 20, timestamp: 41592, dest_sockid: SocketID(81), payload: b"812751" }, V4(0.0.0.0:0)) Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812755 Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812751), lr_ack_acked=SeqNumber(812741) Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Control { timestamp: 270489, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) }, V4(0.0.0.0:0)) Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812755, 812754, 812753, 812752] Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 270423, dest_sockid: SocketID(13), control_type: Ack(5, AckControlInfo { ack_number: SeqNumber(812751), rtt: Some(7764), rtt_variance: Some(765), buffer_available: None, packet_recv_rate: Some(40630), est_link_cap: Some(0) }) } Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::default_congestion_ctrl::sender] New window size: 75 Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812751), lr_ack_acked=SeqNumber(812741) Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 270761, dest_sockid: SocketID(13), control_type: Ack(6, AckControlInfo { ack_number: SeqNumber(812751), rtt: Some(7764), rtt_variance: Some(765), buffer_available: None, packet_recv_rate: Some(56485), est_link_cap: Some(0) }) } Nov 17 21:58:53.885 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::default_congestion_ctrl::sender] New window size: 158 Nov 17 21:58:53.892 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812756 Nov 17 21:58:53.893 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812756, 812755, 812754, 812753, 812752] Nov 17 21:58:53.894 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812757 Nov 17 21:58:53.895 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:53.896 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812758 Nov 17 21:58:53.896 INFO [stdout] 2018-11-17 21:58:53 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812758), message_loc: Only, in_order_delivery: false, message_number: 27, timestamp: 283850, dest_sockid: SocketID(81), payload: b"812758" }, V4(0.0.0.0:0)) Nov 17 21:58:53.898 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812759 Nov 17 21:58:53.899 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812758)] Nov 17 21:58:53.899 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812759, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:53.899 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Got packet: Control { timestamp: 286506, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812758] }) } Nov 17 21:58:53.899 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Loss list=[812758] Nov 17 21:58:53.901 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812758) Nov 17 21:58:53.901 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:53.903 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::sender] Sending packet: 812760 Nov 17 21:58:53.904 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] lr=812750, buffer=[812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:53.939 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:53.940 INFO [stdout] 2018-11-17 21:58:53 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:54.029 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 320528, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) } Nov 17 21:58:54.029 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812751] Nov 17 21:58:54.029 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812751) Nov 17 21:58:54.029 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812751), message_loc: Only, in_order_delivery: false, message_number: 20, timestamp: 41592, dest_sockid: SocketID(81), payload: b"812751" }, V4(0.0.0.0:0)) Nov 17 21:58:54.033 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812761 Nov 17 21:58:54.034 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:54.034 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:54.034 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 421214, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.035 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.036 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812762 Nov 17 21:58:54.036 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.038 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812763 Nov 17 21:58:54.039 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.041 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812764 Nov 17 21:58:54.042 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.045 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812765 Nov 17 21:58:54.045 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.049 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812766 Nov 17 21:58:54.049 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.050 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812767 Nov 17 21:58:54.050 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.052 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812768 Nov 17 21:58:54.052 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.053 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.054 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812770 Nov 17 21:58:54.055 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.058 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812771 Nov 17 21:58:54.058 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812771), message_loc: Only, in_order_delivery: false, message_number: 40, timestamp: 444393, dest_sockid: SocketID(81), payload: b"812771" }, V4(0.0.0.0:0)) Nov 17 21:58:54.062 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812772 Nov 17 21:58:54.063 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812771)] Nov 17 21:58:54.063 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812772, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.063 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 447040, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812771] }) } Nov 17 21:58:54.063 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812771] Nov 17 21:58:54.063 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812771) Nov 17 21:58:54.066 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.066 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812773 Nov 17 21:58:54.066 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.075 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812774 Nov 17 21:58:54.075 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.075 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812775 Nov 17 21:58:54.075 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.079 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812776 Nov 17 21:58:54.079 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.082 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812777 Nov 17 21:58:54.082 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.090 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812778 Nov 17 21:58:54.090 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812778), message_loc: Only, in_order_delivery: false, message_number: 47, timestamp: 474290, dest_sockid: SocketID(81), payload: b"812778" }, V4(0.0.0.0:0)) Nov 17 21:58:54.096 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812779 Nov 17 21:58:54.096 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812778)] Nov 17 21:58:54.096 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812779, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.096 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 482460, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812778] }) } Nov 17 21:58:54.096 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812778] Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751, 812778] [SeqNumber(812751)] Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 484296, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812778) Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812780 Nov 17 21:58:54.103 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.107 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812781 Nov 17 21:58:54.107 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.110 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812782 Nov 17 21:58:54.110 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.116 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812783 Nov 17 21:58:54.117 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.118 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812784 Nov 17 21:58:54.123 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812784, 812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.123 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812785, 812784, 812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.123 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812786 Nov 17 21:58:54.124 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812786, 812785, 812784, 812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812787 Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812751] [SeqNumber(812751)] Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812751)] Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812787, 812786, 812785, 812784, 812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752] Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 859707, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812751] }) } Nov 17 21:58:54.475 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812751] Nov 17 21:58:54.487 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812751) Nov 17 21:58:54.487 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812750, buffer=[812787, 812786, 812785, 812784, 812783, 812782, 812781, 812780, 812779, 812778, 812777, 812776, 812775, 812774, 812773, 812772, 812771, 812770, 812769, 812768, 812767, 812766, 812765, 812764, 812763, 812762, 812761, 812760, 812759, 812758, 812757, 812756, 812755, 812754, 812753, 812752, 812751] Nov 17 21:58:54.488 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812788 Nov 17 21:58:54.489 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812751) Nov 17 21:58:54.490 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812752) Nov 17 21:58:54.490 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812753) Nov 17 21:58:54.490 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812754) Nov 17 21:58:54.491 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812755) Nov 17 21:58:54.491 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812756) Nov 17 21:58:54.491 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812757) Nov 17 21:58:54.492 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812758) Nov 17 21:58:54.492 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812759) Nov 17 21:58:54.492 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812760) Nov 17 21:58:54.492 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812761) Nov 17 21:58:54.493 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812762) Nov 17 21:58:54.493 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812763) Nov 17 21:58:54.493 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812764) Nov 17 21:58:54.494 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812765) Nov 17 21:58:54.494 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812766) Nov 17 21:58:54.494 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812767) Nov 17 21:58:54.495 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812768) Nov 17 21:58:54.495 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812769) Nov 17 21:58:54.495 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812770) Nov 17 21:58:54.495 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812771) Nov 17 21:58:54.496 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812772) Nov 17 21:58:54.496 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812773) Nov 17 21:58:54.496 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812774) Nov 17 21:58:54.496 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812775) Nov 17 21:58:54.497 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812776) Nov 17 21:58:54.497 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812777) Nov 17 21:58:54.497 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812778) Nov 17 21:58:54.498 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812779) Nov 17 21:58:54.498 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812780) Nov 17 21:58:54.498 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812781) Nov 17 21:58:54.498 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812782) Nov 17 21:58:54.499 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812783) Nov 17 21:58:54.499 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812784) Nov 17 21:58:54.499 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812785) Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812786) Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812787) Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812787, buffer=[812788] Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812789 Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812788) Nov 17 21:58:54.500 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812788, buffer=[812789] Nov 17 21:58:54.504 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812790 Nov 17 21:58:54.504 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812789) Nov 17 21:58:54.504 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812789, buffer=[812790] Nov 17 21:58:54.505 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812790) Nov 17 21:58:54.505 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812791), lr_ack_acked=SeqNumber(812751) Nov 17 21:58:54.507 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 892255, dest_sockid: SocketID(13), control_type: Ack(7, AckControlInfo { ack_number: SeqNumber(812791), rtt: Some(7079), rtt_variance: Some(2526), buffer_available: None, packet_recv_rate: Some(610795), est_link_cap: Some(0) }) } Nov 17 21:58:54.507 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 256 Nov 17 21:58:54.507 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812791 Nov 17 21:58:54.508 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812790, buffer=[812791] Nov 17 21:58:54.511 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812792 Nov 17 21:58:54.512 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812791) Nov 17 21:58:54.512 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812791, buffer=[812792] Nov 17 21:58:54.515 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812793 Nov 17 21:58:54.515 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812792) Nov 17 21:58:54.515 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812792, buffer=[812793] Nov 17 21:58:54.519 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812794 Nov 17 21:58:54.519 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812794), message_loc: Only, in_order_delivery: false, message_number: 63, timestamp: 906672, dest_sockid: SocketID(81), payload: b"812794" }, V4(0.0.0.0:0)) Nov 17 21:58:54.527 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812795 Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812793) Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812794)] Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812793, buffer=[812795] Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812796 Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 918293, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812794] }) } Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812794] Nov 17 21:58:54.531 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812793, buffer=[812796, 812795] Nov 17 21:58:54.541 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812794) Nov 17 21:58:54.541 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812793, buffer=[812796, 812795, 812794] Nov 17 21:58:54.543 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812794) Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812795) Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812796) Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812797), lr_ack_acked=SeqNumber(812791) Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 930838, dest_sockid: SocketID(13), control_type: Ack(8, AckControlInfo { ack_number: SeqNumber(812797), rtt: Some(6305), rtt_variance: Some(2302), buffer_available: None, packet_recv_rate: Some(771957), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812797 Nov 17 21:58:54.544 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812796, buffer=[812797] Nov 17 21:58:54.555 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812798 Nov 17 21:58:54.559 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812797) Nov 17 21:58:54.559 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812797, buffer=[812798] Nov 17 21:58:54.561 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812799 Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812798) Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812798, buffer=[812799] Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812800 Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812799) Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812799, buffer=[812800] Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812799, buffer=[812801, 812800] Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812802 Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812800) Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812801) Nov 17 21:58:54.571 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812801, buffer=[812802] Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812803 Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812802) Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812803), lr_ack_acked=SeqNumber(812791) Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 968335, dest_sockid: SocketID(13), control_type: Ack(9, AckControlInfo { ack_number: SeqNumber(812803), rtt: Some(6305), rtt_variance: Some(2302), buffer_available: None, packet_recv_rate: Some(916797), est_link_cap: Some(0) }) } Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812802, buffer=[812803] Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.583 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812803) Nov 17 21:58:54.587 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812804 Nov 17 21:58:54.591 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812803, buffer=[812804] Nov 17 21:58:54.592 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812805 Nov 17 21:58:54.592 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812805), message_loc: Only, in_order_delivery: false, message_number: 74, timestamp: 979261, dest_sockid: SocketID(81), payload: b"812805" }, V4(0.0.0.0:0)) Nov 17 21:58:54.597 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812806 Nov 17 21:58:54.599 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812804) Nov 17 21:58:54.599 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.599 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 984558, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.599 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812806] Nov 17 21:58:54.602 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812807 Nov 17 21:58:54.602 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812807, 812806] Nov 17 21:58:54.607 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812808 Nov 17 21:58:54.609 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812808, 812807, 812806] Nov 17 21:58:54.610 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812809 Nov 17 21:58:54.611 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812809, 812808, 812807, 812806] Nov 17 21:58:54.617 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812810 Nov 17 21:58:54.618 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1004731, dest_sockid: SocketID(13), control_type: Ack(10, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(953978), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812805] [SeqNumber(812805)] Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812810, 812809, 812808, 812807, 812806] Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1004808, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) } Nov 17 21:58:54.619 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812805] Nov 17 21:58:54.632 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812805) Nov 17 21:58:54.632 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812805), message_loc: Only, in_order_delivery: false, message_number: 74, timestamp: 979261, dest_sockid: SocketID(81), payload: b"812805" }, V4(0.0.0.0:0)) Nov 17 21:58:54.638 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812811 Nov 17 21:58:54.644 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812811, 812810, 812809, 812808, 812807, 812806] Nov 17 21:58:54.644 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812812 Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812812, 812811, 812810, 812809, 812808, 812807, 812806] Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812813 Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812813, 812812, 812811, 812810, 812809, 812808, 812807, 812806] Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1037561, dest_sockid: SocketID(13), control_type: Ack(11, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(981164), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812805] [SeqNumber(812805)] Nov 17 21:58:54.650 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.651 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1037628, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) } Nov 17 21:58:54.651 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812805] Nov 17 21:58:54.655 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812805) Nov 17 21:58:54.687 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.687 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812805] [SeqNumber(812805)] Nov 17 21:58:54.687 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.723 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.723 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1106468, dest_sockid: SocketID(13), control_type: Ack(13, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(981164), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.723 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812805] [SeqNumber(812805)] Nov 17 21:58:54.724 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.755 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.755 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812805] [SeqNumber(812805)] Nov 17 21:58:54.755 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812805)] Nov 17 21:58:54.791 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812805), lr_ack_acked=SeqNumber(812803) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1072017, dest_sockid: SocketID(13), control_type: Ack(12, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(981164), est_link_cap: Some(0) }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812804, buffer=[812813, 812812, 812811, 812810, 812809, 812808, 812807, 812806, 812805] Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1206532, dest_sockid: SocketID(81), control_type: Ack2(12) }, V4(0.0.0.0:0)) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1072074, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812805] Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1106544, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812805, 812805] Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1140887, dest_sockid: SocketID(13), control_type: Ack(14, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(981164), est_link_cap: Some(0) }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1140946, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812805] }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812805, 812805, 812805] Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1175319, dest_sockid: SocketID(13), control_type: Ack(15, AckControlInfo { ack_number: SeqNumber(812805), rtt: Some(5550), rtt_variance: Some(2234), buffer_available: None, packet_recv_rate: Some(981164), est_link_cap: Some(0) }) } Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812805) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812805) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812806) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812807) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812808) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812809) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812810) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812811) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812812) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812813) Nov 17 21:58:54.821 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Received packet SeqNumber(812805) twice Nov 17 21:58:54.835 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812805) Nov 17 21:58:54.835 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Received packet SeqNumber(812805) twice Nov 17 21:58:54.839 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812805) Nov 17 21:58:54.843 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Received packet SeqNumber(812805) twice Nov 17 21:58:54.863 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812814 Nov 17 21:58:54.863 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812813, buffer=[812814] Nov 17 21:58:54.872 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812815 Nov 17 21:58:54.873 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812814) Nov 17 21:58:54.873 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812814, buffer=[812815] Nov 17 21:58:54.887 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812816 Nov 17 21:58:54.887 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812815) Nov 17 21:58:54.887 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812815, buffer=[812816] Nov 17 21:58:54.887 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812815, buffer=[812817, 812816] Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812818 Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812816) Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812817) Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812817, buffer=[812818] Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812819 Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812818) Nov 17 21:58:54.899 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812818, buffer=[812819] Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812820 Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812819) Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812819, buffer=[812820] Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812820) Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812821), lr_ack_acked=SeqNumber(812805) Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1295824, dest_sockid: SocketID(13), control_type: Ack(16, AckControlInfo { ack_number: SeqNumber(812821), rtt: Some(15464), rtt_variance: Some(16782), buffer_available: None, packet_recv_rate: Some(1179090), est_link_cap: Some(0) }) } Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1296013, dest_sockid: SocketID(81), control_type: Ack2(16) }, V4(0.0.0.0:0)) Nov 17 21:58:54.911 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.919 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812821 Nov 17 21:58:54.923 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812820, buffer=[812821] Nov 17 21:58:54.923 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812822 Nov 17 21:58:54.925 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812821) Nov 17 21:58:54.925 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812821, buffer=[812822] Nov 17 21:58:54.932 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812823 Nov 17 21:58:54.932 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812823), message_loc: Only, in_order_delivery: false, message_number: 92, timestamp: 1319306, dest_sockid: SocketID(81), payload: b"812823" }, V4(0.0.0.0:0)) Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812824 Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812822) Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812823)] Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812822, buffer=[812824] Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1327468, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812823] }) } Nov 17 21:58:54.940 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812823] Nov 17 21:58:54.948 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812823) Nov 17 21:58:54.948 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812822, buffer=[812824, 812823] Nov 17 21:58:54.957 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812825 Nov 17 21:58:54.958 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812825), message_loc: Only, in_order_delivery: false, message_number: 94, timestamp: 1344221, dest_sockid: SocketID(81), payload: b"812825" }, V4(0.0.0.0:0)) Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812826 Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812823) Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Releasing SeqNumber(812824) Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812825)] Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1353590, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812825] }) }, V4(0.0.0.0:0)) Nov 17 21:58:54.966 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812824, buffer=[812826] Nov 17 21:58:54.975 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812827 Nov 17 21:58:54.979 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812824, buffer=[812827, 812826] Nov 17 21:58:54.984 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812828 Nov 17 21:58:54.984 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812824, buffer=[812828, 812827, 812826] Nov 17 21:58:54.994 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Sending packet: 812829 Nov 17 21:58:54.996 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] lr=812824, buffer=[812829, 812828, 812827, 812826] Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812825), lr_ack_acked=SeqNumber(812805) Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK with lost packets: ll=[812825] [SeqNumber(812825)] Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::receiver] Sending NAK for=[SeqNumber(812825)] Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1384603, dest_sockid: SocketID(13), control_type: Ack(17, AckControlInfo { ack_number: SeqNumber(812825), rtt: Some(15464), rtt_variance: Some(16782), buffer_available: None, packet_recv_rate: Some(1305406), est_link_cap: Some(0) }) } Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [tests] Dropping packet: (Control { timestamp: 1384833, dest_sockid: SocketID(81), control_type: Ack2(17) }, V4(0.0.0.0:0)) Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Got packet: Control { timestamp: 1384655, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812825] }) } Nov 17 21:58:54.998 INFO [stdout] 2018-11-17 21:58:54 INFO [srt::sender] Loss list=[812825] Nov 17 21:58:55.004 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812825) Nov 17 21:58:55.005 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812824, buffer=[812829, 812828, 812827, 812826, 812825] Nov 17 21:58:55.014 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812830 Nov 17 21:58:55.015 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812825) Nov 17 21:58:55.015 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812826) Nov 17 21:58:55.015 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812827) Nov 17 21:58:55.015 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812828) Nov 17 21:58:55.015 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812829) Nov 17 21:58:55.016 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812829, buffer=[812830] Nov 17 21:58:55.035 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812831 Nov 17 21:58:55.035 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812831), message_loc: Only, in_order_delivery: false, message_number: 100, timestamp: 1413403, dest_sockid: SocketID(81), payload: b"812831" }, V4(0.0.0.0:0)) Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812832 Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812830) Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK for=[SeqNumber(812831)] Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812830, buffer=[812832] Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812830, buffer=[812833, 812832] Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1425074, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812831] }) } Nov 17 21:58:55.041 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Loss list=[812831] Nov 17 21:58:55.051 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812831) Nov 17 21:58:55.051 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812830, buffer=[812833, 812832, 812831] Nov 17 21:58:55.061 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812834 Nov 17 21:58:55.061 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812831) Nov 17 21:58:55.061 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812832) Nov 17 21:58:55.061 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812833) Nov 17 21:58:55.061 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812833, buffer=[812834] Nov 17 21:58:55.073 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812835 Nov 17 21:58:55.074 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812834) Nov 17 21:58:55.074 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812834, buffer=[812835] Nov 17 21:58:55.091 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812835) Nov 17 21:58:55.091 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812836), lr_ack_acked=SeqNumber(812805) Nov 17 21:58:55.091 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812836 Nov 17 21:58:55.092 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812836), message_loc: Only, in_order_delivery: false, message_number: 105, timestamp: 1473264, dest_sockid: SocketID(81), payload: b"812836" }, V4(0.0.0.0:0)) Nov 17 21:58:55.092 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1473167, dest_sockid: SocketID(13), control_type: Ack(18, AckControlInfo { ack_number: SeqNumber(812836), rtt: Some(15464), rtt_variance: Some(16782), buffer_available: None, packet_recv_rate: Some(1377097), est_link_cap: Some(0) }) } Nov 17 21:58:55.092 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.099 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812837 Nov 17 21:58:55.099 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812837), message_loc: Only, in_order_delivery: false, message_number: 106, timestamp: 1485931, dest_sockid: SocketID(81), payload: b"812837" }, V4(0.0.0.0:0)) Nov 17 21:58:55.215 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812838 Nov 17 21:58:55.215 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK for=[SeqNumber(812836), SeqNumber(812837)] Nov 17 21:58:55.215 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812835, buffer=[812838] Nov 17 21:58:55.215 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1594243, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670812, 812837] }) } Nov 17 21:58:55.215 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Loss list=[812836, 812837] Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812836) Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK with lost packets: ll=[812836, 812837] [SeqNumber(812836), SeqNumber(812837)] Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK for=[SeqNumber(812836), SeqNumber(812837)] Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812835, buffer=[812838, 812836] Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812836) Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1639134, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670812, 812837] }) } Nov 17 21:58:55.253 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Loss list=[812837, 812836, 812837] Nov 17 21:58:55.274 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812837) Nov 17 21:58:55.274 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812836, buffer=[812838, 812837] Nov 17 21:58:55.290 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812836) Nov 17 21:58:55.290 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812836), message_loc: Only, in_order_delivery: false, message_number: 105, timestamp: 1473264, dest_sockid: SocketID(81), payload: b"812836" }, V4(0.0.0.0:0)) Nov 17 21:58:55.311 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812837) Nov 17 21:58:55.311 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812837) Nov 17 21:58:55.311 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812838) Nov 17 21:58:55.311 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Received packet SeqNumber(812837) twice Nov 17 21:58:55.322 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812839 Nov 17 21:58:55.322 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812838, buffer=[812839] Nov 17 21:58:55.329 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812839) Nov 17 21:58:55.329 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812840), lr_ack_acked=SeqNumber(812836) Nov 17 21:58:55.329 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1716416, dest_sockid: SocketID(13), control_type: Ack(19, AckControlInfo { ack_number: SeqNumber(812840), rtt: Some(13559), rtt_variance: Some(16725), buffer_available: None, packet_recv_rate: Some(1484964), est_link_cap: Some(0) }) } Nov 17 21:58:55.329 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.339 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812840 Nov 17 21:58:55.339 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812840), message_loc: Only, in_order_delivery: false, message_number: 109, timestamp: 1725109, dest_sockid: SocketID(81), payload: b"812840" }, V4(0.0.0.0:0)) Nov 17 21:58:55.353 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812841 Nov 17 21:58:55.354 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK for=[SeqNumber(812840)] Nov 17 21:58:55.354 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812839, buffer=[812841] Nov 17 21:58:55.354 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1740787, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812840] }) } Nov 17 21:58:55.354 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Loss list=[812840] Nov 17 21:58:55.369 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812840) Nov 17 21:58:55.369 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812839, buffer=[812841, 812840] Nov 17 21:58:55.391 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812842 Nov 17 21:58:55.391 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812840) Nov 17 21:58:55.391 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812841) Nov 17 21:58:55.391 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812841, buffer=[812842] Nov 17 21:58:55.411 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812842) Nov 17 21:58:55.411 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812843), lr_ack_acked=SeqNumber(812840) Nov 17 21:58:55.479 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812843), lr_ack_acked=SeqNumber(812840) Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1791520, dest_sockid: SocketID(13), control_type: Ack(20, AckControlInfo { ack_number: SeqNumber(812843), rtt: Some(11943), rtt_variance: Some(16567), buffer_available: None, packet_recv_rate: Some(1558707), est_link_cap: Some(0) }) } Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1865846, dest_sockid: SocketID(13), control_type: Ack(21, AckControlInfo { ack_number: SeqNumber(812843), rtt: Some(11943), rtt_variance: Some(16567), buffer_available: None, packet_recv_rate: Some(1558707), est_link_cap: Some(0) }) } Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812843 Nov 17 21:58:55.493 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812842, buffer=[812843] Nov 17 21:58:55.515 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812844 Nov 17 21:58:55.515 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812843) Nov 17 21:58:55.515 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812843, buffer=[812844] Nov 17 21:58:55.530 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812845 Nov 17 21:58:55.535 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812844) Nov 17 21:58:55.535 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812844, buffer=[812845] Nov 17 21:58:55.546 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812846 Nov 17 21:58:55.549 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812845) Nov 17 21:58:55.549 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812845, buffer=[812846] Nov 17 21:58:55.571 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812847 Nov 17 21:58:55.571 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812846) Nov 17 21:58:55.571 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812846, buffer=[812847] Nov 17 21:58:55.587 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812848 Nov 17 21:58:55.587 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812847) Nov 17 21:58:55.587 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812847, buffer=[812848] Nov 17 21:58:55.587 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812847, buffer=[812849, 812848] Nov 17 21:58:55.603 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812850 Nov 17 21:58:55.603 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812848) Nov 17 21:58:55.603 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812849) Nov 17 21:58:55.603 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812849, buffer=[812850] Nov 17 21:58:55.610 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812850) Nov 17 21:58:55.610 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812851), lr_ack_acked=SeqNumber(812843) Nov 17 21:58:55.610 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 1996949, dest_sockid: SocketID(13), control_type: Ack(22, AckControlInfo { ack_number: SeqNumber(812851), rtt: Some(20278), rtt_variance: Some(26861), buffer_available: None, packet_recv_rate: Some(1817410), est_link_cap: Some(0) }) } Nov 17 21:58:55.610 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.619 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812851 Nov 17 21:58:55.619 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812850, buffer=[812851] Nov 17 21:58:55.635 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812852 Nov 17 21:58:55.635 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812851) Nov 17 21:58:55.635 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812851, buffer=[812852] Nov 17 21:58:55.655 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812853 Nov 17 21:58:55.655 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812853), message_loc: Only, in_order_delivery: false, message_number: 122, timestamp: 2038241, dest_sockid: SocketID(81), payload: b"812853" }, V4(0.0.0.0:0)) Nov 17 21:58:55.723 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Releasing SeqNumber(812852) Nov 17 21:58:55.723 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812853), lr_ack_acked=SeqNumber(812851) Nov 17 21:58:55.827 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812853), lr_ack_acked=SeqNumber(812851) Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 2106017, dest_sockid: SocketID(13), control_type: Ack(23, AckControlInfo { ack_number: SeqNumber(812853), rtt: Some(17853), rtt_variance: Some(26641), buffer_available: None, packet_recv_rate: Some(1866983), est_link_cap: Some(0) }) } Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Control { timestamp: 2306515, dest_sockid: SocketID(81), control_type: Ack2(23) }, V4(0.0.0.0:0)) Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 2214058, dest_sockid: SocketID(13), control_type: Ack(24, AckControlInfo { ack_number: SeqNumber(812853), rtt: Some(17853), rtt_variance: Some(26641), buffer_available: None, packet_recv_rate: Some(1866983), est_link_cap: Some(0) }) } Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812854 Nov 17 21:58:55.922 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812854), message_loc: Only, in_order_delivery: false, message_number: 123, timestamp: 2306633, dest_sockid: SocketID(81), payload: b"812854" }, V4(0.0.0.0:0)) Nov 17 21:58:55.952 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet: 812855 Nov 17 21:58:55.952 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] Sending NAK for=[SeqNumber(812853), SeqNumber(812854)] Nov 17 21:58:55.952 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812852, buffer=[812855] Nov 17 21:58:55.952 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Got packet: Control { timestamp: 2336917, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670795, 812854] }) } Nov 17 21:58:55.952 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Loss list=[812853, 812854] Nov 17 21:58:55.968 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812853) Nov 17 21:58:55.968 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::receiver] lr=812852, buffer=[812855, 812853] Nov 17 21:58:55.984 INFO [stdout] 2018-11-17 21:58:55 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812854) Nov 17 21:58:55.984 INFO [stdout] 2018-11-17 21:58:55 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812854), message_loc: Only, in_order_delivery: false, message_number: 123, timestamp: 2306633, dest_sockid: SocketID(81), payload: b"812854" }, V4(0.0.0.0:0)) Nov 17 21:58:56.007 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812856 Nov 17 21:58:56.007 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812853) Nov 17 21:58:56.007 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812853, buffer=[812856, 812855] Nov 17 21:58:56.027 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812857 Nov 17 21:58:56.027 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812853, buffer=[812857, 812856, 812855] Nov 17 21:58:56.043 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812858 Nov 17 21:58:56.043 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812853, buffer=[812858, 812857, 812856, 812855] Nov 17 21:58:56.063 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812859 Nov 17 21:58:56.063 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812853, buffer=[812859, 812858, 812857, 812856, 812855] Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812854), lr_ack_acked=SeqNumber(812853) Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending NAK with lost packets: ll=[812854] [SeqNumber(812854)] Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending NAK for=[SeqNumber(812854)] Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Got packet: Control { timestamp: 2461968, dest_sockid: SocketID(13), control_type: Ack(25, AckControlInfo { ack_number: SeqNumber(812854), rtt: Some(27191), rtt_variance: Some(36460), buffer_available: None, packet_recv_rate: Some(2118633), est_link_cap: Some(0) }) } Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Got packet: Control { timestamp: 2462037, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812854] }) } Nov 17 21:58:56.075 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Loss list=[812854] Nov 17 21:58:56.083 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812854) Nov 17 21:58:56.083 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812853, buffer=[812859, 812858, 812857, 812856, 812855, 812854] Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812860 Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812854) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812855) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812856) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812857) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812858) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812859) Nov 17 21:58:56.103 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812859, buffer=[812860] Nov 17 21:58:56.222 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Releasing SeqNumber(812860) Nov 17 21:58:56.222 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812861), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:56.367 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812861), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:56.367 INFO [stdout] 2018-11-17 21:58:56 INFO [tests] Dropping packet: (Control { timestamp: 2746133, dest_sockid: SocketID(13), control_type: Ack(27, AckControlInfo { ack_number: SeqNumber(812861), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(2192088), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Got packet: Control { timestamp: 2604359, dest_sockid: SocketID(13), control_type: Ack(26, AckControlInfo { ack_number: SeqNumber(812861), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(2192088), est_link_cap: Some(0) }) } Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [tests] Dropping packet: (Control { timestamp: 3165868, dest_sockid: SocketID(81), control_type: Ack2(26) }, V4(0.0.0.0:0)) Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::sender] Sending packet: 812861 Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812861), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [tests] Dropping packet: (Control { timestamp: 3166262, dest_sockid: SocketID(13), control_type: Ack(28, AckControlInfo { ack_number: SeqNumber(812861), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(2192088), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:56.785 INFO [stdout] 2018-11-17 21:58:56 INFO [srt::receiver] lr=812860, buffer=[812861] Nov 17 21:58:57.086 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812862 Nov 17 21:58:57.086 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812861) Nov 17 21:58:57.086 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812862), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:57.087 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812861, buffer=[812862] Nov 17 21:58:57.087 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812862) Nov 17 21:58:57.087 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3473789, dest_sockid: SocketID(13), control_type: Ack(29, AckControlInfo { ack_number: SeqNumber(812862), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(2270158), est_link_cap: Some(0) }) } Nov 17 21:58:57.087 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Control { timestamp: 3474403, dest_sockid: SocketID(81), control_type: Ack2(29) }, V4(0.0.0.0:0)) Nov 17 21:58:57.087 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:57.106 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812863 Nov 17 21:58:57.106 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812862, buffer=[812863] Nov 17 21:58:57.125 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812864 Nov 17 21:58:57.125 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812865), message_loc: Only, in_order_delivery: false, message_number: 134, timestamp: 3512353, dest_sockid: SocketID(81), payload: b"812865" }, V4(0.0.0.0:0)) Nov 17 21:58:57.125 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812863) Nov 17 21:58:57.125 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812863, buffer=[812864] Nov 17 21:58:57.144 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812866 Nov 17 21:58:57.144 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812864) Nov 17 21:58:57.145 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812865)] Nov 17 21:58:57.145 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812866] Nov 17 21:58:57.145 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3531960, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812865] }) } Nov 17 21:58:57.145 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Loss list=[812865] Nov 17 21:58:57.190 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812865) Nov 17 21:58:57.190 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812865), message_loc: Only, in_order_delivery: false, message_number: 134, timestamp: 3512353, dest_sockid: SocketID(81), payload: b"812865" }, V4(0.0.0.0:0)) Nov 17 21:58:57.190 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812867 Nov 17 21:58:57.252 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812867, 812866] Nov 17 21:58:57.252 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812868 Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812868, 812867, 812866] Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812865), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK with lost packets: ll=[812865] [SeqNumber(812865)] Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812865)] Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3596572, dest_sockid: SocketID(13), control_type: Ack(30, AckControlInfo { ack_number: SeqNumber(812865), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(2856638), est_link_cap: Some(0) }) } Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Control { timestamp: 3596836, dest_sockid: SocketID(81), control_type: Ack2(30) }, V4(0.0.0.0:0)) Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3596621, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812865] }) } Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Loss list=[812865] Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812865) Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812865), message_loc: Only, in_order_delivery: false, message_number: 134, timestamp: 3512353, dest_sockid: SocketID(81), payload: b"812865" }, V4(0.0.0.0:0)) Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812869 Nov 17 21:58:57.295 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812869, 812868, 812867, 812866] Nov 17 21:58:57.296 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812870 Nov 17 21:58:57.296 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812870, 812869, 812868, 812867, 812866] Nov 17 21:58:57.343 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812871 Nov 17 21:58:57.343 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812871, 812870, 812869, 812868, 812867, 812866] Nov 17 21:58:57.352 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812865), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:57.352 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Control { timestamp: 3738345, dest_sockid: SocketID(13), control_type: Ack(31, AckControlInfo { ack_number: SeqNumber(812865), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(3127641), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:57.352 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK with lost packets: ll=[812865] [SeqNumber(812865)] Nov 17 21:58:57.352 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812865)] Nov 17 21:58:57.539 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812865), lr_ack_acked=SeqNumber(812854) Nov 17 21:58:57.539 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK with lost packets: ll=[812865] [SeqNumber(812865)] Nov 17 21:58:57.539 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812865)] Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3738420, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812865] }) } Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Loss list=[812865] Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3880100, dest_sockid: SocketID(13), control_type: Ack(32, AckControlInfo { ack_number: SeqNumber(812865), rtt: Some(23854), rtt_variance: Some(36335), buffer_available: None, packet_recv_rate: Some(3127641), est_link_cap: Some(0) }) } Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 3880161, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812865] }) } Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Loss list=[812865, 812865] Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812865) Nov 17 21:58:57.555 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812864, buffer=[812871, 812870, 812869, 812868, 812867, 812866, 812865] Nov 17 21:58:57.599 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812865) Nov 17 21:58:57.599 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812865) Nov 17 21:58:57.599 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812866) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812867) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812868) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812869) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812870) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812871) Nov 17 21:58:57.600 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Received packet SeqNumber(812865) twice Nov 17 21:58:57.658 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812872 Nov 17 21:58:57.658 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812872), message_loc: Only, in_order_delivery: false, message_number: 141, timestamp: 3994639, dest_sockid: SocketID(81), payload: b"812872" }, V4(0.0.0.0:0)) Nov 17 21:58:57.658 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812873 Nov 17 21:58:57.659 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812872)] Nov 17 21:58:57.659 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812871, buffer=[812873] Nov 17 21:58:57.659 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 4026724, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812872] }) } Nov 17 21:58:57.659 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Loss list=[812872] Nov 17 21:58:57.679 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812872) Nov 17 21:58:57.679 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812871, buffer=[812873, 812872] Nov 17 21:58:57.699 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812872) Nov 17 21:58:57.699 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812873) Nov 17 21:58:57.699 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812874), lr_ack_acked=SeqNumber(812865) Nov 17 21:58:57.699 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 4080445, dest_sockid: SocketID(13), control_type: Ack(33, AckControlInfo { ack_number: SeqNumber(812874), rtt: Some(27180), rtt_variance: Some(30784), buffer_available: None, packet_recv_rate: Some(3522163), est_link_cap: Some(0) }) } Nov 17 21:58:57.699 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:57.723 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812874 Nov 17 21:58:57.723 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812873, buffer=[812874] Nov 17 21:58:57.751 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812875 Nov 17 21:58:57.751 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812874) Nov 17 21:58:57.751 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812874, buffer=[812875] Nov 17 21:58:57.782 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812876 Nov 17 21:58:57.782 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812875) Nov 17 21:58:57.782 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812875, buffer=[812876] Nov 17 21:58:57.815 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812877 Nov 17 21:58:57.815 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812877), message_loc: Only, in_order_delivery: false, message_number: 146, timestamp: 4202317, dest_sockid: SocketID(81), payload: b"812877" }, V4(0.0.0.0:0)) Nov 17 21:58:57.847 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Releasing SeqNumber(812876) Nov 17 21:58:57.847 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812877), lr_ack_acked=SeqNumber(812874) Nov 17 21:58:57.915 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Got packet: Control { timestamp: 4234217, dest_sockid: SocketID(13), control_type: Ack(34, AckControlInfo { ack_number: SeqNumber(812877), rtt: Some(24692), rtt_variance: Some(28963), buffer_available: None, packet_recv_rate: Some(3790229), est_link_cap: Some(0) }) } Nov 17 21:58:57.915 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:57.915 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::sender] Sending packet: 812878 Nov 17 21:58:57.923 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] Sending NAK for=[SeqNumber(812877)] Nov 17 21:58:57.923 INFO [stdout] 2018-11-17 21:58:57 INFO [tests] Dropping packet: (Control { timestamp: 4306527, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812877] }) }, V4(0.0.0.0:0)) Nov 17 21:58:57.923 INFO [stdout] 2018-11-17 21:58:57 INFO [srt::receiver] lr=812876, buffer=[812878] Nov 17 21:58:58.084 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK with lost packets: ll=[812877] [SeqNumber(812877)] Nov 17 21:58:58.084 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812877)] Nov 17 21:58:58.155 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 4471283, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812877] }) } Nov 17 21:58:58.155 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812877] Nov 17 21:58:58.155 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812877) Nov 17 21:58:58.155 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812877), message_loc: Only, in_order_delivery: false, message_number: 146, timestamp: 4202317, dest_sockid: SocketID(81), payload: b"812877" }, V4(0.0.0.0:0)) Nov 17 21:58:58.195 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812879 Nov 17 21:58:58.195 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812876, buffer=[812879, 812878] Nov 17 21:58:58.231 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812880 Nov 17 21:58:58.231 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812876, buffer=[812880, 812879, 812878] Nov 17 21:58:58.231 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812876, buffer=[812881, 812880, 812879, 812878] Nov 17 21:58:58.249 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK with lost packets: ll=[812877] [SeqNumber(812877)] Nov 17 21:58:58.250 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812877)] Nov 17 21:58:58.250 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 4636253, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812877] }) } Nov 17 21:58:58.250 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812877] Nov 17 21:58:58.267 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812877) Nov 17 21:58:58.267 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812876, buffer=[812881, 812880, 812879, 812878, 812877] Nov 17 21:58:58.306 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812882 Nov 17 21:58:58.306 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812882), message_loc: Only, in_order_delivery: false, message_number: 151, timestamp: 4693477, dest_sockid: SocketID(81), payload: b"812882" }, V4(0.0.0.0:0)) Nov 17 21:58:58.345 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812883 Nov 17 21:58:58.345 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812877) Nov 17 21:58:58.345 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812878) Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812879) Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812880) Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812881) Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812882)] Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812881, buffer=[812883] Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 4732927, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812882] }) } Nov 17 21:58:58.346 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812882] Nov 17 21:58:58.384 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812882) Nov 17 21:58:58.387 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812881, buffer=[812883, 812882] Nov 17 21:58:58.414 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812882) Nov 17 21:58:58.415 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812883) Nov 17 21:58:58.415 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812884), lr_ack_acked=SeqNumber(812877) Nov 17 21:58:58.415 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 4801146, dest_sockid: SocketID(13), control_type: Ack(35, AckControlInfo { ack_number: SeqNumber(812884), rtt: Some(30607), rtt_variance: Some(32485), buffer_available: None, packet_recv_rate: Some(4254180), est_link_cap: Some(0) }) } Nov 17 21:58:58.415 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:58.434 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812884 Nov 17 21:58:58.434 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812884), message_loc: Only, in_order_delivery: false, message_number: 153, timestamp: 4821503, dest_sockid: SocketID(81), payload: b"812884" }, V4(0.0.0.0:0)) Nov 17 21:58:58.483 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812885 Nov 17 21:58:58.483 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812884)] Nov 17 21:58:58.483 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Control { timestamp: 4870037, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812884] }) }, V4(0.0.0.0:0)) Nov 17 21:58:58.483 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812883, buffer=[812885] Nov 17 21:58:58.535 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812886 Nov 17 21:58:58.535 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812883, buffer=[812886, 812885] Nov 17 21:58:58.568 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK with lost packets: ll=[812884] [SeqNumber(812884)] Nov 17 21:58:58.568 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812884)] Nov 17 21:58:58.575 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 4954226, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812884] }) } Nov 17 21:58:58.575 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812884] Nov 17 21:58:58.579 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812884) Nov 17 21:58:58.581 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812883, buffer=[812886, 812885, 812884] Nov 17 21:58:58.630 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812887 Nov 17 21:58:58.632 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812884) Nov 17 21:58:58.632 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812885) Nov 17 21:58:58.632 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812886) Nov 17 21:58:58.632 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812886, buffer=[812887] Nov 17 21:58:58.688 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812888 Nov 17 21:58:58.688 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812888), message_loc: Only, in_order_delivery: false, message_number: 157, timestamp: 5070830, dest_sockid: SocketID(81), payload: b"812888" }, V4(0.0.0.0:0)) Nov 17 21:58:58.719 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Releasing SeqNumber(812887) Nov 17 21:58:58.719 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812888), lr_ack_acked=SeqNumber(812884) Nov 17 21:58:58.723 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 5106271, dest_sockid: SocketID(13), control_type: Ack(36, AckControlInfo { ack_number: SeqNumber(812888), rtt: Some(26806), rtt_variance: Some(32433), buffer_available: None, packet_recv_rate: Some(4534770), est_link_cap: Some(0) }) } Nov 17 21:58:58.723 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:58.738 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812889 Nov 17 21:58:58.738 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812888)] Nov 17 21:58:58.738 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Control { timestamp: 5124043, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812888] }) }, V4(0.0.0.0:0)) Nov 17 21:58:58.738 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812887, buffer=[812889] Nov 17 21:58:58.792 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812890 Nov 17 21:58:58.793 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812887, buffer=[812890, 812889] Nov 17 21:58:58.838 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812891 Nov 17 21:58:58.839 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812887, buffer=[812891, 812890, 812889] Nov 17 21:58:58.863 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK with lost packets: ll=[812888] [SeqNumber(812888)] Nov 17 21:58:58.863 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812888)] Nov 17 21:58:58.863 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 5246241, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812888] }) } Nov 17 21:58:58.863 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812888] Nov 17 21:58:58.891 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812888) Nov 17 21:58:58.891 INFO [stdout] 2018-11-17 21:58:58 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812888), message_loc: Only, in_order_delivery: false, message_number: 157, timestamp: 5070830, dest_sockid: SocketID(81), payload: b"812888" }, V4(0.0.0.0:0)) Nov 17 21:58:58.945 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Sending packet: 812892 Nov 17 21:58:58.947 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] lr=812887, buffer=[812892, 812891, 812890, 812889] Nov 17 21:58:58.995 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK with lost packets: ll=[812888] [SeqNumber(812888)] Nov 17 21:58:58.995 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::receiver] Sending NAK for=[SeqNumber(812888)] Nov 17 21:58:58.995 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Got packet: Control { timestamp: 5382365, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812888] }) } Nov 17 21:58:58.995 INFO [stdout] 2018-11-17 21:58:58 INFO [srt::sender] Loss list=[812888] Nov 17 21:58:59.009 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812888) Nov 17 21:58:59.009 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812887, buffer=[812892, 812891, 812890, 812889, 812888] Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812893 Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812888) Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812889) Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812890) Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812891) Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812892) Nov 17 21:58:59.081 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812892, buffer=[812893] Nov 17 21:58:59.133 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812893) Nov 17 21:58:59.133 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812894), lr_ack_acked=SeqNumber(812888) Nov 17 21:58:59.144 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Got packet: Control { timestamp: 5519218, dest_sockid: SocketID(13), control_type: Ack(37, AckControlInfo { ack_number: SeqNumber(812894), rtt: Some(23744), rtt_variance: Some(31854), buffer_available: None, packet_recv_rate: Some(4967095), est_link_cap: Some(0) }) } Nov 17 21:58:59.144 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:59.144 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812894 Nov 17 21:58:59.145 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812893, buffer=[812894] Nov 17 21:58:59.250 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812895 Nov 17 21:58:59.255 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812894) Nov 17 21:58:59.255 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812894, buffer=[812895] Nov 17 21:58:59.279 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812895) Nov 17 21:58:59.279 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812896), lr_ack_acked=SeqNumber(812894) Nov 17 21:58:59.279 INFO [stdout] 2018-11-17 21:58:59 INFO [tests] Dropping packet: (Control { timestamp: 5660170, dest_sockid: SocketID(13), control_type: Ack(38, AckControlInfo { ack_number: SeqNumber(812896), rtt: Some(22357), rtt_variance: Some(28692), buffer_available: None, packet_recv_rate: Some(5090506), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:59.311 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812896 Nov 17 21:58:59.311 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812895, buffer=[812896] Nov 17 21:58:59.312 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812896) Nov 17 21:58:59.312 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812896, buffer=[812897] Nov 17 21:58:59.375 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812898 Nov 17 21:58:59.376 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812897) Nov 17 21:58:59.376 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812897, buffer=[812898] Nov 17 21:58:59.402 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812898) Nov 17 21:58:59.402 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812899), lr_ack_acked=SeqNumber(812894) Nov 17 21:58:59.402 INFO [stdout] 2018-11-17 21:58:59 INFO [tests] Dropping packet: (Control { timestamp: 5789239, dest_sockid: SocketID(13), control_type: Ack(39, AckControlInfo { ack_number: SeqNumber(812899), rtt: Some(22357), rtt_variance: Some(28692), buffer_available: None, packet_recv_rate: Some(5287756), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:59.436 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812899 Nov 17 21:58:59.442 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812898, buffer=[812899] Nov 17 21:58:59.496 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812900 Nov 17 21:58:59.499 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812899) Nov 17 21:58:59.499 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812899, buffer=[812900] Nov 17 21:58:59.539 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812900) Nov 17 21:58:59.539 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812901), lr_ack_acked=SeqNumber(812894) Nov 17 21:58:59.546 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Got packet: Control { timestamp: 5926369, dest_sockid: SocketID(13), control_type: Ack(40, AckControlInfo { ack_number: SeqNumber(812901), rtt: Some(22357), rtt_variance: Some(28692), buffer_available: None, packet_recv_rate: Some(5417226), est_link_cap: Some(0) }) } Nov 17 21:58:59.546 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:59.559 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812901 Nov 17 21:58:59.559 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812900, buffer=[812901] Nov 17 21:58:59.616 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812902 Nov 17 21:58:59.616 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812901) Nov 17 21:58:59.616 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812901, buffer=[812902] Nov 17 21:58:59.667 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812902) Nov 17 21:58:59.668 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812903), lr_ack_acked=SeqNumber(812901) Nov 17 21:58:59.671 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Got packet: Control { timestamp: 6054267, dest_sockid: SocketID(13), control_type: Ack(41, AckControlInfo { ack_number: SeqNumber(812903), rtt: Some(20428), rtt_variance: Some(26960), buffer_available: None, packet_recv_rate: Some(5546352), est_link_cap: Some(0) }) } Nov 17 21:58:59.671 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:59.672 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812903 Nov 17 21:58:59.679 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812902, buffer=[812903] Nov 17 21:58:59.726 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812904 Nov 17 21:58:59.726 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812903) Nov 17 21:58:59.726 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812903, buffer=[812904] Nov 17 21:58:59.781 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812905 Nov 17 21:58:59.784 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812904) Nov 17 21:58:59.784 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812904, buffer=[812905] Nov 17 21:58:59.790 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812905) Nov 17 21:58:59.790 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812906), lr_ack_acked=SeqNumber(812903) Nov 17 21:58:59.790 INFO [stdout] 2018-11-17 21:58:59 INFO [tests] Dropping packet: (Control { timestamp: 6177669, dest_sockid: SocketID(13), control_type: Ack(42, AckControlInfo { ack_number: SeqNumber(812906), rtt: Some(19358), rtt_variance: Some(23992), buffer_available: None, packet_recv_rate: Some(5735928), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:58:59.835 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812906 Nov 17 21:58:59.835 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812905, buffer=[812906] Nov 17 21:58:59.888 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812907 Nov 17 21:58:59.888 INFO [stdout] 2018-11-17 21:58:59 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812907), message_loc: Only, in_order_delivery: false, message_number: 176, timestamp: 6275828, dest_sockid: SocketID(81), payload: b"812907" }, V4(0.0.0.0:0)) Nov 17 21:58:59.902 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Releasing SeqNumber(812906) Nov 17 21:58:59.902 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812907), lr_ack_acked=SeqNumber(812903) Nov 17 21:58:59.902 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Got packet: Control { timestamp: 6289590, dest_sockid: SocketID(13), control_type: Ack(43, AckControlInfo { ack_number: SeqNumber(812907), rtt: Some(19358), rtt_variance: Some(23992), buffer_available: None, packet_recv_rate: Some(5798235), est_link_cap: Some(0) }) } Nov 17 21:58:59.902 INFO [stdout] 2018-11-17 21:58:59 INFO [tests] Dropping packet: (Control { timestamp: 6289774, dest_sockid: SocketID(81), control_type: Ack2(43) }, V4(0.0.0.0:0)) Nov 17 21:58:59.902 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:58:59.942 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet: 812908 Nov 17 21:58:59.942 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] Sending NAK for=[SeqNumber(812907)] Nov 17 21:58:59.942 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812906, buffer=[812908] Nov 17 21:58:59.943 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Got packet: Control { timestamp: 6329874, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812907] }) } Nov 17 21:58:59.943 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Loss list=[812907] Nov 17 21:58:59.994 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812907) Nov 17 21:58:59.995 INFO [stdout] 2018-11-17 21:58:59 INFO [srt::receiver] lr=812906, buffer=[812908, 812907] Nov 17 21:59:00.016 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812907) Nov 17 21:59:00.016 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812908) Nov 17 21:59:00.018 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812909), lr_ack_acked=SeqNumber(812903) Nov 17 21:59:00.051 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6405363, dest_sockid: SocketID(13), control_type: Ack(44, AckControlInfo { ack_number: SeqNumber(812909), rtt: Some(19358), rtt_variance: Some(23992), buffer_available: None, packet_recv_rate: Some(5922053), est_link_cap: Some(0) }) } Nov 17 21:59:00.051 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.052 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812909 Nov 17 21:59:00.052 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812908, buffer=[812909] Nov 17 21:59:00.106 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812910 Nov 17 21:59:00.106 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812909) Nov 17 21:59:00.106 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812909, buffer=[812910] Nov 17 21:59:00.160 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812911 Nov 17 21:59:00.160 INFO [stdout] 2018-11-17 21:59:00 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812911), message_loc: Only, in_order_delivery: false, message_number: 180, timestamp: 6547594, dest_sockid: SocketID(81), payload: b"812911" }, V4(0.0.0.0:0)) Nov 17 21:59:00.167 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812910) Nov 17 21:59:00.167 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812911), lr_ack_acked=SeqNumber(812909) Nov 17 21:59:00.168 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6554698, dest_sockid: SocketID(13), control_type: Ack(45, AckControlInfo { ack_number: SeqNumber(812911), rtt: Some(21182), rtt_variance: Some(20484), buffer_available: None, packet_recv_rate: Some(6042895), est_link_cap: Some(0) }) } Nov 17 21:59:00.168 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.214 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812912 Nov 17 21:59:00.215 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending NAK for=[SeqNumber(812911)] Nov 17 21:59:00.215 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812910, buffer=[812912] Nov 17 21:59:00.215 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812910, buffer=[812913, 812912] Nov 17 21:59:00.215 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6601958, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812911] }) } Nov 17 21:59:00.215 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Loss list=[812911] Nov 17 21:59:00.267 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812911) Nov 17 21:59:00.267 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812910, buffer=[812913, 812912, 812911] Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812911) Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812912) Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812913) Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812914), lr_ack_acked=SeqNumber(812911) Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6660323, dest_sockid: SocketID(13), control_type: Ack(46, AckControlInfo { ack_number: SeqNumber(812914), rtt: Some(18609), rtt_variance: Some(20333), buffer_available: None, packet_recv_rate: Some(6219007), est_link_cap: Some(0) }) } Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [tests] Dropping packet: (Control { timestamp: 6660622, dest_sockid: SocketID(81), control_type: Ack2(46) }, V4(0.0.0.0:0)) Nov 17 21:59:00.273 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.351 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812914 Nov 17 21:59:00.351 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812913, buffer=[812914] Nov 17 21:59:00.378 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812914) Nov 17 21:59:00.378 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812915), lr_ack_acked=SeqNumber(812911) Nov 17 21:59:00.378 INFO [stdout] 2018-11-17 21:59:00 INFO [tests] Dropping packet: (Control { timestamp: 6765174, dest_sockid: SocketID(13), control_type: Ack(47, AckControlInfo { ack_number: SeqNumber(812915), rtt: Some(18609), rtt_variance: Some(20333), buffer_available: None, packet_recv_rate: Some(6279918), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:59:00.407 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812915 Nov 17 21:59:00.407 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812914, buffer=[812915] Nov 17 21:59:00.462 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812916 Nov 17 21:59:00.462 INFO [stdout] 2018-11-17 21:59:00 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812916), message_loc: Only, in_order_delivery: false, message_number: 185, timestamp: 6849457, dest_sockid: SocketID(81), payload: b"812916" }, V4(0.0.0.0:0)) Nov 17 21:59:00.484 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812915) Nov 17 21:59:00.484 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812916), lr_ack_acked=SeqNumber(812911) Nov 17 21:59:00.484 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6871606, dest_sockid: SocketID(13), control_type: Ack(48, AckControlInfo { ack_number: SeqNumber(812916), rtt: Some(18609), rtt_variance: Some(20333), buffer_available: None, packet_recv_rate: Some(6340237), est_link_cap: Some(0) }) } Nov 17 21:59:00.484 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.517 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812917 Nov 17 21:59:00.518 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending NAK for=[SeqNumber(812916)] Nov 17 21:59:00.518 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812915, buffer=[812917] Nov 17 21:59:00.518 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6904991, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812916] }) } Nov 17 21:59:00.518 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Loss list=[812916] Nov 17 21:59:00.575 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812916) Nov 17 21:59:00.575 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812915, buffer=[812917, 812916] Nov 17 21:59:00.586 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812916) Nov 17 21:59:00.587 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812917) Nov 17 21:59:00.587 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812918), lr_ack_acked=SeqNumber(812916) Nov 17 21:59:00.599 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 6974005, dest_sockid: SocketID(13), control_type: Ack(49, AckControlInfo { ack_number: SeqNumber(812918), rtt: Some(16379), rtt_variance: Some(20140), buffer_available: None, packet_recv_rate: Some(6467379), est_link_cap: Some(0) }) } Nov 17 21:59:00.599 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.639 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812918 Nov 17 21:59:00.639 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812917, buffer=[812918] Nov 17 21:59:00.686 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812918) Nov 17 21:59:00.686 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812919), lr_ack_acked=SeqNumber(812918) Nov 17 21:59:00.687 INFO [stdout] 2018-11-17 21:59:00 INFO [tests] Dropping packet: (Control { timestamp: 7074323, dest_sockid: SocketID(13), control_type: Ack(50, AckControlInfo { ack_number: SeqNumber(812919), rtt: Some(15346), rtt_variance: Some(18110), buffer_available: None, packet_recv_rate: Some(6531075), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:59:00.690 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812919 Nov 17 21:59:00.690 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812918, buffer=[812919] Nov 17 21:59:00.745 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812920 Nov 17 21:59:00.745 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812919) Nov 17 21:59:00.745 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812919, buffer=[812920] Nov 17 21:59:00.775 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812920) Nov 17 21:59:00.775 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812921), lr_ack_acked=SeqNumber(812918) Nov 17 21:59:00.775 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 7162236, dest_sockid: SocketID(13), control_type: Ack(51, AckControlInfo { ack_number: SeqNumber(812921), rtt: Some(15346), rtt_variance: Some(18110), buffer_available: None, packet_recv_rate: Some(6657966), est_link_cap: Some(0) }) } Nov 17 21:59:00.775 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.803 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812921 Nov 17 21:59:00.815 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812920, buffer=[812921] Nov 17 21:59:00.857 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812921) Nov 17 21:59:00.857 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812922), lr_ack_acked=SeqNumber(812921) Nov 17 21:59:00.939 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 7244570, dest_sockid: SocketID(13), control_type: Ack(52, AckControlInfo { ack_number: SeqNumber(812922), rtt: Some(13453), rtt_variance: Some(18058), buffer_available: None, packet_recv_rate: Some(6722161), est_link_cap: Some(0) }) } Nov 17 21:59:00.939 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.939 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812922 Nov 17 21:59:00.943 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812922), lr_ack_acked=SeqNumber(812921) Nov 17 21:59:00.943 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812921, buffer=[812922] Nov 17 21:59:00.943 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] Releasing SeqNumber(812922) Nov 17 21:59:00.956 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Got packet: Control { timestamp: 7330178, dest_sockid: SocketID(13), control_type: Ack(53, AckControlInfo { ack_number: SeqNumber(812922), rtt: Some(13453), rtt_variance: Some(18058), buffer_available: None, packet_recv_rate: Some(6722161), est_link_cap: Some(0) }) } Nov 17 21:59:00.956 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:00.988 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::sender] Sending packet: 812923 Nov 17 21:59:00.988 INFO [stdout] 2018-11-17 21:59:00 INFO [srt::receiver] lr=812922, buffer=[812923] Nov 17 21:59:01.039 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812924 Nov 17 21:59:01.040 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812923) Nov 17 21:59:01.040 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812923, buffer=[812924] Nov 17 21:59:01.078 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812924) Nov 17 21:59:01.078 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812925), lr_ack_acked=SeqNumber(812922) Nov 17 21:59:01.079 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Got packet: Control { timestamp: 7466066, dest_sockid: SocketID(13), control_type: Ack(54, AckControlInfo { ack_number: SeqNumber(812925), rtt: Some(21272), rtt_variance: Some(27223), buffer_available: None, packet_recv_rate: Some(6922091), est_link_cap: Some(0) }) } Nov 17 21:59:01.079 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:01.086 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812925 Nov 17 21:59:01.087 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812924, buffer=[812925] Nov 17 21:59:01.135 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812926 Nov 17 21:59:01.139 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812925) Nov 17 21:59:01.139 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812925, buffer=[812926] Nov 17 21:59:01.180 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812927 Nov 17 21:59:01.180 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812926) Nov 17 21:59:01.181 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812926, buffer=[812927] Nov 17 21:59:01.197 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812927) Nov 17 21:59:01.197 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812928), lr_ack_acked=SeqNumber(812925) Nov 17 21:59:01.197 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Got packet: Control { timestamp: 7584306, dest_sockid: SocketID(13), control_type: Ack(55, AckControlInfo { ack_number: SeqNumber(812928), rtt: Some(19241), rtt_variance: Some(25966), buffer_available: None, packet_recv_rate: Some(7111656), est_link_cap: Some(0) }) } Nov 17 21:59:01.198 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:01.227 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812928 Nov 17 21:59:01.227 INFO [stdout] 2018-11-17 21:59:01 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812928), message_loc: Only, in_order_delivery: false, message_number: 197, timestamp: 7614398, dest_sockid: SocketID(81), payload: b"812928" }, V4(0.0.0.0:0)) Nov 17 21:59:01.228 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending NAK for=[SeqNumber(812928)] Nov 17 21:59:01.228 INFO [stdout] 2018-11-17 21:59:01 INFO [tests] Dropping packet: (Control { timestamp: 7615021, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812928] }) }, V4(0.0.0.0:0)) Nov 17 21:59:01.228 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812927, buffer=[812929] Nov 17 21:59:01.271 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812930 Nov 17 21:59:01.271 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812927, buffer=[812930, 812929] Nov 17 21:59:01.305 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending NAK with lost packets: ll=[812928] [SeqNumber(812928)] Nov 17 21:59:01.305 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending NAK for=[SeqNumber(812928)] Nov 17 21:59:01.313 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812931 Nov 17 21:59:01.315 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812927, buffer=[812931, 812930, 812929] Nov 17 21:59:01.317 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Got packet: Control { timestamp: 7692100, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812928] }) } Nov 17 21:59:01.317 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Loss list=[812928] Nov 17 21:59:01.357 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812928) Nov 17 21:59:01.359 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812927, buffer=[812931, 812930, 812929, 812928] Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812928) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812929) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812930) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812931) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812932), lr_ack_acked=SeqNumber(812928) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [tests] Dropping packet: (Control { timestamp: 7792213, dest_sockid: SocketID(13), control_type: Ack(56, AckControlInfo { ack_number: SeqNumber(812932), rtt: Some(16927), rtt_variance: Some(25783), buffer_available: None, packet_recv_rate: Some(7357468), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812932 Nov 17 21:59:01.405 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812931, buffer=[812932] Nov 17 21:59:01.454 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812933 Nov 17 21:59:01.454 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812932) Nov 17 21:59:01.454 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812932, buffer=[812933] Nov 17 21:59:01.503 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812934 Nov 17 21:59:01.503 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812933) Nov 17 21:59:01.503 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812933, buffer=[812934] Nov 17 21:59:01.511 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812934) Nov 17 21:59:01.511 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812935), lr_ack_acked=SeqNumber(812928) Nov 17 21:59:01.511 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Got packet: Control { timestamp: 7895693, dest_sockid: SocketID(13), control_type: Ack(57, AckControlInfo { ack_number: SeqNumber(812935), rtt: Some(16927), rtt_variance: Some(25783), buffer_available: None, packet_recv_rate: Some(7522148), est_link_cap: Some(0) }) } Nov 17 21:59:01.511 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:01.551 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812935 Nov 17 21:59:01.559 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812934, buffer=[812935] Nov 17 21:59:01.598 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812936 Nov 17 21:59:01.598 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812935) Nov 17 21:59:01.598 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] lr=812935, buffer=[812936] Nov 17 21:59:01.605 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Releasing SeqNumber(812936) Nov 17 21:59:01.605 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812937), lr_ack_acked=SeqNumber(812935) Nov 17 21:59:01.605 INFO [stdout] 2018-11-17 21:59:01 INFO [tests] Dropping packet: (Control { timestamp: 7991306, dest_sockid: SocketID(13), control_type: Ack(58, AckControlInfo { ack_number: SeqNumber(812937), rtt: Some(14850), rtt_variance: Some(25704), buffer_available: None, packet_recv_rate: Some(7629452), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:59:01.915 INFO [stdout] 2018-11-17 21:59:01 INFO [srt::sender] Sending packet: 812937 Nov 17 21:59:01.915 INFO [stdout] 2018-11-17 21:59:01 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812937), message_loc: Only, in_order_delivery: false, message_number: 206, timestamp: 8302301, dest_sockid: SocketID(81), payload: b"812937" }, V4(0.0.0.0:0)) Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812938 Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812937), lr_ack_acked=SeqNumber(812935) Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending NAK for=[SeqNumber(812937)] Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812936, buffer=[812938] Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8430357, dest_sockid: SocketID(13), control_type: Ack(59, AckControlInfo { ack_number: SeqNumber(812937), rtt: Some(14850), rtt_variance: Some(25704), buffer_available: None, packet_recv_rate: Some(7629452), est_link_cap: Some(0) }) } Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8430424, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812937] }) } Nov 17 21:59:02.047 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Loss list=[812937] Nov 17 21:59:02.095 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812937) Nov 17 21:59:02.095 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812936, buffer=[812938, 812937] Nov 17 21:59:02.135 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812937) Nov 17 21:59:02.135 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812938) Nov 17 21:59:02.135 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812939), lr_ack_acked=SeqNumber(812937) Nov 17 21:59:02.223 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812939), lr_ack_acked=SeqNumber(812937) Nov 17 21:59:02.311 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812939), lr_ack_acked=SeqNumber(812937) Nov 17 21:59:02.394 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812939), lr_ack_acked=SeqNumber(812937) Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8518600, dest_sockid: SocketID(13), control_type: Ack(60, AckControlInfo { ack_number: SeqNumber(812939), rtt: Some(13034), rtt_variance: Some(25622), buffer_available: None, packet_recv_rate: Some(7778415), est_link_cap: Some(0) }) } Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8606327, dest_sockid: SocketID(13), control_type: Ack(61, AckControlInfo { ack_number: SeqNumber(812939), rtt: Some(13034), rtt_variance: Some(25622), buffer_available: None, packet_recv_rate: Some(7778415), est_link_cap: Some(0) }) } Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8694163, dest_sockid: SocketID(13), control_type: Ack(62, AckControlInfo { ack_number: SeqNumber(812939), rtt: Some(13034), rtt_variance: Some(25622), buffer_available: None, packet_recv_rate: Some(7778415), est_link_cap: Some(0) }) } Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [tests] Dropping packet: (Control { timestamp: 8884721, dest_sockid: SocketID(81), control_type: Ack2(62) }, V4(0.0.0.0:0)) Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8781910, dest_sockid: SocketID(13), control_type: Ack(63, AckControlInfo { ack_number: SeqNumber(812939), rtt: Some(13034), rtt_variance: Some(25622), buffer_available: None, packet_recv_rate: Some(7778415), est_link_cap: Some(0) }) } Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812939 Nov 17 21:59:02.498 INFO [stdout] 2018-11-17 21:59:02 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812939), message_loc: Only, in_order_delivery: false, message_number: 208, timestamp: 8884824, dest_sockid: SocketID(81), payload: b"812939" }, V4(0.0.0.0:0)) Nov 17 21:59:02.503 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812939), lr_ack_acked=SeqNumber(812937) Nov 17 21:59:02.503 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8890597, dest_sockid: SocketID(13), control_type: Ack(64, AckControlInfo { ack_number: SeqNumber(812939), rtt: Some(13034), rtt_variance: Some(25622), buffer_available: None, packet_recv_rate: Some(7778415), est_link_cap: Some(0) }) } Nov 17 21:59:02.503 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:02.545 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812940 Nov 17 21:59:02.545 INFO [stdout] 2018-11-17 21:59:02 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812940), message_loc: Only, in_order_delivery: false, message_number: 209, timestamp: 8930294, dest_sockid: SocketID(81), payload: b"812940" }, V4(0.0.0.0:0)) Nov 17 21:59:02.595 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812941 Nov 17 21:59:02.595 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending NAK for=[SeqNumber(812939), SeqNumber(812940)] Nov 17 21:59:02.595 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812938, buffer=[812941] Nov 17 21:59:02.595 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Got packet: Control { timestamp: 8978496, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [-2146670709, 812940] }) } Nov 17 21:59:02.595 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Loss list=[812939, 812940] Nov 17 21:59:02.631 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812939) Nov 17 21:59:02.631 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812938, buffer=[812941, 812939] Nov 17 21:59:02.681 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet in loss list, seq=SeqNumber(812940) Nov 17 21:59:02.681 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812939) Nov 17 21:59:02.681 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812939, buffer=[812941, 812940] Nov 17 21:59:02.739 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812942 Nov 17 21:59:02.739 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812940) Nov 17 21:59:02.739 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812941) Nov 17 21:59:02.739 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812941, buffer=[812942] Nov 17 21:59:02.827 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812943 Nov 17 21:59:02.827 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812942) Nov 17 21:59:02.827 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812942, buffer=[812943] Nov 17 21:59:02.867 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::sender] Sending packet: 812944 Nov 17 21:59:02.867 INFO [stdout] 2018-11-17 21:59:02 INFO [tests] Dropping packet: (Data { seq_number: SeqNumber(812945), message_loc: Only, in_order_delivery: false, message_number: 214, timestamp: 9253416, dest_sockid: SocketID(81), payload: b"812945" }, V4(0.0.0.0:0)) Nov 17 21:59:02.867 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812943) Nov 17 21:59:02.867 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] lr=812943, buffer=[812944] Nov 17 21:59:02.927 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Releasing SeqNumber(812944) Nov 17 21:59:02.927 INFO [stdout] 2018-11-17 21:59:02 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:03.123 INFO [stdout] 2018-11-17 21:59:03 INFO [srt::sender] Got packet: Control { timestamp: 9314337, dest_sockid: SocketID(13), control_type: Ack(65, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:03.123 INFO [stdout] 2018-11-17 21:59:03 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:03.123 INFO [stdout] 2018-11-17 21:59:03 INFO [srt::sender] Sending packet: 812946 Nov 17 21:59:03.340 INFO [stdout] 2018-11-17 21:59:03 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:03.763 INFO [stdout] 2018-11-17 21:59:03 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:04.177 INFO [stdout] 2018-11-17 21:59:04 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:04.596 INFO [stdout] 2018-11-17 21:59:04 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:05.014 INFO [stdout] 2018-11-17 21:59:05 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:05.435 INFO [stdout] 2018-11-17 21:59:05 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:05.853 INFO [stdout] 2018-11-17 21:59:05 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:05.853 INFO [stdout] 2018-11-17 21:59:05 INFO [tests] Dropping packet: (Control { timestamp: 12238237, dest_sockid: SocketID(13), control_type: Ack(72, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) }, V4(0.0.0.0:0)) Nov 17 21:59:06.271 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::receiver] Sending ACK; ack_num=SeqNumber(812945), lr_ack_acked=SeqNumber(812939) Nov 17 21:59:06.460 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 9727764, dest_sockid: SocketID(13), control_type: Ack(66, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.460 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.460 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 10150687, dest_sockid: SocketID(13), control_type: Ack(67, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.460 INFO [stdout] 2018-11-17 21:59:06 INFO [tests] Dropping packet: (Control { timestamp: 12847818, dest_sockid: SocketID(81), control_type: Ack2(67) }, V4(0.0.0.0:0)) Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 10564587, dest_sockid: SocketID(13), control_type: Ack(68, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 10983480, dest_sockid: SocketID(13), control_type: Ack(69, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 11406132, dest_sockid: SocketID(13), control_type: Ack(70, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [tests] Dropping packet: (Control { timestamp: 12847957, dest_sockid: SocketID(81), control_type: Ack2(70) }, V4(0.0.0.0:0)) Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 11819772, dest_sockid: SocketID(13), control_type: Ack(71, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 12656595, dest_sockid: SocketID(13), control_type: Ack(73, AckControlInfo { ack_number: SeqNumber(812945), rtt: Some(77913), rtt_variance: Some(96764), buffer_available: None, packet_recv_rate: Some(8381998), est_link_cap: Some(0) }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::default_congestion_ctrl::sender] New window size: 1000 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Sending packet: 812947 Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::receiver] Sending NAK for=[SeqNumber(812945)] Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::receiver] lr=812944, buffer=[812946] Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Got packet: Control { timestamp: 12848205, dest_sockid: SocketID(13), control_type: Nak(NakControlInfo { loss_info: [812945] }) } Nov 17 21:59:06.461 INFO [stdout] 2018-11-17 21:59:06 INFO [srt::sender] Loss list=[812945] Nov 17 21:59:06.462 INFO [stderr] thread '' panicked at 'attempt to multiply with overflow', /source/src/receiver.rs:407:33 Nov 17 21:59:06.462 INFO [stderr] stack backtrace: Nov 17 21:59:06.499 INFO [stderr] 0: 0x55cc51047bb3 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h1a944b80a560daa8 Nov 17 21:59:06.551 INFO [stderr] at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 Nov 17 21:59:06.551 INFO [stderr] 1: 0x55cc51042128 - std::sys_common::backtrace::_print::h18f735b4c3a49bdb Nov 17 21:59:06.551 INFO [stderr] at libstd/sys_common/backtrace.rs:71 Nov 17 21:59:06.551 INFO [stderr] 2: 0x55cc51046984 - std::panicking::default_hook::{{closure}}::h97ab3548a215c097 Nov 17 21:59:06.551 INFO [stderr] at libstd/sys_common/backtrace.rs:59 Nov 17 21:59:06.551 INFO [stderr] at libstd/panicking.rs:211 Nov 17 21:59:06.551 INFO [stderr] 3: 0x55cc510466ed - std::panicking::default_hook::h98c2a01ef734e4b0 Nov 17 21:59:06.551 INFO [stderr] at libstd/panicking.rs:227 Nov 17 21:59:06.551 INFO [stderr] 4: 0x55cc51047090 - std::panicking::rust_panic_with_hook::hb4b3f28eb79ea752 Nov 17 21:59:06.551 INFO [stderr] at libstd/panicking.rs:476 Nov 17 21:59:06.551 INFO [stderr] 5: 0x55cc51046c11 - std::panicking::continue_panic_fmt::h61fd5a7b1a268752 Nov 17 21:59:06.551 INFO [stderr] at libstd/panicking.rs:390 Nov 17 21:59:06.551 INFO [stderr] 6: 0x55cc51046af5 - rust_begin_unwind Nov 17 21:59:06.551 INFO [stderr] at libstd/panicking.rs:325 Nov 17 21:59:06.551 INFO [stderr] 7: 0x55cc5105717c - core::panicking::panic_fmt::h400423a63e8ecedb Nov 17 21:59:06.573 INFO [stderr] at libcore/panicking.rs:77 Nov 17 21:59:06.574 INFO [stderr] 8: 0x55cc510570ab - core::panicking::panic::hdd7d3081d33a952e Nov 17 21:59:06.574 INFO [stderr] at libcore/panicking.rs:52 Nov 17 21:59:06.574 INFO [stderr] 9: 0x55cc50f54175 - >::handle_packet::h7fa7d338e2ab12fc Nov 17 21:59:06.574 INFO [stderr] at /source/src/receiver.rs:407 Nov 17 21:59:06.575 INFO [stderr] 10: 0x55cc50f5745b - as futures::stream::Stream>::poll::hd50e890a58fbcd73 Nov 17 21:59:06.575 INFO [stderr] at /source/src/receiver.rs:633 Nov 17 21:59:06.578 INFO [stderr] 11: 0x55cc50f86f43 - as futures::future::Future>::poll::he33bce87a7915a23 Nov 17 21:59:06.582 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/stream/forward.rs:94 Nov 17 21:59:06.583 INFO [stderr] 12: 0x55cc50f85875 - as futures::future::Future>::poll::h0e75769eb2d0af06 Nov 17 21:59:06.583 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/future/map_err.rs:30 Nov 17 21:59:06.583 INFO [stderr] 13: 0x55cc50f620da - as futures::future::Future>::poll::hfcd1ebabfd8bafa3 Nov 17 21:59:06.583 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/future/map.rs:30 Nov 17 21:59:06.583 INFO [stderr] 14: 0x55cc50f8ff62 - >::poll_future_notify::{{closure}}::haeb7c54d97386e3a Nov 17 21:59:06.583 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/mod.rs:326 Nov 17 21:59:06.583 INFO [stderr] 15: 0x55cc50f901ef - >::enter::{{closure}}::hb6dab6bdb82b0b6f Nov 17 21:59:06.583 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/mod.rs:396 Nov 17 21:59:06.583 INFO [stderr] 16: 0x55cc50f7c34a - futures::task_impl::std::set::hdc97081a1be0bad8 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/std/mod.rs:78 Nov 17 21:59:06.587 INFO [stderr] 17: 0x55cc50f9018a - >::enter::hac79b93227e5c8c1 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/mod.rs:396 Nov 17 21:59:06.587 INFO [stderr] 18: 0x55cc50f8fd63 - >::poll_fn_notify::hc9cf99a27a0b0b11 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/mod.rs:288 Nov 17 21:59:06.587 INFO [stderr] 19: 0x55cc50f8ff36 - >::poll_future_notify::h72b4d87e859a4eed Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/mod.rs:326 Nov 17 21:59:06.587 INFO [stderr] 20: 0x55cc50f7c44d - futures::task_impl::std::>::wait_future::{{closure}}::h1017891adb3943d3 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/std/mod.rs:231 Nov 17 21:59:06.587 INFO [stderr] 21: 0x55cc50f7bf86 - futures::task_impl::std::ThreadNotify::with_current::{{closure}}::h3df9937857e79c71 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/std/mod.rs:478 Nov 17 21:59:06.587 INFO [stderr] 22: 0x55cc50f60189 - >::try_with::hc738c505f0e704a3 Nov 17 21:59:06.587 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/thread/local.rs:309 Nov 17 21:59:06.587 INFO [stderr] 23: 0x55cc50f5fcfc - >::with::he61e2879395ad833 Nov 17 21:59:06.587 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/thread/local.rs:255 Nov 17 21:59:06.587 INFO [stderr] 24: 0x55cc50f7bf06 - futures::task_impl::std::ThreadNotify::with_current::h2d9ff1c04c153481 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/std/mod.rs:478 Nov 17 21:59:06.587 INFO [stderr] 25: 0x55cc50f914cc - futures::task_impl::std::>::wait_future::h6095f3fcd8798b34 Nov 17 21:59:06.587 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/task_impl/std/mod.rs:228 Nov 17 21:59:06.587 INFO [stderr] 26: 0x55cc50f61a49 - futures::future::Future::wait::h17e12d9c1a275208 Nov 17 21:59:06.588 INFO [stderr] at /cargo-home/registry/src/github.com-1ecc6299db9ec823/futures-0.1.25/src/future/mod.rs:299 Nov 17 21:59:06.588 INFO [stderr] 27: 0x55cc50f6e726 - tests::test_with_loss::{{closure}}::h8a381c95a6324bb4 Nov 17 21:59:06.588 INFO [stderr] at tests/tests.rs:261 Nov 17 21:59:06.588 INFO [stderr] 28: 0x55cc50f790d6 - std::sys_common::backtrace::__rust_begin_short_backtrace::he39e23f720b780a3 Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/sys_common/backtrace.rs:136 Nov 17 21:59:06.588 INFO [stderr] 29: 0x55cc50f5e054 - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::he269abf68d0edd45 Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/thread/mod.rs:477 Nov 17 21:59:06.588 INFO [stderr] 30: 0x55cc50f78c44 - as core::ops::function::FnOnce<()>>::call_once::hd04ec662309e500c Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/panic.rs:319 Nov 17 21:59:06.588 INFO [stderr] 31: 0x55cc50f64f69 - std::panicking::try::do_call::hcbfa09a6df1842ce Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/panicking.rs:310 Nov 17 21:59:06.588 INFO [stderr] 32: 0x55cc51055a19 - __rust_maybe_catch_panic Nov 17 21:59:06.588 INFO [stderr] at libpanic_unwind/lib.rs:102 Nov 17 21:59:06.588 INFO [stderr] 33: 0x55cc50f64dc7 - std::panicking::try::h8a46b1cbd9572f71 Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/panicking.rs:289 Nov 17 21:59:06.588 INFO [stderr] 34: 0x55cc50f79176 - std::panic::catch_unwind::he797d79747c5d9ee Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/panic.rs:398 Nov 17 21:59:06.588 INFO [stderr] 35: 0x55cc50f5ddf2 - std::thread::Builder::spawn_unchecked::{{closure}}::ha34184f85d60bccb Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/libstd/thread/mod.rs:476 Nov 17 21:59:06.588 INFO [stderr] 36: 0x55cc50f5e414 - >::call_box::h40950ef5c6528f9e Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/liballoc/boxed.rs:673 Nov 17 21:59:06.588 INFO [stderr] 37: 0x55cc5104982d - std::sys::unix::thread::Thread::new::thread_start::h5f8d67158a1ca038 Nov 17 21:59:06.588 INFO [stderr] at /rustc/6b9b97bd9b704f85f0184f7a213cc4d62bd9654c/src/liballoc/boxed.rs:683 Nov 17 21:59:06.589 INFO [stderr] at libstd/sys_common/thread.rs:24 Nov 17 21:59:06.589 INFO [stderr] at libstd/sys/unix/thread.rs:90 Nov 17 21:59:06.589 INFO [stderr] 38: 0x7f7f2b1226b9 - start_thread Nov 17 21:59:06.589 INFO [stderr] 39: 0x7f7f2ac4241c - clone Nov 17 21:59:06.589 INFO [stderr] 40: 0x0 - Nov 17 21:59:18.219 INFO [stdout] test test_with_loss ... ok Nov 17 21:59:18.219 INFO [stderr] Doc-tests srt Nov 17 21:59:18.219 INFO [stdout] Nov 17 21:59:18.219 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 17 21:59:18.219 INFO [stdout] Nov 17 21:59:22.759 INFO [stdout] Nov 17 21:59:22.759 INFO [stdout] running 0 tests Nov 17 21:59:22.759 INFO [stdout] Nov 17 21:59:22.759 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Nov 17 21:59:22.759 INFO [stdout] Nov 17 21:59:22.776 INFO [stderr] su: No module specific data is present Nov 17 21:59:23.566 INFO running `"docker" "inspect" "d29dd707fa1bcc649ada7f9e2fb97cdf923f555f93585f7eb54582f8fac30048"` Nov 17 21:59:23.779 INFO running `"docker" "rm" "-f" "d29dd707fa1bcc649ada7f9e2fb97cdf923f555f93585f7eb54582f8fac30048"` Nov 17 21:59:23.935 INFO [stdout] d29dd707fa1bcc649ada7f9e2fb97cdf923f555f93585f7eb54582f8fac30048