[org-node] Bug: Failed to send update refs request to client: receive failed

[Ryanmtate]

While testing rad subscribe, noticing error when attempting to send req requests to client, exiting with a receive failed.

Also appears maybe the monorepo project I have could be corrupted? e.g. panics on reference target must exist.

Possibly due to changing location of org-node socket.

Nov 19 07:07:39.717 DEBUG org-node: Signed refs for rad:git:hnrkbtw9t1of4ykjy6er4qqwxtc54k9943eto updated: heads={OneLevel("master"): Oid(6841688e4f5b5f449ed99f8a0a4e33ff34535eb1)} at=2503fa2014ae506ec778966d884a773aedee260e
Nov 19 07:07:39.719 DEBUG org-node: Setting ref "refs/namespaces/hnrkbtw9t1of4ykjy6er4qqwxtc54k9943eto/HEAD" -> "refs/namespaces/hnrkbtw9t1of4ykjy6er4qqwxtc54k9943eto/refs/heads/master"
thread 'tokio-runtime-worker' panicked at 'reference target must exist', org-node/src/client.rs:590:46
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Nov 19 07:07:39.720 ERROR org-node: Failed to send update refs request to client: receive failed
Nov 19 07:07:39.720  INFO org-node: Exiting..

[Ryanmtate]

@cloudhead any chance this would be due to using an org with the address of 0x0000000000000000000000000000000000000001; I know we did that to avoid tracking other projects, but not sure if that would cause an issue here.

Other thoughts, maybe the state of the repo is stale on my end?

Let's sync next week when you're available. Will make some more progress on rad subscribe and ssh signing implementations and try to debug this in the process.

[Ryanmtate]

Pretty sure this is due to a divergent branch between upstream and local repo, but we probably need to handle this error a little more gracefully than calling .expect()

[Ryanmtate]

Pretty sure this is due to a divergent branch between upstream and local repo, but we probably need to handle this error a little more gracefully than calling .expect()

Hmm, actually I am not sure this is the issue. It might be, but it seems there may be another issue at play. @cloudhead if you have time tomorrow let's try to sync and walk through it for sanity check purposes.

Also, this is occurring in the UpdateRefs handler, and not the set head method.

The bizarre thing is that when I look at the mono repo git tree, the ref appears to be there, but when attempting to set the symbolic reference, it errors, suggesting the target does not exist. Possibly corrupted mono-repo?

[cloudhead]

As far as I can tell, this is due to a replication bug: radicle-dev/radicle-link#782

I don't think it should happen in normal scenarios, ie. if things are working correctly, though I guess it's possible if the server shuts down abruptly in the middle of replication, so we need a way to handle that.

[xphoniex]

I'm encountering the same issue in my local setup:

Nov 25 20:56:21.982  INFO org-node: Updating refs
Nov 25 20:56:21.983  INFO org-node: updating refs for urn: Urn { id: Oid(02c1f6dbdbadd0d269dd91ab9dd38080bb08989d), path: None }
thread 'tokio-runtime-worker' panicked at 'reference target must exist', org-node/src/client.rs:604:46
stack backtrace:
   0: rust_begin_unwind
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panicking.rs:515:5
   1: core::panicking::panic_fmt
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/core/src/panicking.rs:92:14
   2: core::option::expect_failed
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/core/src/option.rs:1243:5
   3: core::option::Option<T>::expect
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/core/src/option.rs:351:21
   4: radicle_org_node::client::Client::handle_request::{{closure}}
             at ./org-node/src/client.rs:604:27
   5: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/core/src/future/mod.rs:80:19
   6: radicle_org_node::client::Client::run::{{closure}}::{{closure}}
             at ./org-node/src/client.rs:289:47
   7: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/core/src/future/mod.rs:80:19
   8: tokio::runtime::task::core::CoreStage<T>::poll::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/core.rs:161:17
   9: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/loom/std/unsafe_cell.rs:14:9
  10: tokio::runtime::task::core::CoreStage<T>::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/core.rs:151:13
  11: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:461:19
  12: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panic.rs:347:9
  13: std::panicking::try::do_call
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panicking.rs:401:40
  14: __rust_try
  15: std::panicking::try
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panicking.rs:365:19
  16: std::panic::catch_unwind
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panic.rs:434:14
  17: tokio::runtime::task::harness::poll_future
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:449:18
  18: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:98:27
  19: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:53:15
  20: tokio::runtime::task::raw::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/raw.rs:113:5
  21: tokio::runtime::task::raw::RawTask::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/raw.rs:70:18
  22: tokio::runtime::task::LocalNotified<S>::run
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/mod.rs:343:9
  23: tokio::runtime::thread_pool::worker::Context::run_task::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:420:13
  24: tokio::coop::with_budget::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/coop.rs:106:9
  25: std::thread::local::LocalKey<T>::try_with
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/thread/local.rs:400:16
  26: std::thread::local::LocalKey<T>::with
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/thread/local.rs:376:9
  27: tokio::coop::with_budget
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/coop.rs:99:5
  28: tokio::coop::budget
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/coop.rs:76:5
  29: tokio::runtime::thread_pool::worker::Context::run_task
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:419:9
  30: tokio::runtime::thread_pool::worker::Context::run
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:386:24
  31: tokio::runtime::thread_pool::worker::run::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:371:17
  32: tokio::macros::scoped_tls::ScopedKey<T>::set
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/macros/scoped_tls.rs:61:9
  33: tokio::runtime::thread_pool::worker::run
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:368:5
  34: tokio::runtime::thread_pool::worker::Launch::launch::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/thread_pool/worker.rs:347:45
  35: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/blocking/task.rs:42:21
  36: tokio::runtime::task::core::CoreStage<T>::poll::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/core.rs:161:17
  37: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/loom/std/unsafe_cell.rs:14:9
  38: tokio::runtime::task::core::CoreStage<T>::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/core.rs:151:13
  39: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:461:19
  40: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panic.rs:347:9
  41: std::panicking::try::do_call
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panicking.rs:401:40
  42: __rust_try
  43: std::panicking::try
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panicking.rs:365:19
  44: std::panic::catch_unwind
             at /rustc/a85f584aebd9b08314bf30b9adc17b4a752143e5/library/std/src/panic.rs:434:14
  45: tokio::runtime::task::harness::poll_future
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:449:18
  46: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:98:27
  47: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/harness.rs:53:15
  48: tokio::runtime::task::raw::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/raw.rs:113:5
  49: tokio::runtime::task::raw::RawTask::poll
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/raw.rs:70:18
  50: tokio::runtime::task::UnownedTask<S>::run
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/task/mod.rs:379:9
  51: tokio::runtime::blocking::pool::Inner::run
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/blocking/pool.rs:265:17
  52: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.12.0/src/runtime/blocking/pool.rs:245:17
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Nov 25 20:56:26.037 ERROR org-node: Failed to send update refs request to client: receive failed

[cloudhead]

I'll see if we can be more graceful about this.

[Ryanmtate]

I'll see if we can be more graceful about this.

Let me know a good time to get a pair programming session together. It's going to need to be early morning my time, somewhere around 4-5am PST. Just send me a msg on discord.

[Ryanmtate]

I see some works on #77, let me know if there is anything I can assist with.

[cloudhead]

Closing as we haven't this pop up in a while.