search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
124.14k stars 17.69k forks source link

x/tools/internal/lsp/lsprpc: TestClientLoggingV2 failure with "timeout waiting for client log" #50724

Open bcmills opened 2 years ago

bcmills commented 2 years ago 
#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2022/01/20 18:03:54 New server
    new_server="1"
    logfile=""
    debug_address=""
    gopls_path="/tmp/workdir-host-freebsd-arm64-dmgk/tmp/go-build3210943659/b793/lsprpc.test"
    client_id="3"
2022/01/20 18:03:54 forwarder: exited with error: remote disconnected: failed reading header line: read tcp 127.0.0.1:58365->127.0.0.1:25447: use of closed network connection
2022/01/20 18:03:55 New server
    new_server="3"
    logfile=""
    debug_address=""
    gopls_path="/tmp/workdir-host-freebsd-arm64-dmgk/tmp/go-build3210943659/b793/lsprpc.test"
    client_id="6"
2022/01/20 18:03:57 forwarder: exited with error: remote disconnected: failed reading header line: read tcp 127.0.0.1:25208->127.0.0.1:60842: use of closed network connection
2022/01/20 18:03:57 ping
2022/01/20 18:03:58 jsonrpc2 message delivery failed: JSON RPC internal error: "window/logMessage" notification failed: io: read/write on closed pipe: JSON RPC internal error
2022/01/20 18:03:58 ping
--- FAIL: TestClientLoggingV2 (1.58s)
    --- FAIL: TestClientLoggingV2/forwarded (1.58s)
        binder_test.go:111: timeout waiting for client log
FAIL
FAIL    golang.org/x/tools/internal/lsp/lsprpc  5.125s

greplogs --dashboard -md -l -e 'timeout waiting for client log' --since=2021-01-01

2022-01-20T14:52:25-ab35822-9de1ac6/freebsd-arm64-dmgk

CC @findleyr

bcmills commented 2 years ago

Now that the freebsd-amd64-race builder is back, it caught one too. Looks like the same failure mode, and it's a scalable builder (so might be easier to reproduce with a gomote).

greplogs --dashboard -md -l -e 'timeout waiting for client log' --since=2022-01-21

2022-02-04T14:03:20-8305295-1b867ce/freebsd-amd64-race

2022/02/04 14:11:02 New server
    new_server="1"
    logfile=""
    debug_address=""
    gopls_path="/tmp/workdir/tmp/go-build2798088286/b793/lsprpc.test"
    client_id="3"
2022/02/04 14:11:02 forwarder: exited with error: remote disconnected: failed reading header line: read tcp 127.0.0.1:53063->127.0.0.1:14348: use of closed network connection
2022/02/04 14:11:05 New server
    new_server="3"
    logfile=""
    debug_address=""
    gopls_path="/tmp/workdir/tmp/go-build2798088286/b793/lsprpc.test"
    client_id="6"
2022/02/04 14:11:06 forwarder: exited with error: client disconnected: io: read/write on closed pipe
2022/02/04 14:11:06 ping
2022/02/04 14:11:08 ping
--- FAIL: TestClientLoggingV2 (1.31s)
    --- FAIL: TestClientLoggingV2/forwarded (1.29s)
        binder_test.go:111: timeout waiting for client log
2022/02/04 14:11:08 jsonrpc2 message delivery failed: io: read/write on closed pipe
2022/02/04 14:11:08 jsonrpc2 message delivery failed: io: read/write on closed pipe
FAIL
FAIL    golang.org/x/tools/internal/lsp/lsprpc  5.853s
heschi commented 2 years ago

2022-07-01T14:51:09-f042799-8d2935a/freebsd-amd64-race

bcmills commented 2 years ago

2022-08-04T18:51:46-99fd76f-a10afb1/freebsd-amd64-race

bcmills commented 11 months ago

https://ci.chromium.org/ui/p/golang/builders/ci/x_tools-gotip-wasip1-wasm_wasmtime/b8761768142198806625/overview

gopherbot commented 9 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-02-03 21:27 x_tools-go1.22-wasip1-wasm_wasmtime tools@a1fbc781 release-branch.go1.22@b0957cfc x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/02/03 21:33:26 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.39s)

— watchflakes

gopherbot commented 9 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-02-12 19:37 x_tools-go1.22-wasip1-wasm_wasmtime tools@50b4f1b1 release-branch.go1.22@20107e05 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/02/12 19:47:48 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.25s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-02-29 21:45 x_tools-go1.22-wasip1-wasm_wasmtime tools@5bf7d005 release-branch.go1.22@16830ab4 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/02/29 21:52:00 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.25s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-07 17:26 x_tools-gotip-wasip1-wasm_wasmtime tools@070fcfb9 go@da5871d5 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/standalone (log) === RUN TestClientLoggingV2/standalone 2024/03/07 17:36:57 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/standalone (1.49s)
2024-03-07 22:04 x_tools-go1.22-wasip1-wasm_wasmtime tools@656fcde9 release-branch.go1.22@db6097f8 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/07 22:10:38 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.31s)
2024-03-08 15:27 x_tools-go1.22-wasip1-wasm_wasmtime tools@31f056a4 release-branch.go1.22@db6097f8 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/08 15:37:43 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.43s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-14 17:37 x_tools-go1.21-wasip1-wasm_wasmtime tools@e2567148 release-branch.go1.21@140b37d6 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/14 17:43:29 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.43s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-18 17:50 x_tools-go1.22-wasip1-wasm_wasmtime tools@6d9ecf22 release-branch.go1.22@db6097f8 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded binder_test.go:156: timeout waiting for client log 2024/03/18 17:59:42 ping --- FAIL: TestClientLoggingV2/forwarded (1.35s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-19 15:15 x_tools-go1.22-wasip1-wasm_wasmtime tools@0fb9b7b7 release-branch.go1.22@db6097f8 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/19 15:24:38 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.25s)

— watchflakes

gopherbot commented 8 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-19 19:46 x_tools-go1.22-wasip1-wasm_wasmtime tools@dd526462 release-branch.go1.22@db6097f8 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/19 19:55:52 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.52s)

— watchflakes

gopherbot commented 7 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-03-26 14:22 x_tools-go1.22-wasip1-wasm_wasmtime tools@867c912e release-branch.go1.22@35b1a146 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/26 14:33:12 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.40s)
2024-03-29 16:14 x_tools-go1.22-wasip1-wasm_wasmtime tools@96639992 release-branch.go1.22@4edf4bb2 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/03/29 16:25:04 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.26s)
2024-04-02 20:54 x_tools-go1.22-wasip1-wasm_wasmtime tools@85b65275 release-branch.go1.22@4edf4bb2 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded binder_test.go:156: timeout waiting for client log 2024/04/02 20:59:45 ping --- FAIL: TestClientLoggingV2/forwarded (1.56s)
2024-04-02 20:54 x_tools-gotip-wasip1-wasm_wasmtime tools@0a4fc723 go@b6efc3b7 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/standalone (log) === RUN TestClientLoggingV2/standalone 2024/04/02 21:03:42 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/standalone (1.50s)
2024-04-08 15:12 x_tools-go1.22-wasip1-wasm_wasmtime tools@5c3c2ff0 release-branch.go1.22@a65a2bbd x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/04/08 15:23:41 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.30s)
2024-04-08 16:03 x_tools-gotip-wasip1-wasm_wasmtime tools@de6db989 go@da732dd1 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/04/08 16:09:53 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.54s)
2024-04-10 13:15 x_tools-go1.21-wasip1-wasm_wasmtime tools@c4c0bf99 release-branch.go1.21@74501172 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/04/10 13:25:17 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.38s)

— watchflakes

gopherbot commented 6 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-05-15 17:13 x_tools-go1.22-wasip1-wasm_wasmtime tools@528484d5 release-branch.go1.22@3a842931 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/05/15 17:35:02 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.01s)

— watchflakes

gopherbot commented 4 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-07-15 17:52 x_tools-go1.23-wasip1-wasm_wasmtime tools@da125806 release-branch.go1.23@30b6fd60 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/07/16 15:48:46 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.25s)

— watchflakes

gopherbot commented 3 months ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-07-31 20:28 x_tools-go1.21-wasip1-wasm_wasmtime tools@ead76ab5 release-branch.go1.21@dabed2e0 x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/07/31 20:34:14 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.17s)

— watchflakes

gopherbot commented 1 month ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-09-19 23:09 x_tools-go1.22-wasip1-wasm_wasmtime tools@8517dc99 release-branch.go1.22@b4086b7c x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/09/19 23:19:54 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.26s)

— watchflakes

gopherbot commented 1 month ago

Found new dashboard test flakes for:

#!watchflakes
post <- (pkg == "golang.org/x/tools/gopls/internal/lsp/lsprpc" || pkg == "golang.org/x/tools/gopls/internal/lsprpc") &&
    test ~ `TestClientLoggingV2` &&
    `timeout waiting for client log`
2024-09-27 21:39 x_tools-gotip-wasip1-wasm_wasmtime tools@7d92dd6f go@676d427f x/tools/gopls/internal/lsprpc.TestClientLoggingV2/forwarded (log) === RUN TestClientLoggingV2/forwarded 2024/09/27 21:48:08 ping binder_test.go:156: timeout waiting for client log --- FAIL: TestClientLoggingV2/forwarded (1.12s)

— watchflakes