SagerNet / SagerNet/sing-box

URLTest delay includes the whole connection setup when WebSocket early data is enabled

Open
#4,451 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Go
Stars
38.1k
Forks
4.6k
Avg merge
19d 15h
Merged PRs (30d)
1

Description

Operating system

Others (platform independent)

System version

N/A — the behaviour is in shared Go code, not platform specific. Measured on macOS 15.

Installation type

Original sing-box Command Line

Version
testing @ 77bd3261367463b970648edf445c88ac541b3bf2 (1.14.0-rc.1)
Description

Enabling max_early_data on the ws transport makes the delay reported by URLTest go up by roughly 3x for the same server, even though early data saves a round trip on the wire.

Measured with the repro below, one sing-box process, two vless + ws + TLS inbounds that differ only in max_early_data, both reached through a proxy that adds 25 ms per hop (50 ms RTT):

URLTest delay via plain  = 56 ms
URLTest delay via early  = 191 ms
URLTest delay via plain  = 54 ms
URLTest delay via early  = 193 ms
URLTest delay via plain  = 55 ms
URLTest delay via early  = 168 ms

The cause is that URLTest restarts its timer after DialContext returns:

https://github.com/SagerNet/sing-box/blob/77bd3261367463b970648edf445c88ac541b3bf2/common/urltest/urltest.go#L105-L107

That reset was added in 61ac1411 ("Improve URLTest delay calculate") and assumes that when the returned connection still needs a handshake for write, the network connection was already established during DialContext and only the protocol header is pending. That holds for vless/trojan/vmess over plain TLS, so the reported delay is one round trip — the 56 ms above.

With max_early_data > 0 the assumption breaks: v2raywebsocket.Client.DialContext() returns an EarlyWebsocketConn without touching the network, and the TCP connect, TLS handshake and WebSocket upgrade all happen on the first write, i.e. after the timer was reset:

https://github.com/SagerNet/sing-box/blob/77bd3261367463b970648edf445c88ac541b3bf2/transport/v2raywebsocket/client.go#L111-L121

So the two cases do not measure the same thing:

what the reported delay covers measured at 50 ms RTT
ws request round trip only ~55 ms
ws + early data TCP connect + TLS handshake + WebSocket upgrade + request ~185 ms

The practical effect is that the number shown for an early-data outbound is not comparable with the number shown for any other outbound, and a urltest group will systematically rank early-data servers last even when they are the fastest ones.

I am reporting the mechanism rather than sending a patch, because which of the two definitions of "delay" is the intended one is a design decision:

  • keep the current definition (request round trip only) and find a way to exclude the deferred setup for lazily dialed transports, or
  • always include the connection setup, which would make the numbers consistent across outbounds and would let early data show the round trip it actually saves, at the cost of raising every reported delay.

Unrelated to the choice above, URLTest already runs urlTest twice for multiplex outbounds to avoid measuring session setup, so there is precedent for treating "the connection does not exist yet" as something to warm up rather than to measure.

Reproduction

Drop this into test/ and run go test -run TestURLTestEarlyDataDelay -v. It needs no remote server and no Docker; latencyProxy supplies the round trip time that makes the difference visible.

test/urltest_early_data_test.go
package main

import (
	"context"
	"fmt"
	"io"
	"net"
	"net/http"
	"net/netip"
	"testing"
	"time"

	"github.com/sagernet/sing-box/adapter"
	"github.com/sagernet/sing-box/common/urltest"
	C "github.com/sagernet/sing-box/constant"
	"github.com/sagernet/sing-box/option"
	"github.com/sagernet/sing/common"
	"github.com/sagernet/sing/common/json/badoption"

	"github.com/gofrs/uuid/v5"
	"github.com/stretchr/testify/require"
)

func vlessWSInbound(port uint16, user string, certPem, keyPem string, early uint32) option.Inbound {
	transport := &option.V2RayTransportOptions{
		Type:             C.V2RayTransportTypeWebsocket,
		WebsocketOptions: option.V2RayWebsocketOptions{Path: "/"},
	}
	if early > 0 {
		transport.WebsocketOptions.MaxEarlyData = early
		transport.WebsocketOptions.EarlyDataHeaderName = "Sec-WebSocket-Protocol"
	}
	return option.Inbound{
		Type: C.TypeVLESS,
		Options: &option.VLESSInboundOptions{
			ListenOptions: option.ListenOptions{
				Listen:     common.Ptr(badoption.Addr(netip.IPv4Unspecified())),
				ListenPort: port,
			},
			Users: []option.VLESSUser{{UUID: user}},
			InboundTLSOptionsContainer: option.InboundTLSOptionsContainer{
				TLS: &option.InboundTLSOptions{
					Enabled: true, ServerName: "example.org",
					CertificatePath: certPem, KeyPath: keyPem,
				},
			},
			Transport: transport,
		},
	}
}

func vlessWSOutbound(tag string, port uint16, user string, certPem string, early uint32) option.Outbound {
	transport := &option.V2RayTransportOptions{
		Type:             C.V2RayTransportTypeWebsocket,
		WebsocketOptions: option.V2RayWebsocketOptions{Path: "/"},
	}
	if early > 0 {
		transport.WebsocketOptions.MaxEarlyData = early
		transport.WebsocketOptions.EarlyDataHeaderName = "Sec-WebSocket-Protocol"
	}
	return option.Outbound{
		Type: C.TypeVLESS,
		Tag:  tag,
		Options: &option.VLESSOutboundOptions{
			ServerOptions: option.ServerOptions{Server: "127.0.0.1", ServerPort: port},
			UUID:          user,
			OutboundTLSOptionsContainer: option.OutboundTLSOptionsContainer{
				TLS: &option.OutboundTLSOptions{
					Enabled: true, ServerName: "example.org", CertificatePath: certPem,
				},
			},
			Transport: transport,
		},
	}
}

func latencyPipe(dst io.Writer, src io.Reader, delay time.Duration) {
	buffer := make([]byte, 32*1024)
	for {
		n, err := src.Read(buffer)
		if n > 0 {
			time.Sleep(delay)
			if _, writeErr := dst.Write(buffer[:n]); writeErr != nil {
				return
			}
		}
		if err != nil {
			return
		}
	}
}

// latencyProxy forwards listenPort to targetPort, adding delay to the connect
// and to every chunk in each direction, so one round trip costs 2*delay.
func latencyProxy(t *testing.T, listenPort, targetPort uint16, delay time.Duration) {
	listener, err := net.Listen("tcp", fmt.Sprintf("127.0.0.1:%d", listenPort))
	require.NoError(t, err)
	t.Cleanup(func() { listener.Close() })
	go func() {
		for {
			conn, err := listener.Accept()
			if err != nil {
				return
			}
			go func() {
				defer conn.Close()
				time.Sleep(delay)
				upstream, err := net.Dial("tcp", fmt.Sprintf("127.0.0.1:%d", targetPort))
				if err != nil {
					return
				}
				defer upstream.Close()
				go latencyPipe(conn, upstream, delay)
				latencyPipe(upstream, conn, delay)
			}()
		}
	}()
}

func TestURLTestEarlyDataDelay(t *testing.T) {
	user, err := uuid.DefaultGenerator.NewV4()
	require.NoError(t, err)
	_, certPem, keyPem := createSelfSignedCertificate(t, "example.org")

	listener, err := net.Listen("tcp", fmt.Sprintf("127.0.0.1:%d", testPort))
	require.NoError(t, err)
	server := &http.Server{Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		w.WriteHeader(http.StatusNoContent)
	})}
	go server.Serve(listener)
	defer server.Close()

	const hop = 25 * time.Millisecond
	latencyProxy(t, otherClientPort, serverPort, hop)
	latencyProxy(t, otherClientPort+1, otherPort, hop)

	instance := startInstance(t, option.Options{
		Inbounds: []option.Inbound{
			vlessWSInbound(serverPort, user.String(), certPem, keyPem, 0),
			vlessWSInbound(otherPort, user.String(), certPem, keyPem, 2560),
		},
		Outbounds: []option.Outbound{
			{Type: C.TypeDirect},
			vlessWSOutbound("plain", otherClientPort, user.String(), certPem, 0),
			vlessWSOutbound("early", otherClientPort+1, user.String(), certPem, 2560),
		},
	})

	link := fmt.Sprintf("http://127.0.0.1:%d/", testPort)
	for _, tag := range []string{"plain", "early", "plain", "early", "plain", "early"} {
		out, ok := instance.Outbound().Outbound(tag)
		require.True(t, ok)
		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
		delay, err := urltest.URLTest(ctx, link, out.(adapter.Outbound))
		cancel()
		require.NoError(t, err)
		t.Logf("URLTest delay via %-6s = %d ms", tag, delay)
	}
}

Two notes about running it: test/go.mod is currently stale relative to the root module, so go mod tidy has to be run in test/ first, and the module only links on Go ~1.26 or older because of the //go:linkname to golang.org/x/net/http2.(*Transport).connPool in transport/v2rayhttp/force_close.go.

The same difference shows up with an ordinary config: two outbounds pointing at the same ws server, identical except for max_early_data, both listed in a urltest group, then compare the delays in the Dashboard or through the Clash API.

Logs
N/A — nothing is logged as an error; the delay value itself is the symptom.
Supporter
Integrity requirements
  • I confirm that I have read the documentation, understand the meaning of all the configuration items I wrote, and did not pile up seemingly useful options or default values.
  • I confirm that I have provided the server and client configuration files and process that can be reproduced locally, instead of a complicated client configuration file that has been stripped of sensitive data.
  • I confirm that I have provided the simplest configuration that can be used to reproduce the error I reported, instead of depending on remote servers, TUN, graphical interface clients, or other closed-source software.
  • I confirm that I have provided the complete configuration files and logs, rather than just providing parts I think are useful out of confidence in my own intelligence.

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the timer reset in common/urltest/urltest.go and the lazy connection behavior in transport/v2raywebsocket/client.go. Run test/urltest_early_data_test.go with the stated test module setup to reproduce the mismatch. Done requires an agreed definition of URLTest delay and regression coverage showing consistent behavior for early-data and plain WebSocket outbounds.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
networking
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Active
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.