Skip to content

Commit 48d1eca

Browse files
committed
fix: Fixed webstreams which terminate their datastream with a tcp-close
This behavior was observed on `https://www.wgv.de/hc_scripts/oti.js?cid=[integer]`. A js file is send with `Connection: close`. The connection is terminated, which means that the data has been fully send, no Content-Length or boundries or anything like it.
1 parent bcbb9d4 commit 48d1eca

File tree

5 files changed

+287
-1
lines changed

5 files changed

+287
-1
lines changed

.gitignore

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -58,3 +58,7 @@ coverage.html
5858
/GEMINI.md
5959

6060
/result
61+
62+
/log.txt
63+
/weird_request
64+
/weird-request

main.go

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,7 @@ func parseFlagsAndConfig() (cfg *config.Config, configPaths []string) {
4141
flag.Var(&configs, "config", "Path to configuration file (supports .json and .hcl formats). Can be specified multiple times, later configs take precedence")
4242
envfile := flag.String("envfile", "", "Path to env file to load environment variables")
4343
debugMode := flag.Bool("debug", false, "Enable debug logging")
44+
traceMode := flag.Bool("trace", false, "Enable trace logging")
4445
flag.Parse()
4546

4647
if len(configs) == 0 {
@@ -66,6 +67,10 @@ func parseFlagsAndConfig() (cfg *config.Config, configPaths []string) {
6667
logger.SetLevel(logger.DEBUG)
6768
logger.Debug("Debug logging enabled")
6869
}
70+
if *traceMode {
71+
logger.SetLevel(logger.TRACE)
72+
logger.Debug("Trace logging enabled")
73+
}
6974

7075
logger.Info("Starting msgtausch proxy server")
7176
logger.Debug("Using configuration files: %s", strings.Join(configs, ", "))

msgtausch-srv/logger/logger.go

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,8 @@ type LogLevel int
1212

1313
const (
1414
// DEBUG level for detailed troubleshooting information
15-
DEBUG LogLevel = iota
15+
TRACE LogLevel = iota
16+
DEBUG
1617
// INFO level for general operational information
1718
INFO
1819
// WARN level for non-critical issues
@@ -38,6 +39,8 @@ func SetLevel(level LogLevel) {
3839
// GetLevelFromString converts a string level to LogLevel
3940
func GetLevelFromString(level string) LogLevel {
4041
switch strings.ToUpper(level) {
42+
case "TRACE":
43+
return TRACE
4144
case "DEBUG":
4245
return DEBUG
4346
case "INFO":
@@ -56,6 +59,8 @@ func GetLevelFromString(level string) LogLevel {
5659
// levelToString converts a LogLevel to its string representation
5760
func levelToString(level LogLevel) string {
5861
switch level {
62+
case TRACE:
63+
return "TRACE"
5964
case DEBUG:
6065
return "DEBUG"
6166
case INFO:
@@ -81,6 +86,12 @@ func logMessage(level LogLevel, format string, v ...any) {
8186
stdLogger.Printf("[%s] %s", levelToString(level), msg)
8287
}
8388

89+
// Debug logs a debug message
90+
// Arguments are handled in the manner of [fmt.Printf].
91+
func Trace(format string, v ...any) {
92+
logMessage(TRACE, format, v...)
93+
}
94+
8495
// Debug logs a debug message
8596
// Arguments are handled in the manner of [fmt.Printf].
8697
func Debug(format string, v ...any) {
Lines changed: 244 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,244 @@
1+
package proxy
2+
3+
import (
4+
"bufio"
5+
"context"
6+
"crypto/tls"
7+
"fmt"
8+
"net"
9+
"net/http"
10+
"net/url"
11+
"testing"
12+
"time"
13+
14+
"github.com/codefionn/msgtausch/msgtausch-srv/config"
15+
)
16+
17+
// TestConnectionCloseHandling tests that the proxy handles "Connection: close" responses quickly
18+
func TestConnectionCloseHandling(t *testing.T) {
19+
// Create a mock HTTPS server that sends Connection: close
20+
ln, err := net.Listen("tcp", "127.0.0.1:0")
21+
if err != nil {
22+
t.Fatalf("Failed to create listener for mock server: %v", err)
23+
}
24+
defer ln.Close()
25+
26+
serverAddr := ln.Addr().String()
27+
28+
// JavaScript content similar to the problematic wgv.de response
29+
jsContent := `/* Dynamically generated content! DON'T COPY IT TO YOUR SERVERS! */
30+
(function(){var w=window,d=document,t="script";console.log("test")})();`
31+
32+
// Start mock server that sends Connection: close
33+
go func() {
34+
for {
35+
conn, err := ln.Accept()
36+
if err != nil {
37+
return // Listener closed
38+
}
39+
40+
go func(conn net.Conn) {
41+
defer conn.Close()
42+
43+
// Read the HTTP request
44+
reader := bufio.NewReader(conn)
45+
_, err := http.ReadRequest(reader)
46+
if err != nil {
47+
return
48+
}
49+
50+
// Send response with Connection: close (like wgv.de does)
51+
response := fmt.Sprintf("HTTP/1.1 200 OK\r\n"+
52+
"Content-Type: text/javascript\r\n"+
53+
"Connection: close\r\n"+
54+
"Content-Length: %d\r\n"+
55+
"Cache-Control: private, no-cache, no-store, must-revalidate\r\n"+
56+
"\r\n"+
57+
"%s", len(jsContent), jsContent)
58+
59+
conn.Write([]byte(response))
60+
// Immediately close the connection after sending (like Connection: close should)
61+
}(conn)
62+
}
63+
}()
64+
65+
// Create proxy configuration
66+
cfg := &config.Config{
67+
Servers: []config.ServerConfig{
68+
{
69+
Type: config.ProxyTypeStandard,
70+
ListenAddress: "127.0.0.1:0",
71+
Enabled: true,
72+
},
73+
},
74+
TimeoutSeconds: 30,
75+
MaxConcurrentConnections: 100,
76+
Classifiers: make(map[string]config.Classifier),
77+
}
78+
79+
proxy := NewProxy(cfg)
80+
81+
// Start proxy server
82+
proxyListener, err := net.Listen("tcp", cfg.Servers[0].ListenAddress)
83+
if err != nil {
84+
t.Fatalf("Failed to create proxy listener: %v", err)
85+
}
86+
proxyAddr := proxyListener.Addr().String()
87+
88+
go func() {
89+
if err := proxy.StartWithListener(proxyListener); err != http.ErrServerClosed && err != nil {
90+
t.Errorf("Proxy server error: %v", err)
91+
}
92+
}()
93+
defer proxy.Stop()
94+
95+
// Wait for proxy to start
96+
time.Sleep(100 * time.Millisecond)
97+
98+
// Test the Connection: close handling
99+
t.Run("Connection close handling", func(t *testing.T) {
100+
// Create HTTP client that uses our proxy
101+
client := &http.Client{
102+
Transport: &http.Transport{
103+
Proxy: http.ProxyURL(&url.URL{Host: proxyAddr}),
104+
TLSClientConfig: &tls.Config{
105+
InsecureSkipVerify: true, // For testing
106+
},
107+
},
108+
Timeout: 10 * time.Second, // Should complete much faster
109+
}
110+
111+
// Measure the time it takes to complete the request
112+
start := time.Now()
113+
114+
// Make request to our mock server through the proxy
115+
targetURL := fmt.Sprintf("http://%s/test.js", serverAddr)
116+
req, err := http.NewRequestWithContext(context.Background(), "GET", targetURL, nil)
117+
if err != nil {
118+
t.Fatalf("Failed to create request: %v", err)
119+
}
120+
121+
resp, err := client.Do(req)
122+
if err != nil {
123+
t.Fatalf("Request through proxy failed: %v", err)
124+
}
125+
defer resp.Body.Close()
126+
127+
duration := time.Since(start)
128+
129+
// Verify response
130+
if resp.StatusCode != http.StatusOK {
131+
t.Errorf("Expected status code %d, got %d", http.StatusOK, resp.StatusCode)
132+
}
133+
134+
// Read response body
135+
body := make([]byte, len(jsContent))
136+
n, err := resp.Body.Read(body)
137+
if err != nil && err.Error() != "EOF" {
138+
t.Fatalf("Failed to read response body: %v", err)
139+
}
140+
141+
if string(body[:n]) != jsContent {
142+
t.Errorf("Response body mismatch.\nExpected: %s\nGot: %s", jsContent, string(body[:n]))
143+
}
144+
145+
// Verify that the connection closed quickly (should be under 2 seconds)
146+
// Before the fix, this would take 30+ seconds due to timeout
147+
if duration > 2*time.Second {
148+
t.Errorf("Connection close handling too slow: %v (should be < 2s)", duration)
149+
}
150+
151+
t.Logf("Connection close handling completed in: %v", duration)
152+
})
153+
}
154+
155+
// TestConnectionCloseHTTPS tests Connection: close handling over HTTPS tunnel
156+
func TestConnectionCloseHTTPS(t *testing.T) {
157+
// Create a TLS server that sends Connection: close
158+
tlsServer, certPool := setupTLSServer(t)
159+
defer tlsServer.Close()
160+
161+
// Replace the default handler with one that sends Connection: close
162+
tlsServer.Config.Handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
163+
w.Header().Set("Connection", "close")
164+
w.Header().Set("Content-Type", "text/javascript")
165+
w.Header().Set("Cache-Control", "private, no-cache, no-store, must-revalidate")
166+
167+
jsContent := `/* Test JS content with Connection: close */
168+
(function(){console.log("connection close test")})();`
169+
w.Write([]byte(jsContent))
170+
})
171+
172+
// Create proxy configuration
173+
cfg := &config.Config{
174+
Servers: []config.ServerConfig{
175+
{
176+
Type: config.ProxyTypeStandard,
177+
ListenAddress: "127.0.0.1:0",
178+
Enabled: true,
179+
},
180+
},
181+
TimeoutSeconds: 30,
182+
MaxConcurrentConnections: 100,
183+
Classifiers: make(map[string]config.Classifier),
184+
}
185+
186+
proxy := NewProxy(cfg)
187+
188+
// Start proxy server
189+
proxyListener, err := net.Listen("tcp", cfg.Servers[0].ListenAddress)
190+
if err != nil {
191+
t.Fatalf("Failed to create proxy listener: %v", err)
192+
}
193+
proxyAddr := proxyListener.Addr().String()
194+
195+
go func() {
196+
if err := proxy.StartWithListener(proxyListener); err != http.ErrServerClosed && err != nil {
197+
t.Errorf("Proxy server error: %v", err)
198+
}
199+
}()
200+
defer proxy.Stop()
201+
202+
// Wait for proxy to start
203+
time.Sleep(100 * time.Millisecond)
204+
205+
t.Run("HTTPS Connection close handling", func(t *testing.T) {
206+
// Create HTTP client that uses our proxy
207+
client := &http.Client{
208+
Transport: &http.Transport{
209+
Proxy: http.ProxyURL(&url.URL{Host: proxyAddr}),
210+
TLSClientConfig: &tls.Config{
211+
RootCAs: certPool,
212+
},
213+
},
214+
Timeout: 10 * time.Second,
215+
}
216+
217+
// Measure the time it takes to complete the request
218+
start := time.Now()
219+
220+
resp, err := client.Get(tlsServer.URL + "/test.js")
221+
if err != nil {
222+
t.Fatalf("HTTPS request through proxy failed: %v", err)
223+
}
224+
defer resp.Body.Close()
225+
226+
duration := time.Since(start)
227+
228+
// Verify response
229+
if resp.StatusCode != http.StatusOK {
230+
t.Errorf("Expected status code %d, got %d", http.StatusOK, resp.StatusCode)
231+
}
232+
233+
// Note: Connection: close header might not be preserved in HTTP/2
234+
// but the connection handling should still be fast
235+
t.Logf("Connection header: %v", resp.Header.Get("Connection"))
236+
237+
// Verify that the connection closed quickly
238+
if duration > 2*time.Second {
239+
t.Errorf("HTTPS connection close handling too slow: %v (should be < 2s)", duration)
240+
}
241+
242+
t.Logf("HTTPS connection close handling completed in: %v", duration)
243+
})
244+
}

msgtausch-srv/proxy/proxy.go

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1175,8 +1175,13 @@ func (p *Server) handleConnect(w http.ResponseWriter, r *http.Request, connectio
11751175
var wg sync.WaitGroup
11761176
wg.Add(2)
11771177

1178+
// Create a context to coordinate tunnel shutdown
1179+
ctx, cancel := context.WithCancel(context.Background())
1180+
defer cancel()
1181+
11781182
go func() {
11791183
defer wg.Done()
1184+
defer cancel() // Cancel context when this goroutine exits
11801185
if clientBuf != nil && clientBuf.Reader != nil && clientBuf.Reader.Buffered() > 0 {
11811186
if _, err := clientBuf.WriteTo(targetConn); err != nil {
11821187
if !isClosedConnError(err) {
@@ -1190,15 +1195,32 @@ func (p *Server) handleConnect(w http.ResponseWriter, r *http.Request, connectio
11901195
logger.Warn("TCP tunnel copy error (client to target): %v", err)
11911196
}
11921197
}
1198+
// Close the target connection to signal completion
1199+
if tcpConn, ok := targetConn.(*net.TCPConn); ok {
1200+
tcpConn.CloseWrite()
1201+
}
11931202
}()
11941203

11951204
go func() {
11961205
defer wg.Done()
1206+
defer cancel() // Cancel context when this goroutine exits
11971207
if _, err := io.Copy(clientConn, targetConn); err != nil {
11981208
if !isClosedConnError(err) {
11991209
logger.Warn("TCP tunnel copy error (target to client): %v", err)
12001210
}
12011211
}
1212+
// Close the client connection to signal completion
1213+
if tcpConn, ok := clientConn.(*net.TCPConn); ok {
1214+
tcpConn.CloseWrite()
1215+
}
1216+
}()
1217+
1218+
// Wait for context cancellation or goroutines to complete
1219+
go func() {
1220+
<-ctx.Done()
1221+
// Force close connections when context is cancelled
1222+
clientConn.Close()
1223+
targetConn.Close()
12021224
}()
12031225

12041226
wg.Wait()

0 commit comments

Comments
 (0)