Add tquic-goodput-debug.yml for debuging

.github/workflows/tquic-goodput-debug.yml

@@ -0,0 +1,85 @@
+name: GoodputDebug
+
+on:
+  schedule:
+    - cron: '30 1 * * *'
+  workflow_dispatch:
+
+env:
+  CARGO_TERM_COLOR: always
+  QUIC_IMAGES: gquiche=tquicgroup/qirgq,lsquic=tquicgroup/qirls,picoquic=tquicgroup/qirpq,quiche=tquicgroup/qircq
+
+jobs:
+  measure:
+    runs-on: ubuntu-latest
+
+    strategy:
+      matrix:
+        impl: [tquic,lsquic]
+        case: [goodput10m]
+        cc: [bbr]
+
+    # The scheduled workflow only runs for the main repository.
+    # You can manually trigger it if necessary.
+    if: ${{ ( github.event_name == 'schedule' && github.repository == 'tencent/tquic' ) || github.event_name == 'workflow_dispatch' }}
+    steps:
+    - uses: actions/checkout@v4
+      with:
+        submodules: 'recursive'
+
+    - name: Build docker image
+      run: docker build -t tquic_interop:v1 -f interop/Dockerfile .
+
+    - name: Install quic-interop-runner
+      run: |
+        git clone https://github.com/tquic-group/quic-interop-runner.git
+        cd quic-interop-runner
+        pip3 install -r requirements.txt
+
+    - name: Install dependencies
+      run: |
+        sudo modprobe ip6table_filter
+        sudo add-apt-repository -y ppa:wireshark-dev/stable
+        sudo apt install -y tshark
+
+    - name: Run the interop tests 
+      run: |
+        cd quic-interop-runner   
+        python3 run.py -r "$QUIC_IMAGES,tquic=tquic_interop:v1" -s ${{ matrix.impl }} -c ${{ matrix.impl }} -t ${{ matrix.case }} -a ${{ matrix.cc }} -d -n "drop-rate --delay=15ms --bandwidth=30Mbps --queue=25 --rate_to_server=0 --rate_to_client=0" -j ${{ matrix.case }}-0-${{ matrix.cc }}-${{ matrix.impl }}.json
+
+    - name: Store measurement results
+      uses: actions/upload-artifact@v4
+      with:
+        name: ${{ matrix.case }}-${{ matrix.cc }}-${{ matrix.impl }}
+        path: quic-interop-runner/*
+
+  result:
+    runs-on: ubuntu-latest
+    needs: measure
+    steps:
+    - name: Download all workflow run artifacts
+      uses: actions/download-artifact@v4
+
+    - name: Display structure of downloaded files
+      run: ls -R
+
+    - name: Display all measurement details
+      run: grep "details.*" . -Ro
+
+    - name: Download plot tools
+      uses: actions/checkout@v4
+      with:
+        path: tools
+
+    - name: Install dependencies
+      run: |
+        sudo apt install python3-matplotlib
+
+    - name: Plot all measurement results
+      run: python3 tools/.github/workflows/plot-goodput.py .
+
+    - name: Store all measurement results
+      uses: actions/upload-artifact@v4
+      with:
+        name: goodput-all-result
+        path: goodput*

interop/run_endpoint.sh

@@ -64,7 +64,7 @@ esac
 
 # Note: You can add extra command-line options to tquic_client/tquic_sever by
 # using the `EXTRA_ARGS` environment variable.
-COMMON_ARGS="--keylog-file $SSLKEYLOGFILE --log-level DEBUG --log-file $LOG_DIR/$ROLE.log --idle-timeout 30000 --handshake-timeout 30000 --initial-rtt 100 --congestion-control-algor $CC_ALGOR $EXTRA_ARGS"
+COMMON_ARGS="--keylog-file $SSLKEYLOGFILE --log-level trace --log-file $LOG_DIR/$ROLE.log --idle-timeout 30000 --handshake-timeout 30000 --initial-rtt 100 --congestion-control-algor $CC_ALGOR $EXTRA_ARGS"
 
 if [ "$TESTCASE" != "transfer" ]; then
     COMMON_ARGS="$COMMON_ARGS --qlog-dir $QLOG_DIR"

src/connection/connection.rs

@@ -2364,6 +2364,10 @@ impl Connection {
             .map(|(&k, &v)| (k, v))
             .collect::<Vec<(u64, u64)>>()
         {
+            log::debug!(
+                "~~~ stream {} is blocked, sending STREAM_DATA_BLOCKED",
+                stream_id
+            );
             let frame = frame::Frame::StreamDataBlocked {
                 stream_id,
                 max: limit,

src/connection/flowcontrol.rs

@@ -103,7 +103,15 @@ impl FlowControl {
     /// Return true if the available window is smaller than the half
     /// of the current window.
     pub fn should_send_max_data(&self) -> bool {
-        (self.max_data - self.read_off) * 2 < self.window
+        let v = (self.max_data - self.read_off) * 2 < self.window;
+        log::debug!(
+            "~~~ should_send_max_data {}: max_data {} - read_off {} < window {} / 2",
+            v,
+            self.max_data,
+            self.read_off,
+            self.window
+        );
+        v
     }
 
     /// Get the next max_data limit which will be sent to the peer

src/connection/stream.rs

@@ -379,9 +379,21 @@ impl StreamMap {
         let empty_fin = buf_len == 0 && fin;
 
         if written < buf_len {
+            log::debug!(
+                "~~~ stream {} not all data has been written buf_len {}, written{}",
+                stream_id,
+                buf_len,
+                written
+            );
             let max_data = stream.send.max_data();
 
             if stream.send.blocked_at() != Some(max_data) {
+                log::debug!(
+                    "~~~ stream {} sendbuf blocked_at() {:?} != max_data() {:?}, mark stream blocked",
+                    stream_id,
+                    stream.send.blocked_at(),
+                    Some(max_data)
+                );
                 stream.send.update_blocked_at(Some(max_data));
                 self.mark_blocked(stream_id, true, max_data);
             }
@@ -525,6 +537,12 @@ impl StreamMap {
         // The connection-level flow control credit is not enough, mark the connection
         // blocked and schedule a DATA_BLOCKED frame to be sent to the peer.
         if self.max_tx_data_left() < len as u64 {
+            trace!(
+                "{} stream {} was blocked by connection-level flow control at {}",
+                self.trace_id,
+                stream_id,
+                self.send_capacity.max_data
+            );
             self.update_data_blocked_at(Some(self.send_capacity.max_data));
         }
 
@@ -544,6 +562,10 @@ impl StreamMap {
         if stream.send.capacity()? < len {
             let max_data = stream.send.max_data();
             if stream.send.blocked_at() != Some(max_data) {
+                debug!(
+                    "~~~ stream {} was blocked by stream-level flow control at {}",
+                    stream_id, max_data
+                );
                 stream.send.update_blocked_at(Some(max_data));
                 self.mark_blocked(stream_id, true, max_data);
             }

tools/src/bin/tquic_client.rs

@@ -546,6 +546,7 @@ impl Worker {
         config.enable_multipath(option.enable_multipath);
         config.set_multipath_algorithm(option.multipath_algor);
         config.set_active_connection_id_limit(option.active_cid_limit);
+        config.enable_pacing(false);
         config.enable_encryption(!option.disable_encryption);
         let tls_config = TlsConfig::new_client_config(
             ApplicationProto::convert_to_vec(&option.alpn),