Skip to content

net: pure-Go DNS resolver occasionally delayed by GC/scheduler — kernel receives UDP but userspace processes late (short DNSLookup spikes) #75517

@keon2024

Description

@keon2024

Go version

go1.20 - go 1.24 linux/amd64

Output of go env in your module/workspace:

AR='ar'
CC='clang'
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_ENABLED='1'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
CXX='clang++'
GCCGO='gccgo'
GO111MODULE=''
GOAMD64='v1'
GOARCH='amd64'
GOAUTH='netrc'
GOBIN=''
GOCACHE='/Users/edy/Library/Caches/go-build'
GOCACHEPROG=''
GODEBUG=''
GOENV='/Users/edy/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFIPS140='off'
GOFLAGS=''
GOGCCFLAGS='-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/kc/p5h1tshd1r5dldk97dglrgrh0000gn/T/go-build2170672662=/tmp/go-build -gno-record-gcc-switches -fno-common'
GOHOSTARCH='amd64'
GOHOSTOS='darwin'
GOMOD='/dev/null'
GOMODCACHE='/Users/edy/go/pkg/mod'
GOOS='linux'
GOPATH='/Users/edy/go'
GOPROXY='https://goproxy.cn,direct'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTELEMETRY='local'
GOTELEMETRYDIR='/Users/edy/Library/Application Support/go/telemetry'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/darwin_amd64'
GOVCS=''
GOVERSION='go1.24.6'
GOWORK=''
PKG_CONFIG='pkg-config'

What did you do?

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
	"os"
	"runtime"
	"runtime/trace"
	"sync"
	"time"

	"github.com/go-resty/resty/v2"
)

var (
	profilingOnce sync.Once
)

func CpuProfiling() {
	profilingOnce.Do(func() {
		profilingDone := make(chan struct{})
		timestamp := time.Now().Format("2006-01-02-15-04-05")
		//profFileName := fmt.Sprintf("cpu-%s.prof", timestamp)
		profFileName := fmt.Sprintf("trace-%s.out", timestamp)
		f, err := os.Create(profFileName)
		if err != nil {
			fmt.Println("create cpu profile file error:", err)
			close(profilingDone)
			return
		}
		defer f.Close()
		fmt.Print("Timestamp:", time.Now().Format("2006-01-02 15:04:05"))
		fmt.Println(" Profiling start")
		if err := trace.Start(f); err != nil {
			//if err := pprof.StartCPUProfile(f); err != nil {
			fmt.Println("start cpu profile error:", err)
			close(profilingDone)
			return
		}

		go func() {
			time.Sleep(3 * time.Second)
			fmt.Print("Timestamp:", time.Now().Format("2006-01-02 15:04:05"))
			fmt.Println(" Profiling stopped after 3 seconds")
			//pprof.StopCPUProfile()
			trace.Stop()
			fmt.Print("Timestamp:", time.Now().Format("2006-01-02 15:04:05"))
			fmt.Println(" Profiling stopped")
			close(profilingDone)
		}()

		// 等待profiling完成
		<-profilingDone
	})

}

func main() {
	runtime.GOMAXPROCS(runtime.NumCPU())

	// 启动HTTP服务器用于pprof
	go func() {
		fmt.Println("Starting pprof server on :6060")
		if err := http.ListenAndServe(":6060", nil); err != nil {
			fmt.Printf("pprof server error: %v\n", err)
		}
	}()

	//client := httpclient.NewRestyClientWithDNSCache()
	client := resty.New()
	//client := xhttp.Client(context.Background())
	var lock sync.RWMutex
	dnsMaxDelay := float64(0)

	ticker := time.NewTicker(time.Second / 6000)
	defer ticker.Stop()

	requestChan := make(chan int, 100000)
	go func() {
		for i := 0; ; i++ {
			select {
			case <-ticker.C:
				requestChan <- i
			}
		}
	}()

	for {
		select {
		case i := <-requestChan:
			go func() {
				//resp, _ := xhttp.Client(context.TODO()).DNSCache(false).Request().

				resp, _ := client.R().EnableTrace().
					Get("http://host:8080/api/test")
				ti := resp.Request.TraceInfo()
				d := ti.DNSLookup.Seconds() * float64(1000)
				lock.Lock()
				if d > dnsMaxDelay {
					dnsMaxDelay = d
				}
				lock.Unlock()
				if d > 300 {
					fmt.Print("Timestamp:", time.Now().Format("2006-01-02 15:04:05"))
					fmt.Print(", Request #", i)
					fmt.Print(", Status Code: ", resp.StatusCode())
					fmt.Print(", DNSLookup: ", d)
					fmt.Println(", MaxDNSLookup: ", dnsMaxDelay)
					// start profiling
					CpuProfiling()
				}
			}()
		default:
			continue
		}
	}
}

type User struct {
	ID    int            `json:"id"`
	Name  string         `json:"name"`
	Tags  []string       `json:"tags"`
	Extra map[string]any `json:"extra"`
}

DNS_问题.pdf

What did you see happen?

You need to replace the address used in the resty request in the above code with a URL that is accessible to you. After executing the code, within a few minutes, you will notice numerous DNS-related errors. These errors are not caused by the resty package but are due to delays in the Go scheduler. The documentation provides detailed troubleshooting steps.

What did you expect to see?

We hope the official team can optimize this issue in future versions, as using Go’s standard net package for HTTP requests is a widespread scenario that may affect a large number of Go developers. We look forward to seeing better and improved versions of the Go language in the future.

Metadata

Metadata

Assignees

No one assigned

    Labels

    BugReportIssues describing a possible bug in the Go implementation.NeedsInvestigationSomeone must examine and confirm this is a valid issue and not a duplicate of an existing one.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions