SIGINT never gets around to shutting down node

[saurik]

System information

Geth version: 1.9.24-stable
OS & Version: Linux
Commit hash : cc05b05

Expected behaviour

SIGINT causes node to shut down in a reasonable amount of time.

Actual behaviour

Over ten minutes later I'm still waiting for the node to shut down.

Steps to reproduce the behaviour

Attempt to shut down a running node using SIGINT.

Backtrace

I saw #1379 had been asked for the log after you just panic it, so:

sigint.log

[holiman]

Interesting. @zsfelfoldi the stack has a ton of these:

goroutine 33251500 [sync.Cond.Wait, 12 minutes]:
runtime.goparkunlock(...)
        runtime/proc.go:312
sync.runtime_notifyListWait(0xc0fd57ca10, 0x7b)
        runtime/sema.go:513 +0xf8
sync.(*Cond).Wait(0xc0fd57ca00)
        sync/cond.go:56 +0x9d
github.com/ethereum/go-ethereum/p2p/nodestate.(*NodeStateMachine).opStart(0xc0fd5d81c0, 0x35)
        github.com/ethereum/go-ethereum/p2p/nodestate/nodestate.go:703 +0x2c
github.com/ethereum/go-ethereum/p2p/nodestate.(*NodeStateMachine).SetField(0xc0fd5d81c0, 0xc119f781c0, 0x2, 0x1e6ea40, 0x0, 0x0, 0x0, 0x0)
        github.com/ethereum/go-ethereum/p2p/nodestate/nodestate.go:865 +0x7b
github.com/ethereum/go-ethereum/les.(*clientPool).disconnectNode(0xc109244420, 0xc119f781c0)
        github.com/ethereum/go-ethereum/les/clientpool.go:264 +0x65
github.com/ethereum/go-ethereum/les.(*clientPool).disconnect(0xc109244420, 0x1555560, 0xc188ef99e0)
        github.com/ethereum/go-ethereum/les/clientpool.go:259 +0x3f
github.com/ethereum/go-ethereum/les.(*serverHandler).handle.func3(0xc115b93790, 0xc0fc8e94a0, 0xc188ef99e0, 0x4cd377491a824)
        github.com/ethereum/go-ethereum/les/server_handler.go:180 +0x5e
github.com/ethereum/go-ethereum/les.(*serverHandler).handle(0xc0fc8e94a0, 0xc188ef99e0, 0x15349c0, 0xc00006a060)
        github.com/ethereum/go-ethereum/les/server_handler.go:200 +0xa40
github.com/ethereum/go-ethereum/les.(*serverHandler).runPeer(0xc0fc8e94a0, 0x3, 0xc1fed021e0, 0x15438a0, 0xc1c27d2a00, 0x0, 0x0)
        github.com/ethereum/go-ethereum/les/server_handler.go:112 +0x10e
github.com/ethereum/go-ethereum/les.(*lesCommons).makeProtocols.func1(0xc1fed021e0, 0x15438a0, 0xc1c27d2a00, 0xf8ae76f84067e5d4, 0x67f5d5406ab810c0)
        github.com/ethereum/go-ethereum/les/commons.go:97 +0x4c
github.com/ethereum/go-ethereum/p2p.(*Peer).startProtocols.func1(0xc1fed021e0, 0xc1c27d2a00, 0x15438a0, 0xc1c27d2a00)
        github.com/ethereum/go-ethereum/p2p/peer.go:379 +0x98
created by github.com/ethereum/go-ethereum/p2p.(*Peer).startProtocols
        github.com/ethereum/go-ethereum/p2p/peer.go:377 +0x205

Where looks like we're trying to disconnect a node les.(*clientPool).disconnectNode(, but get stuck on some sync.Cond. PTAL

@saurik what's was the command line that started it?

[saurik]

@holiman Here is the script I use to start the node. (I have a firewall set up external to this box to prevent anyone from accessing those 0.0.0.0 bound endpoints.)

#!/bin/bash
ulimit -n 65535
exec geth \
    --cache $((24*1024)) \
    --http --http.addr 0.0.0.0 --http.api eth,web3,net --http.vhosts '*' \
    --ws --ws.addr 0.0.0.0 \
    --graphql --graphql.vhosts '*' \
    --nousb --light.serve 50

One thing I also noticed (which I explicitly looked for due to that linked issue) is that there was, in fact, some kind of long-running leveldb compaction happening?

[holiman]

some kind of long-running leveldb compaction happening?

Yes, it's a background compaction in leveldb

[holiman]

Thanks for the detailed report!