2025-04-30 10:12:30,624 Generated random file: jfpsoqhrhi of size: 10485760 2025-04-30 10:12:30,624 Requests: https://server4:443/jfpsoqhrhi 2025-04-30 10:12:30,685 2025-04-30 10:12:30,685 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_xkcg8lz3/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_cau5ul2v/ DOWNLOADS=/tmp/download_26oz3jlm/ SERVER_LOGS=/tmp/logs_server_i7kqrya9 CLIENT_LOGS=/tmp/logs_client_acgl3kts SCENARIO="rebind --delay=15ms --bandwidth=10Mbps --queue=25 --first-rebind=1s --rebind-freq=5s --rebind-addr" CLIENT=ghcr.io/alibaba/xquic/xquic-interop:latest SERVER=ghcr.io/nginx/nginx-quic-qns:latest REQUESTS="https://server4:443/jfpsoqhrhi" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 10:13:12,636 Container sim Recreate Container sim Recreated Container server Recreate Container client Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... server | Actual changes: server | tx-checksumming: off server | tx-checksum-ip-generic: off server | tx-checksum-sctp: off server | tcp-segmentation-offload: off server | tx-tcp-segmentation: off [requested on] server | tx-tcp-ecn-segmentation: off [requested on] server | tx-tcp-mangleid-segmentation: off [requested on] server | tx-tcp6-segmentation: off [requested on] server | tx-udp-segmentation: off [requested on] server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | >>> Starting nginx server... server | nginx version: nginx/1.27.0 (9270:d1b8568f3042) server | built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2) server | built with OpenSSL 1.1.1 (compatible; BoringSSL) (running with BoringSSL) server | TLS SNI support enabled server | configure arguments: --prefix=/etc/nginx --build=9270:d1b8568f3042 --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/run/nginx.pid --lock-path=/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx --group=nginx --with-compat --with-debug --with-http_ssl_module --with-http_v2_module --with-http_v3_module --with-cc=c++ --with-cc-opt='-I/boringssl/include -O0 -fno-common -fno-omit-frame-pointer -DNGX_QUIC_DRAFT_VERSION=29 -DNGX_HTTP_V3_HQ=1 -x c' --with-ld-opt='-L/boringssl/build/ssl -L/boringssl/build/crypto' server | >>> Parameters: server | >>> Test case: transfer client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off server | 2025/04/30 10:12:31 [notice] 21#0: using the "epoll" event method server | 2025/04/30 10:12:31 [notice] 21#0: nginx/1.27.0 (9270:d1b8568f3042) server | 2025/04/30 10:12:31 [notice] 21#0: built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2) server | 2025/04/30 10:12:31 [notice] 21#0: OS: Linux 6.11.0-1012-azure server | 2025/04/30 10:12:31 [notice] 21#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576 server | 2025/04/30 10:12:31 [notice] 21#0: start worker processes server | 2025/04/30 10:12:31 [notice] 21#0: start worker process 22 client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.008843897s sim | Using scenario: rebind --delay=15ms --bandwidth=10Mbps --queue=25 --first-rebind=1s --rebind-freq=5s --rebind-addr sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | 0s: first rebind in 1s, frequency 5s client | wait-for-it.sh: sim:57832 is available after 1 seconds client | ./demo_client -l d -L /logs/client.log -D /downloads -k /logs/keys.log -K 30 -o -U "https://server4:443/jfpsoqhrhi" client | client | option log level :d client | option log directory :/logs/client.log client | option save body dir: /downloads client | key output file: /logs/keys.log client | client life circle time: 30 client | set interop mode client | option url only:https://server4:443/jfpsoqhrhi client | server[server4] addr: 193.167.100.100:443. client | No.0 path created id = 0 client | open file[/downloads/jfpsoqhrhi] suc server | 2025/04/30 10:12:32 [info] 22#0: *4 quic no init keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 10:12:32 [info] 22#0: *4 quic no hs keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 sim | 1s: rebinding: 193.167.0.100:53295 -> 193.167.0.224:59022 sim | 1.00087s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00186s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00284s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00382s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00481s: unknown binding for destination 193.167.0.100:53295, dropping packet server | 2025/04/30 10:12:33 [info] 22#0: *4 quic migrated to path seq:1 addr:193.167.0.224:59022 while handling frames, client: 193.167.0.224, server: 0.0.0.0:443 sim | 1.00579s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00677s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00775s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00874s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.00972s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.0107s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01169s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01267s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01366s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01464s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01562s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01569s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01668s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01766s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01865s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.01963s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02061s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.0216s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02258s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02357s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02455s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02551s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.0265s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02748s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02847s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.02945s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03043s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03142s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.0324s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03339s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03437s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03534s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03633s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 1.03731s: unknown binding for destination 193.167.0.100:53295, dropping packet server | 2025/04/30 10:12:33 [info] 22#0: *4 quic path seq:1 addr:193.167.0.224:59022 successfully validated while handling frames, client: 193.167.0.224, server: 0.0.0.0:443 sim | 2.04102s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 2.04201s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 4.04485s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 4.04583s: unknown binding for destination 193.167.0.100:53295, dropping packet sim | 6s: rebinding: 193.167.0.224:59022 -> 193.167.0.71:39968 sim | 6.00007s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00106s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00204s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00302s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00401s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00499s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00598s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00696s: unknown binding for destination 193.167.0.224:59022, dropping packet server | 2025/04/30 10:12:38 [info] 22#0: *4 quic no available client ids for new path while handling decrypted packet, client: 193.167.0.224, server: 0.0.0.0:443 sim | 6.00794s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00839s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.00938s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01036s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01134s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01233s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01331s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.0143s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01528s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01626s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01725s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01818s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.01916s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02014s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02113s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02211s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.0231s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02408s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02506s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02605s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02703s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.028s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02899s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.02997s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03096s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03194s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03292s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03391s: unknown binding for destination 193.167.0.224:59022, dropping packet server | 2025/04/30 10:12:38 [info] 22#0: *4 quic no available client ids for new path while handling decrypted packet, client: 193.167.0.224, server: 0.0.0.0:443 sim | 6.03489s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03588s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03686s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.03784s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.098s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.09804s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.2683s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.26835s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.60876s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 6.6088s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 7.28959s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 7.28964s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 8.02146s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 9.38291s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 9.38296s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 11s: rebinding: 193.167.0.71:39968 -> 193.167.0.3:38910 sim | 12.1058s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 12.1058s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 16s: rebinding: 193.167.0.3:38910 -> 193.167.0.250:19495 sim | 17.5467s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 17.5467s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 21s: rebinding: 193.167.0.250:19495 -> 193.167.0.200:28302 sim | 26s: rebinding: 193.167.0.200:28302 -> 193.167.0.217:46157 sim | 28.4377s: unknown binding for destination 193.167.0.224:59022, dropping packet sim | 28.4378s: unknown binding for destination 193.167.0.224:59022, dropping packet client | [* tasks are running more than 30 seconds, kill it anyway! *] client | [HQ-req] send_bytes:17, recv_bytes:6741142, path_info:0-1-5919-17-6741142 client | task[0], fin_cnt: 1, fin_flag: 1 client | task finished, total task_req_cnt: 1, req_fin_cnt: 1, req_sent_cnt: 0, req_create_cnt: 1 client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 10:13:12,802 Using the client's key log file. 2025-04-30 10:13:12,827 2025-04-30 10:13:12,836 Using the client's key log file. 2025-04-30 10:13:12,836 Using the client's key log file. 2025-04-30 10:13:12,861 2025-04-30 10:13:12,870 Using the client's key log file. 2025-04-30 10:13:13,787 File size of /tmp/download_26oz3jlm/jfpsoqhrhi doesn't match. Original: 10485760 bytes, downloaded: 6741142 bytes. 2025-04-30 10:13:13,788 Using the client's key log file. 2025-04-30 10:13:14,735 File size of /tmp/download_26oz3jlm/jfpsoqhrhi doesn't match. Original: 10485760 bytes, downloaded: 6741142 bytes. 2025-04-30 10:13:14,735 Using the client's key log file. 2025-04-30 10:13:35,751 Server saw these client addresses: {'193.167.0.224', '193.167.0.100'} 2025-04-30 10:13:36,742 File size of /tmp/download_26oz3jlm/jfpsoqhrhi doesn't match. Original: 10485760 bytes, downloaded: 6741142 bytes. 2025-04-30 10:13:36,742 Using the client's key log file. 2025-04-30 10:13:37,732 File size of /tmp/download_26oz3jlm/jfpsoqhrhi doesn't match. Original: 10485760 bytes, downloaded: 6741142 bytes.