From b87d1559680cbc81702977cacd2c1fe5ec118a41 Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 16:42:55 +0200 Subject: [PATCH 1/7] test fetching an image --- x/smart/stream_dialer.go | 23 +++++++++++++++++++++++ 1 file changed, 23 insertions(+) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index 84b28e388..d2026e1f6 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -263,6 +263,29 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream return err } f.logCtx(ctx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) + + // Check a valid path through the same TLS connection + path := "/image/69105246_605.webp" + f.logCtx(ctx, "🏃 running response test: (domain: %v, path: %v)\n", testDomain, path) + + request := "GET " + path + " HTTP/1.1\r\n" + + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + + "Connection: close\r\n" + + "\r\n" + _, err = tlsConn.Write([]byte(request)) + + if err != nil { + f.logCtx(ctx, "🏁 failed to write request %v error=%v ❌ \n", path, err) + } + + response, err := io.ReadAll(tlsConn) + if err != nil { + f.logCtx(ctx, "🏁 reading response error=%v ❌ \n", err) + } + tlsConn.Close() + sizeKB := float64(len(response)) / 1024.0 + + f.logCtx(ctx, "🏁 success: '%v' (domain: %v, path: %v, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, path, sizeKB, time.Since(startTime)) } return nil } From ad545ac2f0863d02a3ed877804722e8c0f9a6c38 Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 17:40:13 +0200 Subject: [PATCH 2/7] switch to a head request --- x/smart/stream_dialer.go | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index d2026e1f6..072546042 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -257,25 +257,23 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream } tlsConn := tls.Client(testConn, &tls.Config{ServerName: testDomain}) err = tlsConn.HandshakeContext(ctx) - tlsConn.Close() if err != nil { f.logCtx(ctx, "🏁 failed TLS handshake: '%v' (domain: %v), duration=%v, handshake=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) return err } f.logCtx(ctx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) - // Check a valid path through the same TLS connection - path := "/image/69105246_605.webp" - f.logCtx(ctx, "🏃 running response test: (domain: %v, path: %v)\n", testDomain, path) + resource := "HEAD / HTTP/1.1" + f.logCtx(ctx, "🏃 running response test: (domain: %v, resource: %v)\n", testDomain, resource) - request := "GET " + path + " HTTP/1.1\r\n" + + request := resource + "\r\n" + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + "Connection: close\r\n" + "\r\n" _, err = tlsConn.Write([]byte(request)) if err != nil { - f.logCtx(ctx, "🏁 failed to write request %v error=%v ❌ \n", path, err) + f.logCtx(ctx, "🏁 failed to write request %v error=%v ❌ \n", resource, err) } response, err := io.ReadAll(tlsConn) @@ -284,8 +282,11 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream } tlsConn.Close() sizeKB := float64(len(response)) / 1024.0 + if sizeKB == 0 { + f.logCtx(ctx, "🏁 response had no content ❌ \n") + } - f.logCtx(ctx, "🏁 success: '%v' (domain: %v, path: %v, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, path, sizeKB, time.Since(startTime)) + f.logCtx(ctx, "🏁 success: '%v' (domain: %v, resource: %v, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, resource, sizeKB, time.Since(startTime)) } return nil } From c72cb1b05fe324720971a5d341cb129d77121e0a Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 17:55:36 +0200 Subject: [PATCH 3/7] returning errs --- x/smart/stream_dialer.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index 072546042..5cfa95e2c 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -274,11 +274,13 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream if err != nil { f.logCtx(ctx, "🏁 failed to write request %v error=%v ❌ \n", resource, err) + return err } response, err := io.ReadAll(tlsConn) if err != nil { f.logCtx(ctx, "🏁 reading response error=%v ❌ \n", err) + return err } tlsConn.Close() sizeKB := float64(len(response)) / 1024.0 From 0a8c9a53723e1a1b2fb0aaf841330d14a7c0ee7a Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 18:00:04 +0200 Subject: [PATCH 4/7] change logging --- x/smart/stream_dialer.go | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index 5cfa95e2c..e860c93a3 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -263,17 +263,15 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream } f.logCtx(ctx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) - resource := "HEAD / HTTP/1.1" - f.logCtx(ctx, "🏃 running response test: (domain: %v, resource: %v)\n", testDomain, resource) + f.logCtx(ctx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) - request := resource + "\r\n" + + request := "HEAD / HTTP/1.1\r\n" + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + "Connection: close\r\n" + "\r\n" _, err = tlsConn.Write([]byte(request)) - if err != nil { - f.logCtx(ctx, "🏁 failed to write request %v error=%v ❌ \n", resource, err) + f.logCtx(ctx, "🏁 failed to write request error=%v ❌ \n", err) return err } @@ -283,12 +281,13 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream return err } tlsConn.Close() + sizeKB := float64(len(response)) / 1024.0 if sizeKB == 0 { f.logCtx(ctx, "🏁 response had no content ❌ \n") } - f.logCtx(ctx, "🏁 success: '%v' (domain: %v, resource: %v, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, resource, sizeKB, time.Since(startTime)) + f.logCtx(ctx, "🏁 success: '%v' (resource: HEAD %v/, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, sizeKB, time.Since(startTime)) } return nil } From c4e2b0252ac472015cbd22fa72c81dd0a9e284ab Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 19:44:52 +0200 Subject: [PATCH 5/7] add logging for test timeouts --- x/smart/stream_dialer.go | 32 +++++++++++++++++++++----------- 1 file changed, 21 insertions(+), 11 deletions(-) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index e860c93a3..b51f94977 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -248,22 +248,32 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream testAddr := net.JoinHostPort(testDomain, "443") f.logCtx(ctx, "🏃 running test: '%v' (domain: %v)\n", transportCfg, testDomain) - ctx, cancel := context.WithTimeout(ctx, f.TestTimeout) + testCtx, cancel := context.WithTimeout(ctx, f.TestTimeout) defer cancel() - testConn, err := dialer.DialStream(ctx, testAddr) + + timeoutChan := make(chan struct{}) + go func() { + <-testCtx.Done() + if errors.Is(testCtx.Err(), context.DeadlineExceeded) { + f.logCtx(ctx, "⏱️ dialer failure, test timed out: '%v' (domain: %v), duration=%v ❌\n", transportCfg, testDomain, time.Since(startTime)) + close(timeoutChan) + } + }() + + testConn, err := dialer.DialStream(testCtx, testAddr) if err != nil { - f.logCtx(ctx, "🏁 failed to dial: '%v' (domain: %v), duration=%v, dial_error=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) + f.logCtx(testCtx, "🏁 failed to dial: '%v' (domain: %v), duration=%v, dial_error=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) return err } tlsConn := tls.Client(testConn, &tls.Config{ServerName: testDomain}) - err = tlsConn.HandshakeContext(ctx) + err = tlsConn.HandshakeContext(testCtx) if err != nil { - f.logCtx(ctx, "🏁 failed TLS handshake: '%v' (domain: %v), duration=%v, handshake=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) + f.logCtx(testCtx, "🏁 failed TLS handshake: '%v' (domain: %v), duration=%v, handshake=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) return err } - f.logCtx(ctx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) + f.logCtx(testCtx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) - f.logCtx(ctx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) + f.logCtx(testCtx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) request := "HEAD / HTTP/1.1\r\n" + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + @@ -271,23 +281,23 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream "\r\n" _, err = tlsConn.Write([]byte(request)) if err != nil { - f.logCtx(ctx, "🏁 failed to write request error=%v ❌ \n", err) + f.logCtx(testCtx, "🏁 failed to write request error=%v ❌ \n", err) return err } response, err := io.ReadAll(tlsConn) if err != nil { - f.logCtx(ctx, "🏁 reading response error=%v ❌ \n", err) + f.logCtx(testCtx, "🏁 reading response error=%v ❌ \n", err) return err } tlsConn.Close() sizeKB := float64(len(response)) / 1024.0 if sizeKB == 0 { - f.logCtx(ctx, "🏁 response had no content ❌ \n") + f.logCtx(testCtx, "🏁 response had no content ❌ \n") } - f.logCtx(ctx, "🏁 success: '%v' (resource: HEAD %v/, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, sizeKB, time.Since(startTime)) + f.logCtx(testCtx, "🏁 success: '%v' (resource: HEAD %v/, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, sizeKB, time.Since(startTime)) } return nil } From 6ba962c87ec349efc99197c4590b59f88f4f8ce4 Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Tue, 13 May 2025 20:11:09 +0200 Subject: [PATCH 6/7] add back image url --- x/smart/stream_dialer.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index b51f94977..20641f7d0 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -275,7 +275,7 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream f.logCtx(testCtx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) - request := "HEAD / HTTP/1.1\r\n" + + request := "GET /image/69105246_605.webp HTTP/1.1\r\n" + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + "Connection: close\r\n" + "\r\n" From 014c64936ee44d9021ef52869ebe4cc8b4c208e9 Mon Sep 17 00:00:00 2001 From: Sarah Laplante Date: Wed, 14 May 2025 17:00:45 +0200 Subject: [PATCH 7/7] test conection ten times --- x/examples/smart-proxy/main.go | 2 +- x/smart/stream_dialer.go | 73 +++++++++++++++++++--------------- 2 files changed, 42 insertions(+), 33 deletions(-) diff --git a/x/examples/smart-proxy/main.go b/x/examples/smart-proxy/main.go index a229e5c06..257bfce36 100644 --- a/x/examples/smart-proxy/main.go +++ b/x/examples/smart-proxy/main.go @@ -112,7 +112,7 @@ func main() { } finder := smart.StrategyFinder{ LogWriter: debugLog.Writer(), - TestTimeout: 5 * time.Second, + TestTimeout: 60 * time.Second, StreamDialer: streamDialer, PacketDialer: packetDialer, } diff --git a/x/smart/stream_dialer.go b/x/smart/stream_dialer.go index 20641f7d0..5ebbaad36 100644 --- a/x/smart/stream_dialer.go +++ b/x/smart/stream_dialer.go @@ -260,44 +260,53 @@ func (f *StrategyFinder) testDialer(ctx context.Context, dialer transport.Stream } }() - testConn, err := dialer.DialStream(testCtx, testAddr) - if err != nil { - f.logCtx(testCtx, "🏁 failed to dial: '%v' (domain: %v), duration=%v, dial_error=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) - return err - } - tlsConn := tls.Client(testConn, &tls.Config{ServerName: testDomain}) - err = tlsConn.HandshakeContext(testCtx) - if err != nil { - f.logCtx(testCtx, "🏁 failed TLS handshake: '%v' (domain: %v), duration=%v, handshake=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) - return err - } - f.logCtx(testCtx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) + for i := 0; i < 10; i++ { - f.logCtx(testCtx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) + testConn, err := dialer.DialStream(testCtx, testAddr) + if err != nil { + f.logCtx(testCtx, "🏁 failed to dial: '%v' (domain: %v), duration=%v, dial_error=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) + return err + } - request := "GET /image/69105246_605.webp HTTP/1.1\r\n" + - "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + - "Connection: close\r\n" + - "\r\n" - _, err = tlsConn.Write([]byte(request)) - if err != nil { - f.logCtx(testCtx, "🏁 failed to write request error=%v ❌ \n", err) - return err - } + tlsConn := tls.Client(testConn, &tls.Config{ServerName: testDomain}) + err = tlsConn.HandshakeContext(testCtx) + if err != nil { + f.logCtx(testCtx, "🏁 failed TLS handshake: '%v' (domain: %v), duration=%v, handshake=%v ❌\n", transportCfg, testDomain, time.Since(startTime), err) + return err + } + f.logCtx(testCtx, "🏁 success: '%v' (domain: %v), duration=%v, status=ok ✅\n", transportCfg, testDomain, time.Since(startTime)) - response, err := io.ReadAll(tlsConn) - if err != nil { - f.logCtx(testCtx, "🏁 reading response error=%v ❌ \n", err) - return err - } - tlsConn.Close() + f.logCtx(testCtx, "🏃 running response test: (resource: HEAD %v/)\n", testDomain) + + f.logCtx(testCtx, "looping %v\n", i) + + request := "GET /image/69105246_605.webp HTTP/1.1\r\n" + + "Host: " + testDomain[:len(testDomain)-1] + "\r\n" + + "Connection: close\r\n" + + "\r\n" + _, err = tlsConn.Write([]byte(request)) + if err != nil { + f.logCtx(testCtx, "🏁 failed to write request error=%v ❌ \n", err) + return err + } + + response, err := io.ReadAll(tlsConn) + if err != nil { + f.logCtx(testCtx, "🏁 reading response error=%v ❌ \n", err) + return err + } + + tlsConn.Close() + + sizeKB := float64(len(response)) / 1024.0 + if sizeKB == 0 { + f.logCtx(testCtx, "🏁 response had no content ❌ \n") + } + + f.logCtx(testCtx, "🏁 success: '%v' (resource: HEAD %v/, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, sizeKB, time.Since(startTime)) - sizeKB := float64(len(response)) / 1024.0 - if sizeKB == 0 { - f.logCtx(testCtx, "🏁 response had no content ❌ \n") } - f.logCtx(testCtx, "🏁 success: '%v' (resource: HEAD %v/, response: %.2f KB), duration=%v, status=ok ✅\n", transportCfg, testDomain, sizeKB, time.Since(startTime)) } return nil }