Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

itest: got error bind: address already in use #8395

Closed
yyforyongyu opened this issue Jan 18, 2024 · 3 comments
Closed

itest: got error bind: address already in use #8395

yyforyongyu opened this issue Jan 18, 2024 · 3 comments
Labels
itests Issues related to integration tests. test flake

Comments

@yyforyongyu
Copy link
Member

As seen in this and many builds,

 harness.go:594: 
            Error Trace:    /home/runner/work/lnd/lnd/lntest/harness.go:594
                                        /home/runner/work/lnd/lnd/lntest/harness.go:633
                                        /home/runner/work/lnd/lnd/lntest/harness.go:368
                                        /home/runner/work/lnd/lnd/lntest/harness.go:395
                                        /home/runner/work/lnd/lnd/itest/lnd_multi-hop_test.go:139
            Error:          Received unexpected error:
                            ConnectRPC err: context deadline exceeded
            Test:           TestLightningNetworkDaemon/tranche03/133-of-139/bitcoind/htlc_timeout_resolver_extract_preimage_local/zeroconf=false/committype=SCRIPT_ENFORCED_LEASE
            Messages:       failed to restart node Bob

This seems to be the last itest flake besides windows build. The logs show the shutdown wasn't clean,

2024-01-18 02:36:39.565 [DBG] RPCS: [/lnrpc.Lightning/StopDaemon] requested
2024-01-18 02:36:39.566 [INF] LTND: Received shutdown request.
2024-01-18 02:36:39.566 [INF] LTND: Shutting down...
2024-01-18 02:36:39.566 [INF] LTND: Gracefully shutting down.
2024-01-18 02:36:39.566 [INF] NANN: Channel Status Manager shutting down...
2024-01-18 02:36:39.566 [DBG] NANN: Channel Status Manager shutdown complete
2024-01-18 02:36:39.566 [INF] HSWC: HTLC Switch shutting down...
2024-01-18 02:36:39.566 [INF] NTFN: Cancelling epoch notification, epoch_id=5
2024-01-18 02:36:39.566 [DBG] HSWC: HTLC Switch shutdown complete
2024-01-18 02:36:39.566 [INF] HSWC: Onion processor shutting down...
2024-01-18 02:36:39.566 [INF] HSWC: Decaying hash log received shutdown request
2024-01-18 02:36:39.566 [INF] NTFN: Cancelling epoch notification, epoch_id=10
2024-01-18 02:36:39.566 [DBG] HSWC: Onion processor shutdown complete
2024-01-18 02:36:39.566 [INF] INVC: InvoiceRegistry shutting down...
2024-01-18 02:36:39.566 [INF] NTFN: Cancelling epoch notification, epoch_id=9
2024-01-18 02:36:39.566 [DBG] INVC: InvoiceRegistry shutdown complete
2024-01-18 02:36:39.566 [INF] CRTR: Channel Router shutting down...
2024-01-18 02:36:39.566 [INF] CRTR: FilteredChainView stopping
2024-01-18 02:36:39.566 [DBG] CRTR: Channel Router shutdown complete
2024-01-18 02:36:39.566 [INF] CNCT: ChainArbitrator shutting down...
2024-01-18 02:36:39.566 [INF] NTFN: Cancelling epoch notification, epoch_id=7
2024-01-18 02:36:39.566 [DBG] CNCT: ChainArbitrator shutdown complete
2024-01-18 02:36:39.566 [INF] FNDG: Funding manager shutting down...
2024-01-18 02:36:39.566 [DBG] FNDG: Funding manager shutdown complete
2024-01-18 02:36:39.566 [INF] BRAR: Breach arbiter shutting down...
2024-01-18 02:36:39.566 [DBG] BRAR: Breach arbiter shutdown complete
2024-01-18 02:36:39.566 [INF] UTXN: UTXO nursery shutting down...
2024-01-18 02:36:39.566 [INF] NTFN: Cancelling epoch notification, epoch_id=4
2024-01-18 02:36:39.566 [DBG] UTXN: UTXO nursery shutdown complete
2024-01-18 02:36:39.566 [INF] DISC: Authenticated gossiper shutting down...
2024-01-18 02:36:39.567 [INF] DISC: Authenticated Gossiper is stopping
2024-01-18 02:36:39.567 [INF] NTFN: Cancelling epoch notification, epoch_id=8
2024-01-18 02:36:39.567 [DBG] DISC: SyncManager is stopping
2024-01-18 02:36:39.567 [DBG] DISC: SyncManager stopped
2024-01-18 02:36:39.567 [DBG] DISC: reliableSender is stopping
2024-01-18 02:36:39.567 [DBG] DISC: reliableSender stopped
2024-01-18 02:36:39.567 [INF] DISC: Authenticated Gossiper stopped
2024-01-18 02:36:39.567 [DBG] DISC: Authenticated gossiper shutdown complete
2024-01-18 02:36:39.567 [INF] SWPR: Sweeper shutting down...
2024-01-18 02:36:39.567 [INF] NTFN: Cancelling epoch notification, epoch_id=3
2024-01-18 02:36:39.567 [DBG] SWPR: Sweeper shutdown complete
2024-01-18 02:36:39.567 [INF] CHNF: ChannelNotifier shutting down...
2024-01-18 02:36:39.567 [DBG] CHNF: ChannelNotifier shutdown complete
2024-01-18 02:36:39.567 [INF] PRNF: PeerNotifier shutting down...
2024-01-18 02:36:39.567 [DBG] PRNF: PeerNotifier shutdown complete
2024-01-18 02:36:39.567 [INF] HSWC: HtlcNotifier shutting down...
2024-01-18 02:36:39.567 [DBG] HSWC: HtlcNotifier shutdown complete
2024-01-18 02:36:39.567 [INF] CHBU: chanbackup.SubSwapper shutting down...
2024-01-18 02:36:39.567 [DBG] CHBU: chanbackup.SubSwapper shutdown complete
2024-01-18 02:36:39.567 [INF] NTFN: bitcoind notifier shutting down...
2024-01-18 02:36:39.567 [INF] NTFN: Stopping mempool notifier
2024-01-18 02:36:39.567 [DBG] NTFN: mempool notifier stopped
2024-01-18 02:36:39.567 [DBG] NTFN: bitcoind notifier shutdown complete
2024-01-18 02:36:39.567 [ERR] NTFN: dead epoch stream in BestBlockTracker
2024-01-18 02:36:39.567 [INF] CHFT: ChannelEventStore shutting down...
2024-01-18 02:36:39.567 [DBG] CHFT: recording flap count for: 0 peers
2024-01-18 02:36:39.567 [ERR] HSWC: InterceptableSwitch stopped: block epoch stream stopped
2024-01-18 02:36:39.567 [DBG] CHFT: ChannelEventStore shutdown complete
2024-01-18 02:36:39.567 [DBG] CRTR: Stopping mission control store ticker
2024-01-18 02:36:39.567 [DBG] CRTR: Mission control store ticker stopped
2024-01-18 02:36:39.567 [INF] HLCK: Health monitor shutting down
2024-01-18 02:36:39.567 [DBG] HLCK: Health check: monitor quit
2024-01-18 02:36:39.567 [DBG] SRVR: Waiting for server to shutdown...
2024-01-18 02:36:39.567 [DBG] SRVR: Stopping buffer pools...
2024-01-18 02:36:39.567 [INF] RPCS: Stopping RPC Server
2024-01-18 02:36:39.567 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping VersionRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping WatchtowerRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping RouterRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping PeersRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping NeutrinoKitRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping WatchtowerClientRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping DevRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] RPCS: Stopping AutopilotRPC Sub-RPC Server
2024-01-18 02:36:39.568 [INF] LTND: Stopping pprof server...
2024-01-18 02:36:39.569 [INF] LTND: Shutdown complete

2024-01-18 02:36:39.610 [WRN] LTND: open /tmp/lndtest-node150679254/lnd.conf: no such file or directory
2024-01-18 02:36:39.610 [INF] LTND: Version: 0.17.0-beta commit=, build=development, logging=default, debuglevel=debug,DISC=trace
2024-01-18 02:36:39.610 [INF] LTND: Active chain: Bitcoin (network=regtest)
2024-01-18 02:36:39.610 [INF] LTND: Pprof listening on 127.0.0.1:8572
2024-01-18 02:36:41.148 [ERR] LTND: Shutting down because error in main method: unable to listen on 127.0.0.1:8570: listen tcp4 127.0.0.1:8570: bind: address already in use
2024-01-18 02:36:41.148 [INF] LTND: Stopping pprof server...
2024-01-18 02:36:41.148 [INF] LTND: Shutdown complete

unable to listen on 127.0.0.1:8570: listen tcp4 127.0.0.1:8570: bind: address already in use

Maybe fixed by #8273?
@yyforyongyu yyforyongyu added test flake itests Issues related to integration tests. labels Jan 18, 2024
@Roasbeef
Copy link
Member

IIRC, we recently switched to slightly different method of obtaining an active port, but maybe that was only for btcd?

@guggero
Copy link
Collaborator

guggero commented Jan 19, 2024

#8273 only fixes the port collision for the unit tests. I think in the itests we already have some port collision prevention code, but maybe we can upgrade the integration tests to use the "per process file based" port collision prevention code introduced in #8273 as well.

@yyforyongyu
Copy link
Member Author

I think what went wrong here is not port collision but the shutdown didn't clean up the port.

@yyforyongyu yyforyongyu mentioned this issue Feb 5, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
itests Issues related to integration tests. test flake
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Roasbeef @guggero @yyforyongyu