update quicly-go debug branch

Project-Faster · Aug 31, 2024 · 35a0166 · 35a0166
1 parent 54876ab
commit 35a0166
Show file tree

Hide file tree

Showing 4 changed files with 21 additions and 33 deletions.
diff --git a/.github/workflows/performance.yml b/.github/workflows/performance.yml
@@ -93,19 +93,15 @@ jobs:
     strategy:
       max-parallel: 1
       matrix:
-        backend: [ 'quicly-go' ]
-        cca: [ 'reno' ]
-        slowstart: [ 'search' ]
-        connection_delay_ms: [ 0, 200 ]
-#        backend: [ 'quic-go', 'quicly-go' ]
-#        cca: [ 'reno', 'cubic' ]
-#        slowstart: [ 'basic', 'search' ]
-#        connection_delay_ms: [ 0, 500 ]
-#        exclude:
-#          - backend: 'quic-go'
-#            slowstart: 'search'
-#          - backend: 'quic-go'
-#            cca: 'cubic'
+        backend: [ 'quic-go', 'quicly-go' ]
+        cca: [ 'reno', 'cubic' ]
+        slowstart: [ 'basic', 'search' ]
+        connection_delay_ms: [ 0, 500 ]
+        exclude:
+          - backend: 'quic-go'
+            slowstart: 'search'
+          - backend: 'quic-go'
+            cca: 'cubic'
     uses: './.github/workflows/run-performance.yml'
     with:
       server_public_address: ${{ inputs.server_public_address }}

diff --git a/backend/quicly-go b/backend/quicly-go
diff --git a/workers/client/client_network.go b/workers/client/client_network.go
@@ -141,7 +141,7 @@ func handleTCPConn(tcpConn net.Conn) {
 	}
 
 	//Proxy all stream content from quic to TCP and from TCP to quic
-	logger.Info("[%d] Stream Start", quicStream.ID())
+	logger.Debug("[%d] Stream Start", quicStream.ID())
 
 	tqActiveFlag := atomic.Bool{}
 	qtActiveFlag := atomic.Bool{}
@@ -192,7 +192,6 @@ func getQuicStream(ctx context.Context) (backend.QuicBackendStream, error) {
 		logger.Debug("Trying to open on existing session")
 		quicStream, err = localSession.OpenStream(context.Background())
 		if err == nil {
-			logger.Info("Opened a new stream: %d", quicStream.ID())
 			return quicStream, nil
 		}
 		// if we weren't able to open a quicStream on that session (usually inactivity timeout), we can try to open a new session
@@ -362,13 +361,8 @@ func handleProxyedRequest(req *http.Request, header *shared.QPepHeader, tcpConn
 			return shared.ErrFailed
 		}
 
-		logger.Info("Sending captured %s request\n", req.Method)
+		logger.Debug("Sending captured %s request\n", req.Method)
 		err = req.Write(stream)
-		//if err != nil {
-		//	_ = tcpConn.Close()
-		//	logger.Error("Error writing to tcp stream: %v", err)
-		//	return shared.ErrFailed
-		//}
 		break
 
 	case http.MethodConnect:
@@ -403,8 +397,7 @@ func handleProxyedRequest(req *http.Request, header *shared.QPepHeader, tcpConn
 
 		t.Write(tcpConn)
 
-		logger.Info("Proxied connection")
-		logger.Info("Sending QPEP header to server, SourceAddr: %v / DestAddr: %v / ID: %v", header.SourceAddr, header.DestAddr, stream.ID())
+		logger.Info("(Proxied) Sending QPEP header to server, SourceAddr: %v / DestAddr: %v / ID: %v", header.SourceAddr, header.DestAddr, stream.ID())
 
 		_, err := stream.Write(header.ToBytes())
 		if err != nil {

diff --git a/workers/server/server_network.go b/workers/server/server_network.go
@@ -216,12 +216,11 @@ func handleQuicStream(quicStream backend.QuicBackendStream) {
 	//we exit (and close the TCP connection) once both streams are done copying or timeout
 	logger.Debug("[%v] Stream Wait", quicStream.ID())
 	streamWait.Wait()
-	logger.Info("Stream %d (duration: %v) End", quicStream.ID(), time.Now().Sub(startTime))
 
 	tcpConn.Close()
 	quicStream.Close()
 
-	logger.Debug("[%d] Closed TCP NetConn %s -> %s\n", quicStream.ID(), qpepHeader.SourceAddr, destAddress)
+	logger.Info("[%d] Closed TCP NetConn %s -> %s [%d] (%v)\n", quicStream.ID(), qpepHeader.SourceAddr, destAddress, quicStream.ID(), time.Now().Sub(startTime))
 }
 
 func handleQuicToTcp(ctx context.Context, streamWait *sync.WaitGroup, speedLimit int64, dst net.Conn, src backend.QuicBackendStream, qtFlag, tqFlag *atomic.Bool) {
@@ -233,7 +232,7 @@ func handleQuicToTcp(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 	periodStart := time.Now()
 	periodWritten := int64(0)
 
-	logger.Info("[%d] Stream Q->T start", src.ID())
+	logger.Debug("[%d] Stream Q->T start", src.ID())
 
 	tskKey := fmt.Sprintf("Q->T:%v", src.ID())
 	tsk := shared.StartRegion(tskKey)
@@ -246,7 +245,7 @@ func handleQuicToTcp(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 		tsk.End()
 		streamWait.Done()
 		qtFlag.Store(false)
-		logger.Error("[%d] Stream Q->T [wr:%v rd:%d] done", src.ID(), written, read)
+		logger.Info("[%d] Stream Q->T [wr:%v rd:%d] done", src.ID(), written, read)
 	}()
 
 	pktPrefix := fmt.Sprintf("%v.server.qt", src.ID())
@@ -260,7 +259,7 @@ func handleQuicToTcp(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 		}
 
 		if src.IsClosed() || !tqFlag.Load() {
-			logger.Info("[%v] T->Q CLOSE (%v %v %v)", src.ID(), src.IsClosed(), !tqFlag.Load(), src.Sync())
+			logger.Debug("[%v] T->Q CLOSE (%v %v %v)", src.ID(), src.IsClosed(), !tqFlag.Load(), src.Sync())
 			return
 		}
 
@@ -287,7 +286,7 @@ func handleQuicToTcp(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 			if err2, ok := err.(net.Error); ok && err2.Timeout() {
 				continue
 			}
-			logger.Error("[%d] END Q->T: %v", src.ID(), err)
+			logger.Error("[%d] STREAM ERR Q->T: %v", src.ID(), err)
 			closeStreamNow(src)
 			return
 		}
@@ -313,7 +312,7 @@ func handleTcpToQuic(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 	periodStart := time.Now()
 	periodWritten := int64(0)
 
-	logger.Info("[%d] Stream T->Q start", dst.ID())
+	logger.Debug("[%d] Stream T->Q start", dst.ID())
 
 	tskKey := fmt.Sprintf("T->Q:%v", dst.ID())
 	tsk := shared.StartRegion(tskKey)
@@ -339,7 +338,7 @@ func handleTcpToQuic(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 		}
 
 		if dst.IsClosed() || !qtFlag.Load() {
-			logger.Info("[%v] T->Q CLOSE (%v %v %v)", dst.ID(), dst.IsClosed(), !qtFlag.Load(), dst.Sync())
+			logger.Error("[%v] T->Q CLOSE (%v %v %v)", dst.ID(), dst.IsClosed(), !qtFlag.Load(), dst.Sync())
 			return
 		}
 
@@ -365,7 +364,7 @@ func handleTcpToQuic(ctx context.Context, streamWait *sync.WaitGroup, speedLimit
 			if err2, ok := err.(net.Error); ok && err2.Timeout() {
 				continue
 			}
-			logger.Error("[%d] END T->Q: %v", dst.ID(), err)
+			logger.Error("[%d] STREAM ERR T->Q: %v", dst.ID(), err)
 			closeStreamNow(dst)
 			return
 		}