invalid address-in-use error on macOS?

[Sajjon]

Description

I've updated to 1.10.21 of Geth and 3.0.0 of Lighthouse, I'm trying to launch lighthouse in two tabs (I used to run terminal tab with lighthouse bn --staking and one with lighthouse vc):

I've launch geth with:

geth --authrpc.addr localhost --authrpc.port 8551 --authrpc.vhosts localhost --authrpc.jwtsecret ~/Library/Ethereum/geth/jwtsecret

Im trying to launch lighthouse with

$ lighthouse \
    --network mainnet \
    beacon_node \
    --http \
    --execution-endpoint http://localhost:8551 \
    --execution-jwt ~/Library/Ethereum/geth/jwtsecret

But this fails to launch, I get "Address already in use"

Error log

Aug 24 05:59:17.425 INFO Logging to file                         path: "/Users/sajjode/.lighthouse/mainnet/beacon/logs/beacon.log"
Aug 24 05:59:17.425 INFO Lighthouse started                      version: Lighthouse/v3.0.0-18c61a5
Aug 24 05:59:17.425 INFO Configured for network                  name: mainnet
Aug 24 05:59:17.426 INFO Data directory initialised              datadir: /Users/sajjode/.lighthouse/mainnet
Aug 24 05:59:17.426 INFO Deposit contract                        address: 0x00000000219ab540356cbb839cbe05303d7705fa, deploy_block: 11184524
Aug 24 05:59:18.000 INFO Hot-Cold DB initialized                 split_state: 0x15f183efd9e1913422189059845b3f1c27f66706ce7de6b6b083f92a7d395f04, split_slot: 4541216, service: freezer_db
Aug 24 05:59:18.004 INFO Starting beacon chain                   method: resume, service: beacon
Aug 24 05:59:40.947 INFO Block production enabled                method: json rpc via http, endpoints: Auth { endpoint: "http://localhost:8551/", jwt_path: "/Users/sajjode/Library/Ethereum/geth/jwtsecret", jwt_id: None, jwt_version: None }
Aug 24 05:59:41.731 INFO Beacon chain initialized                head_slot: 4541305, head_block: 0x6c70…6300, head_state: 0xbf04…2601, service: beacon
Aug 24 05:59:41.731 INFO Timer service started                   service: node_timer
Aug 24 05:59:41.731 INFO UPnP Attempting to initialise routes    service: UPnP
Aug 24 05:59:41.732 INFO Libp2p Starting                         bandwidth_config: 3-Average, peer_id: 16Uiu2HAmRtGSa2BvqMnNgnaYXUF2uuDmKF63on9FiQ9gs5HpJpNb, service: libp2p
Aug 24 05:59:41.732 INFO ENR Initialised                         tcp: Some(9000), udp: None, ip: None, id: 0xea48..34fa, seq: 1116, enr: enr:-K-4QDECQXcKPYyqsLqibKBuiTy2aEJzJY42tABVNJBnlK_cHy_mRuca_XtHC824ZQMnHuTJKZMgvLxJ7HGOxSyj3vKCBFyHYXR0bmV0c4gAAAAAAAAAAIRldGgykK_Kq6ACAAAAADYCAAAAAACCaWSCdjSJc2VjcDI1NmsxoQPEjqy81DrLnQy26X787lqVCVcatsHDNUUZXbHRSSmsGIhzeW5jbmV0cwCDdGNwgiMo, service: libp2p
Aug 24 05:59:41.743 CRIT Failed to start beacon node             reason: Failed to start network: Error(Libp2p(Msg("Io(Os { code: 48, kind: AddrInUse, message: \"Address already in use\" })")), State { next_error: None, backtrace: InternalBacktrace { backtrace: Some(   0: backtrace::capture::Backtrace::new_unresolved
   1: error_chain::backtrace::imp::InternalBacktrace::new
   2: <error_chain::State as core::default::Default>::default
   3: <lighthouse_network::types::error::Error as core::convert::From<alloc::string::String>>::from
   4: lighthouse_network::behaviour::Behaviour<AppReqId,TSpec>::new::{{closure}}
   5: network::service::NetworkService<T>::start::{{closure}}
   6: beacon_node::ProductionBeaconNode<E>::new::{{closure}}
   7: futures_util::future::future::FutureExt::poll_unpin
   8: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
   9: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
  10: <futures_util::future::future::flatten::Flatten<Fut,<Fut as core::future::future::Future>::Output> as core::future::future::Future>::poll
  11: tokio::runtime::task::core::CoreStage<T>::poll
  12: tokio::runtime::task::harness::Harness<T,S>::poll
  13: std::thread::local::LocalKey<T>::with
  14: tokio::runtime::thread_pool::worker::Context::run_task
  15: tokio::runtime::thread_pool::worker::Context::run
  16: tokio::macros::scoped_tls::ScopedKey<T>::set
  17: tokio::runtime::thread_pool::worker::run
  18: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
  19: tokio::runtime::task::harness::Harness<T,S>::poll
  20: tokio::runtime::blocking::pool::Inner::run
  21: std::sys_common::backtrace::__rust_begin_short_backtrace
  22: core::ops::function::FnOnce::call_once{{vtable.shim}}
  23: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/4b91a6ea7258a947e59c6522cd5898e7c0a6a88f/library/alloc/src/boxed.rs:1951:9
      <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/4b91a6ea7258a947e59c6522cd5898e7c0a6a88f/library/alloc/src/boxed.rs:1951:9
      std::sys::unix::thread::Thread::new::thread_start
             at /rustc/4b91a6ea7258a947e59c6522cd5898e7c0a6a88f/library/std/src/sys/unix/thread.rs:108:17
  24: __pthread_deallocate
) } })
Aug 24 05:59:41.743 INFO Internal shutdown received              reason: Failed to start beacon node
Aug 24 05:59:41.743 INFO Shutting down..                         reason: Failure("Failed to start beacon node")
Aug 24 05:59:42.554 INFO Saved beacon chain to disk              service: beacon
Aug 24 05:59:51.732 INFO UPnP not available                      error: IO error: Resource temporarily unavailable (os error 35), service: UPnP
Failed to start beacon node

Version

Please provide your Lighthouse and Rust version. Are you building from
stable or unstable, which commit?
Stable, 3.0.0, built locally in my Mac Mini M1, commit is 18c61a5e8be3e54226a86a69b96f8f4f7fd790e4

Present Behaviour

Fails to lauch

Expected Behaviour

I expect to be able to launch lighthouse

Steps to resolve

Please describe the steps required to resolve this issue, if known.

[michaelsproul]

If you're getting an address-already-in-use error then you've probably already got Lighthouse running in another tab somewhere. You can look for the process ID using ps like this:

ps -aux | grep lighthouse

e.g. on my machine I have this:

michael 325153 217 2.0 12763716 1329500 pts/4 Sl+ 16:23 9:10 lighthouse bn --staking --subscribe-all-subnets --import-all-attestations

If you see a lighthouse bn process there (before you start Lighthouse in the current tab), then that means it's already running. You could try to find the tab where it's running or just kill the process by PID:

kill 325153

change the PID to match the output from ps

[Sajjon]

@michaelsproul I did check for used ports with lsof and I killed all terminal windows and rebooted machine (I have no daemons setup to start when my Mac starts), so I'm pretty sure that was not the cause, why I opened this issue.

Without rebooting or anything, I downgraded Lighthouse to 2.5.1 and re-ran lighthouse, then it worked. So it feels like a regression bug, but I fully understand that I have not given you much to work with here... hmm. Might possibly be human error on my part!

Let's see if anyone else has these issues.

[michaelsproul]

@Sajjon You'll need to run v3.0.0 for the merge, do you get anything different when you change Lighthouse's port with e.g. --port 9001?

[michaelsproul]

If you could also send me the debug logs from ~.lighthouse/mainnet/beacon/logs/beacon.log that would be helpful. I'm @sproul#3907 on the Lighthouse Discord, or my email is <firstname>@sigmaprime.io.

[michaelsproul]

Closing in favour of #2254 which has more detailed discussion about possible root causes.