Skip to content

ping: Don't log idle timeout as error - #18

Open
gonghao wants to merge 1 commit into
MetaCubeX:metafrom
gonghao:fix-ping-idle-timeout-log
Open

ping: Don't log idle timeout as error#18
gonghao wants to merge 1 commit into
MetaCubeX:metafrom
gonghao:fix-ping-idle-timeout-log

Conversation

@gonghao

@gonghao gonghao commented Aug 25, 2026

Copy link
Copy Markdown

Problem

Every ICMP session that finishes normally leaves an ERROR line behind:

level=info  msg="[ICMP] icmp 192.168.188.63:0 --> 8.8.8.8:0 using DIRECT"
level=error msg="receive ICMP echo reply: read ip 192.168.10.1: i/o timeout"

The two lines are exactly idleTimeout apart (measured: 16:58:11.78018416:58:21.780487, i.e. 10.0003s), and the pings themselves succeed — the client sees 0% loss. On a router where a device does periodic connectivity probes, this accumulates hundreds of ERROR entries that are pure noise.

The address in the message is also misleading: it is the local address the raw socket got bound to (ip route get 8.8.8.8src 192.168.10.1), not the ping target, so every direct ICMP session reports the same IP.

Cause

loopRead re-arms a read deadline on every iteration, so a destination that stops receiving echo replies exits with a deadline error. That is the intended end of an idle session — the defer d.Close() added in the same commit exists for exactly this path.

But the error classification was never updated to match. E.IsClosed only covers io.EOF, net.ErrClosed, io.ErrClosedPipe, os.ErrClosed, EPIPE, ECONNRESET and ENOTCONN, so the deadline error falls through to ErrorContext.

The check dates back to 53dbe7b ("Add ping support"), where ReadIP blocked forever and the only possible errors were genuine failures — correct at the time. 5133fee ("ping: Add timeout to destinations") introduced SetReadDeadline and a third, benign exit path, but left the branch untouched.

Fix

Use E.IsClosedOrCanceled, which is IsClosed || IsCanceled || IsTimeout.

E.IsTimeout matches through the net.Error interface, so it covers both conns:

  • ping/destination.go — syscall conn, returns os.ErrDeadlineExceeded
  • ping/destination_gvisor.gogonet returns its own timeoutError{} with Timeout() == true; note that errors.Is(err, os.ErrDeadlineExceeded) would not work here even though the message string is identical

Genuine timeouts are not lost: in both loops the re-armed deadline is the only source of a timeout error.

Verification

go build and go vet pass for linux, darwin, windows and android/arm64, with and without the with_gvisor tag. go test ./ping/... passes.

`loopRead` sets a read deadline of `d.timeout` on every iteration, so a
destination that stops receiving echo replies ends its loop with
`os.ErrDeadlineExceeded` (gonet returns its own `net.Error` with
`Timeout() == true`). That is the intended lifetime end of an idle ICMP
session — `defer d.Close()` right above it exists for exactly this path.

`E.IsClosed` only covers EOF/ErrClosed/EPIPE/ECONNRESET/ENOTCONN, so the
deadline error falls through to `ErrorContext` and every normally
finished ICMP session leaves behind

    receive ICMP echo reply: read ip 192.168.1.1: i/o timeout

The check dates back to the initial commit, when `ReadIP` blocked
forever and the only possible errors were real ones. `SetReadDeadline`
was introduced later without updating it.

Use `E.IsClosedOrCanceled`, which additionally covers `E.IsTimeout` via
the `net.Error` interface and therefore handles both the syscall and the
gVisor conn.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant