search

hyperboria / bugs

Peer-to-peer IPv6 networking, secure and near-zero-conf.
153 stars 17 forks source link

Failed to make function call: UDPInterface_beginConnection #213

Closed marek22k closed 11 months ago

marek22k commented 11 months ago

cjdns used to work wonderfully, but recently it has stopped working. After I restarted it, no tun interface is created anymore and the error message Invalid argument appears.

$ ping h.cjdns.ca
/usr/bin/ping: connect: Invalid argument
$ nslookup h.cjdns.ca
Server:     127.0.0.1
Address:    127.0.0.1#53

Non-authoritative answer:
Name:   h.cjdns.ca
Address: fcf4:e309:14b5:5498:cafd:4f59:4b9c:7f84

$ ping fcf4:e309:14b5:5498:cafd:4f59:4b9c:7f84
/usr/bin/ping: connect: Invalid argument
$ ip route get fcf4:e309:14b5:5498:cafd:4f59:4b9c:7f84
RTNETLINK answers: Invalid argument
$ cjdroute -v
Cjdns version: cjdns-v22-3-g1ccfbe5e
Cjdns protocol version: 22

Log: log.txt

Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 DEBUG UDPAddrIface.c:320 Bound to address [127.0.0.1:11234]
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 DEBUG UDPAddrIface.c:282 Binding to address [127.0.0.1:11234]
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 DEBUG Core.c:463 Finished getting pre-configuration from client
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 DEBUG Pipe.c:257 Pipe [(null)] established connection
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 DEBUG Core.c:460 Getting pre-configuration from client
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO NanotimeEntropyProvider.c:59 Taking clock samples every [1000]ms for random generator
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:63 Seeding random number generator succeeded with [4] sources
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:50 Trying random seed [getentropy(2)] Success
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:50 Trying random seed [sysctl(RANDOM_UUID) (Linux)] Success
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:50 Trying random seed [/proc/sys/kernel/random/uuid (Linux)] Success
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:50 Trying random seed [/dev/urandom] Success
Okt 30 18:54:23 parrot cjdroute[15791]: 1698688463 INFO RandomSeed.c:42 Attempting to seed random number generator
Okt 30 18:54:23 parrot systemd[1]: Started cjdns.service - cjdns: routing engine designed for security, scalability, speed and ease of use.
Okt 30 18:54:23 parrot cjdroute[15788]: RTNETLINK answers: File exists
Okt 30 18:54:23 parrot systemd[1]: Starting cjdns.service - cjdns: routing engine designed for security, scalability, speed and ease of use...
Okt 30 18:54:23 parrot systemd[1]: Stopped cjdns.service - cjdns: routing engine designed for security, scalability, speed and ease of use.
Okt 30 18:54:23 parrot systemd[1]: cjdns.service: Scheduled restart job, restart counter is at 15.
Okt 30 18:54:23 parrot systemd[1]: cjdns.service: Failed with result 'exit-code'.
Okt 30 18:54:23 parrot systemd[1]: cjdns.service: Main process exited, code=exited, status=1/FAILURE
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688463 CRITICAL Configurator.c:71 Aborting.
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688463 CRITICAL Configurator.c:57 enable Log_LEVEL=KEYS to see message content.
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688463 CRITICAL Configurator.c:94 Failed to make function call [Timed out waiting for a response], error: [UDPInterface_beginConnection]
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688458 INFO Configurator.c:197 Setting beacon mode UDPInterface to [2].
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688458 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688458 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:54879]
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688458 DEBUG Pipe.c:279 Sending buffered message
Okt 30 18:54:23 parrot cjdroute[15743]: 1698688458 DEBUG Pipe.c:257 Pipe [/tmp/cjdroute.sock] established connection

Ping on maintainer: @cjdelisle

marek22k commented 11 months ago

Running as root:

#/usr/local/bin/cjdroute --nobg < /etc/cjdroute.conf
1698688726 INFO cjdroute2.c:732 cjdns-v22-3-g1ccfbe5e amd64 linux +seccomp
1698688726 INFO cjdroute2.c:736 Checking for running instance...
1698688726 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:43678]
1698688726 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698688726 INFO RandomSeed.c:42 Attempting to seed random number generator
1698688726 INFO RandomSeed.c:50 Trying random seed [/dev/urandom] Success
1698688726 INFO RandomSeed.c:50 Trying random seed [/proc/sys/kernel/random/uuid (Linux)] Success
1698688726 INFO RandomSeed.c:50 Trying random seed [sysctl(RANDOM_UUID) (Linux)] Success
1698688726 INFO RandomSeed.c:50 Trying random seed [getentropy(2)] Success
1698688726 INFO RandomSeed.c:63 Seeding random number generator succeeded with [4] sources
1698688726 INFO NanotimeEntropyProvider.c:59 Taking clock samples every [1000]ms for random generator
1698688726 DEBUG Core.c:460 Getting pre-configuration from client
1698688726 DEBUG Pipe.c:152 Buffering a message
1698688726 DEBUG cjdroute2.c:812 Sent [144] bytes to core
1698688726 DEBUG Pipe.c:257 Pipe [/tmp/cjdroute.sock] established connection
1698688726 DEBUG Pipe.c:279 Sending buffered message
1698688726 DEBUG Pipe.c:257 Pipe [(null)] established connection
1698688726 DEBUG Core.c:463 Finished getting pre-configuration from client
1698688726 DEBUG UDPAddrIface.c:282 Binding to address [127.0.0.1:11234]
1698688726 DEBUG UDPAddrIface.c:320 Bound to address [127.0.0.1:11234]
1698688726 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:48181]
1698688726 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698688726 INFO Configurator.c:197 Setting beacon mode UDPInterface to [2].
1698688731 CRITICAL Configurator.c:94 Failed to make function call [Timed out waiting for a response], error: [UDPInterface_beginConnection]
1698688731 CRITICAL Configurator.c:57 enable Log_LEVEL=KEYS to see message content.
1698688731 CRITICAL Configurator.c:71 Aborting.
marek22k commented 11 months ago

Ater reducing the number of optional fiels (like in https://github.com/hyperboria/bugs/issues/195) I get:

1698689038 INFO cjdroute2.c:732 cjdns-v22-3-g1ccfbe5e amd64 linux +seccomp
1698689038 INFO cjdroute2.c:736 Checking for running instance...
1698689038 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:53625]
1698689038 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698689038 INFO RandomSeed.c:42 Attempting to seed random number generator
1698689038 INFO RandomSeed.c:50 Trying random seed [/dev/urandom] Success
1698689038 INFO RandomSeed.c:50 Trying random seed [/proc/sys/kernel/random/uuid (Linux)] Success
1698689038 INFO RandomSeed.c:50 Trying random seed [sysctl(RANDOM_UUID) (Linux)] Success
1698689038 INFO RandomSeed.c:50 Trying random seed [getentropy(2)] Success
1698689038 INFO RandomSeed.c:63 Seeding random number generator succeeded with [4] sources
1698689038 INFO NanotimeEntropyProvider.c:59 Taking clock samples every [1000]ms for random generator
1698689038 DEBUG Core.c:460 Getting pre-configuration from client
1698689038 DEBUG Pipe.c:152 Buffering a message
1698689038 DEBUG cjdroute2.c:812 Sent [144] bytes to core
1698689038 DEBUG Pipe.c:257 Pipe [(null)] established connection
1698689038 DEBUG Pipe.c:257 Pipe [/tmp/cjdroute.sock] established connection
1698689038 DEBUG Pipe.c:279 Sending buffered message
1698689038 DEBUG Core.c:463 Finished getting pre-configuration from client
1698689038 DEBUG UDPAddrIface.c:282 Binding to address [127.0.0.1:11234]
1698689038 DEBUG UDPAddrIface.c:320 Bound to address [127.0.0.1:11234]
1698689038 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:44957]
1698689038 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698689038 INFO Configurator.c:197 Setting beacon mode UDPInterface to [2].
1698689038 CRITICAL Configurator.c:104 Got error [UDPInterface.c:215 UDP broadcast only supported by ipv4.] calling [UDPInterface_new]
1698689038 CRITICAL Configurator.c:57 enable Log_LEVEL=KEYS to see message content.
1698689038 CRITICAL Configurator.c:71 Aborting.

and sometimes

#/usr/local/bin/cjdroute --nobg < /etc/cjdroute.conf
1698689073 INFO cjdroute2.c:732 cjdns-v22-3-g1ccfbe5e amd64 linux +seccomp
1698689073 INFO cjdroute2.c:736 Checking for running instance...
1698689073 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:36363]
1698689073 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698689073 INFO RandomSeed.c:42 Attempting to seed random number generator
1698689073 INFO RandomSeed.c:50 Trying random seed [/dev/urandom] Success
1698689073 INFO RandomSeed.c:50 Trying random seed [/proc/sys/kernel/random/uuid (Linux)] Success
1698689073 INFO RandomSeed.c:50 Trying random seed [sysctl(RANDOM_UUID) (Linux)] Success
1698689073 INFO RandomSeed.c:50 Trying random seed [getentropy(2)] Success
1698689073 INFO RandomSeed.c:63 Seeding random number generator succeeded with [4] sources
1698689073 INFO NanotimeEntropyProvider.c:59 Taking clock samples every [1000]ms for random generator
1698689073 DEBUG Core.c:460 Getting pre-configuration from client
1698689073 DEBUG Pipe.c:152 Buffering a message
1698689073 DEBUG cjdroute2.c:812 Sent [144] bytes to core
1698689073 DEBUG Pipe.c:257 Pipe [/tmp/cjdroute.sock] established connection
1698689073 DEBUG Pipe.c:279 Sending buffered message
1698689073 DEBUG Pipe.c:257 Pipe [(null)] established connection
1698689073 DEBUG Core.c:463 Finished getting pre-configuration from client
1698689073 DEBUG UDPAddrIface.c:282 Binding to address [127.0.0.1:11234]
1698689073 DEBUG UDPAddrIface.c:320 Bound to address [127.0.0.1:11234]
1698689073 DEBUG UDPAddrIface.c:320 Bound to address [0.0.0.0:54014]
1698689073 DEBUG AdminClient.c:336 Connecting to [127.0.0.1:11234]
1698689073 INFO Configurator.c:197 Setting beacon mode UDPInterface to [2].
1698689073 CRITICAL Configurator.c:104 Got error [UDPInterface.c:215 UDP broadcast only supported by ipv4.] calling [UDPInterface_new]
1698689073 CRITICAL Configurator.c:57 enable Log_LEVEL=KEYS to see message content.

thread 'tokio-runtime-worker' panicked at 'Core exited with status [0], signal [-127]
', rust/cjdns_sys/src/rffi.rs:348:5
stack backtrace:
   0: rust_begin_unwind
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panicking.rs:593:5
   1: core::panicking::panic_fmt
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/core/src/panicking.rs:67:14
   2: core::panicking::panic_display
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/core/src/panicking.rs:150:5
   3: Rffi_panic
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panic.rs:26:9
   4: Assert_failure
             at /home/marek/cjdns/util/Assert.c:38:5
   5: onCoreExit
             at /home/marek/cjdns/client/cjdroute2.c:543:5
   6: cjdns_sys::rffi::Rffi_spawn::{{closure}}
             at /home/marek/cjdns/rust/cjdns_sys/src/rffi.rs:567:38
   7: tokio::runtime::task::core::CoreStage<T>::poll::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/core.rs:161:17
   8: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/loom/std/unsafe_cell.rs:14:9
   9: tokio::runtime::task::core::CoreStage<T>::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/core.rs:151:13
  10: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:461:19
  11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/core/src/panic/unwind_safe.rs:271:9
  12: std::panicking::try::do_call
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panicking.rs:500:40
  13: std::panicking::try
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panicking.rs:464:19
  14: std::panic::catch_unwind
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panic.rs:142:14
  15: tokio::runtime::task::harness::poll_future
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:449:18
  16: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:98:27
  17: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:53:15
  18: tokio::runtime::task::raw::RawTask::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/raw.rs:70:18
  19: tokio::runtime::task::LocalNotified<S>::run
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/mod.rs:343:9
  20: tokio::runtime::thread_pool::worker::Context::run_task::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/thread_pool/worker.rs:425:18
  21: tokio::coop::with_budget::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/coop.rs:102:9
  22: std::thread::local::LocalKey<T>::try_with
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/thread/local.rs:270:16
  23: std::thread::local::LocalKey<T>::with
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/thread/local.rs:246:9
  24: tokio::coop::with_budget
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/coop.rs:95:13
  25: tokio::coop::budget
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/coop.rs:72:5
  26: tokio::runtime::thread_pool::worker::Context::run_task
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/thread_pool/worker.rs:424:9
  27: tokio::runtime::thread_pool::worker::Context::run
  28: tokio::runtime::thread_pool::worker::run::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/thread_pool/worker.rs:376:17
  29: tokio::macros::scoped_tls::ScopedKey<T>::set
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/macros/scoped_tls.rs:61:9
  30: tokio::runtime::thread_pool::worker::run
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/thread_pool/worker.rs:373:5
  31: tokio::runtime::thread_pool::worker::Launch::launch::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/thread_pool/worker.rs:352:45
  32: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/blocking/task.rs:42:21
  33: tokio::runtime::task::core::CoreStage<T>::poll::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/core.rs:161:17
  34: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/loom/std/unsafe_cell.rs:14:9
  35: tokio::runtime::task::core::CoreStage<T>::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/core.rs:151:13
  36: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:461:19
  37: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/core/src/panic/unwind_safe.rs:271:9
  38: std::panicking::try::do_call
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panicking.rs:500:40
  39: std::panicking::try
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panicking.rs:464:19
  40: std::panic::catch_unwind
             at /rustc/8ede3aae28fe6e4d52b38157d7bfe0d3bceef225/library/std/src/panic.rs:142:14
  41: tokio::runtime::task::harness::poll_future
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:449:18
  42: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:98:27
  43: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/harness.rs:53:15
  44: tokio::runtime::task::raw::RawTask::poll
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/raw.rs:70:18
  45: tokio::runtime::task::UnownedTask<S>::run
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/task/mod.rs:380:9
  46: tokio::runtime::blocking::pool::Task::run
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/blocking/pool.rs:91:9
  47: tokio::runtime::blocking::pool::Inner::run
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/blocking/pool.rs:314:17
  48: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/marek/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.16.1/src/runtime/blocking/pool.rs:294:17
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
1698689078 CRITICAL Configurator.c:69 Failed to stop the core.
1698689078 CRITICAL Configurator.c:71 Aborting.

Setting "beacon": 0 for IPv6 resolved this.

marek22k commented 11 months ago

Duplicate of https://github.com/hyperboria/bugs/issues/195