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

remove pkarr publish backtrace on error #2316

Open
divagant-martian opened this issue May 21, 2024 · 3 comments
Open

remove pkarr publish backtrace on error #2316

divagant-martian opened this issue May 21, 2024 · 3 comments
Assignees
@rklaehn

Comments

@divagant-martian
Copy link
Contributor

divagant-martian commented May 21, 2024 •
edited
Loading

at least in ci there is a constant emission of these:

2024-05-21T16:59:39.2526870Z 
2024-05-21T16:59:39.2526930Z Stack backtrace:
2024-05-21T16:59:39.2527140Z    0: std::backtrace_rs::backtrace::libunwind::trace
2024-05-21T16:59:39.2527680Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/../../backtrace/src/backtrace/libunwind.rs:105:5
2024-05-21T16:59:39.2528220Z    1: std::backtrace_rs::backtrace::trace_unsynchronized
2024-05-21T16:59:39.2528740Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2024-05-21T16:59:39.2529210Z    2: std::backtrace::Backtrace::create
2024-05-21T16:59:39.2529610Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/backtrace.rs:331:13
2024-05-21T16:59:39.2530000Z    3: anyhow::kind::Adhoc::new
2024-05-21T16:59:39.2530490Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.82/src/kind.rs:73:36
2024-05-21T16:59:39.2531070Z    4: iroh_net::discovery::pkarr_publish::PkarrRelayClient::publish::{{closure}}
2024-05-21T16:59:39.2531670Z              at /Users/hetzner/actions-runner/_work/iroh/iroh/iroh-net/src/discovery/pkarr_publish.rs:208:13
2024-05-21T16:59:39.2532240Z    5: iroh_net::discovery::pkarr_publish::PublisherService::publish_current::{{closure}}
2024-05-21T16:59:39.2532860Z              at /Users/hetzner/actions-runner/_work/iroh/iroh/iroh-net/src/discovery/pkarr_publish.rs:172:51
2024-05-21T16:59:39.2533390Z    6: iroh_net::discovery::pkarr_publish::PublisherService::run::{{closure}}
2024-05-21T16:59:39.2533970Z              at /Users/hetzner/actions-runner/_work/iroh/iroh/iroh-net/src/discovery/pkarr_publish.rs:137:62
2024-05-21T16:59:39.2534520Z    7: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
2024-05-21T16:59:39.2535180Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
2024-05-21T16:59:39.2535720Z    8: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
2024-05-21T16:59:39.2536350Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
2024-05-21T16:59:39.2536900Z    9: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
2024-05-21T16:59:39.2537520Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
2024-05-21T16:59:39.2538050Z   10: tokio::runtime::task::core::Core<T,S>::poll
2024-05-21T16:59:39.2538670Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
2024-05-21T16:59:39.2539240Z   11: tokio::runtime::task::harness::poll_future::{{closure}}
2024-05-21T16:59:39.2539860Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
2024-05-21T16:59:39.2540550Z   12: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
2024-05-21T16:59:39.2541140Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/panic/unwind_safe.rs:272:9
2024-05-21T16:59:39.2541560Z   13: std::panicking::try::do_call
2024-05-21T16:59:39.2541940Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
2024-05-21T16:59:39.2542310Z   14: ___rust_try
2024-05-21T16:59:39.2542480Z   15: std::panicking::try
2024-05-21T16:59:39.2542830Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
2024-05-21T16:59:39.2543260Z   16: std::panic::catch_unwind
2024-05-21T16:59:39.2543620Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
2024-05-21T16:59:39.2544020Z   17: tokio::runtime::task::harness::poll_future
2024-05-21T16:59:39.2544620Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
2024-05-21T16:59:39.2545190Z   18: tokio::runtime::task::harness::Harness<T,S>::poll_inner
2024-05-21T16:59:39.2545810Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
2024-05-21T16:59:39.2546360Z   19: tokio::runtime::task::harness::Harness<T,S>::poll
2024-05-21T16:59:39.2550400Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
2024-05-21T16:59:39.2550910Z   20: tokio::runtime::task::raw::poll
2024-05-21T16:59:39.2551460Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
2024-05-21T16:59:39.2551970Z   21: tokio::runtime::task::raw::RawTask::poll
2024-05-21T16:59:39.2552540Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
2024-05-21T16:59:39.2553070Z   22: tokio::runtime::task::LocalNotified<S>::run
2024-05-21T16:59:39.2553640Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:427:9
2024-05-21T16:59:39.2554290Z   23: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}::{{closure}}
2024-05-21T16:59:39.2555080Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:700:25
2024-05-21T16:59:39.2555650Z   24: tokio::runtime::coop::with_budget
2024-05-21T16:59:39.2556190Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:107:5
2024-05-21T16:59:39.2556660Z   25: tokio::runtime::coop::budget
2024-05-21T16:59:39.2557180Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:73:5
2024-05-21T16:59:39.2557760Z   26: tokio::runtime::scheduler::current_thread::Context::run_task::{{closure}}
2024-05-21T16:59:39.2558500Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:343:43
2024-05-21T16:59:39.2559170Z   27: tokio::runtime::scheduler::current_thread::Context::enter
2024-05-21T16:59:39.2559870Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:404:19
2024-05-21T16:59:39.2560510Z   28: tokio::runtime::scheduler::current_thread::Context::run_task
2024-05-21T16:59:39.2561290Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:343:23
2024-05-21T16:59:39.2561980Z   29: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}
2024-05-21T16:59:39.2562720Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:699:35
2024-05-21T16:59:39.2563390Z   30: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
2024-05-21T16:59:39.2564130Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:737:68
2024-05-21T16:59:39.2564730Z   31: tokio::runtime::context::scoped::Scoped<T>::set
2024-05-21T16:59:39.2565330Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/scoped.rs:40:9
2024-05-21T16:59:39.2565890Z   32: tokio::runtime::context::set_scheduler::{{closure}}
2024-05-21T16:59:39.2566530Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:26
2024-05-21T16:59:39.2567050Z   33: std::thread::local::LocalKey<T>::try_with
2024-05-21T16:59:39.2567470Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/thread/local.rs:284:16
2024-05-21T16:59:39.2567880Z   34: std::thread::local::LocalKey<T>::with
2024-05-21T16:59:39.2568290Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/thread/local.rs:260:9
2024-05-21T16:59:39.2568700Z   35: tokio::runtime::context::set_scheduler
2024-05-21T16:59:39.2569260Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:9
2024-05-21T16:59:39.2569830Z   36: tokio::runtime::scheduler::current_thread::CoreGuard::enter
2024-05-21T16:59:39.2570530Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:737:27
2024-05-21T16:59:39.2571180Z   37: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
2024-05-21T16:59:39.2571890Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:646:19
2024-05-21T16:59:39.2572590Z   38: tokio::runtime::scheduler::current_thread::CurrentThread::block_on::{{closure}}
2024-05-21T16:59:39.2573340Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:175:28
2024-05-21T16:59:39.2573940Z   39: tokio::runtime::context::runtime::enter_runtime
2024-05-21T16:59:39.2574550Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/runtime.rs:65:16
2024-05-21T16:59:39.2575160Z   40: tokio::runtime::scheduler::current_thread::CurrentThread::block_on
2024-05-21T16:59:39.2575890Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/current_thread/mod.rs:167:9
2024-05-21T16:59:39.2576480Z   41: tokio::runtime::runtime::Runtime::block_on
2024-05-21T16:59:39.2577060Z              at /Users/hetzner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/runtime.rs:349:47
2024-05-21T16:59:39.2577550Z   42: sync::test_download_policies
2024-05-21T16:59:39.2577770Z              at ./tests/sync.rs:850:5
2024-05-21T16:59:39.2578030Z   43: sync::test_download_policies::{{closure}}
2024-05-21T16:59:39.2578280Z              at ./tests/sync.rs:713:38
2024-05-21T16:59:39.2578530Z   44: core::ops::function::FnOnce::call_once
2024-05-21T16:59:39.2578950Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
2024-05-21T16:59:39.2579360Z   45: core::ops::function::FnOnce::call_once
2024-05-21T16:59:39.2579780Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
2024-05-21T16:59:39.2580180Z   46: test::__rust_begin_short_backtrace
2024-05-21T16:59:39.2580600Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/test/src/lib.rs:621:18
2024-05-21T16:59:39.2580990Z   47: test::run_test_in_process::{{closure}}
2024-05-21T16:59:39.2581380Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/test/src/lib.rs:644:60
2024-05-21T16:59:39.2581930Z   48: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
2024-05-21T16:59:39.2582520Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/panic/unwind_safe.rs:272:9
2024-05-21T16:59:39.2582940Z   49: std::panicking::try::do_call
2024-05-21T16:59:39.2583320Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
2024-05-21T16:59:39.2583700Z   50: std::panicking::try
2024-05-21T16:59:39.2584050Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
2024-05-21T16:59:39.2584530Z   51: std::panic::catch_unwind
2024-05-21T16:59:39.2584890Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
2024-05-21T16:59:39.2585260Z   52: test::run_test_in_process
2024-05-21T16:59:39.2585620Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/test/src/lib.rs:644:27
2024-05-21T16:59:39.2585990Z   53: test::run_test::{{closure}}
2024-05-21T16:59:39.2586350Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/test/src/lib.rs:567:43
2024-05-21T16:59:39.2586720Z   54: test::run_test::{{closure}}
2024-05-21T16:59:39.2587070Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/test/src/lib.rs:595:41
2024-05-21T16:59:39.2587510Z   55: std::sys_common::backtrace::__rust_begin_short_backtrace
2024-05-21T16:59:39.2587990Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:18
2024-05-21T16:59:39.2588510Z   56: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}
2024-05-21T16:59:39.2589000Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/thread/mod.rs:528:17
2024-05-21T16:59:39.2589570Z   57: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
2024-05-21T16:59:39.2590150Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/panic/unwind_safe.rs:272:9
2024-05-21T16:59:39.2590570Z   58: std::panicking::try::do_call
2024-05-21T16:59:39.2590940Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
2024-05-21T16:59:39.2591330Z   59: std::panicking::try
2024-05-21T16:59:39.2591670Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
2024-05-21T16:59:39.2592060Z   60: std::panic::catch_unwind
2024-05-21T16:59:39.2592410Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
2024-05-21T16:59:39.2592840Z   61: std::thread::Builder::spawn_unchecked_::{{closure}}
2024-05-21T16:59:39.2593280Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/thread/mod.rs:527:30
2024-05-21T16:59:39.2593740Z   62: core::ops::function::FnOnce::call_once{{vtable.shim}}
2024-05-21T16:59:39.2594210Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
2024-05-21T16:59:39.2594720Z   63: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
2024-05-21T16:59:39.2595240Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/alloc/src/boxed.rs:2020:9
2024-05-21T16:59:39.2595730Z   64: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
2024-05-21T16:59:39.2596220Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/alloc/src/boxed.rs:2020:9
2024-05-21T16:59:39.2596660Z   65: std::sys::pal::unix::thread::Thread::new::thread_start
2024-05-21T16:59:39.2597220Z              at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys/pal/unix/thread.rs:108:17
2024-05-21T16:59:39.2597800Z   66: __pthread_deallocate url=https://dns.iroh.link/pkarr

if this is ever triggered for an user this is more than 120 lines in a single warn that look like a panic. In ci this is very annoying, for an user this would look terribly worrisome and provides imo no actual extra information that can be used to know why the publish failed

This is emitted in

discovery service produced error

and

Failed to publish to pkarr
@dignifiedquire dignifiedquire added this to the v0.18.0 milestone May 22, 2024
@rklaehn
Copy link
Contributor

rklaehn commented Jun 5, 2024

This is a new feature of anyhow. It now will always attach backtraces and print them when RUST_BACKTRACE=1 is set.

From https://crates.io/crates/anyhow:

If using Rust ≥ 1.65, a backtrace is captured and printed with the error if the underlying error type does not already provide its own. In order to see backtraces, they must be enabled through the environment variables described in std::backtrace:

If you want panics and errors to both have backtraces, set RUST_BACKTRACE=1;
If you want only errors to have backtraces, set RUST_LIB_BACKTRACE=1;
If you want only panics to have backtraces, set RUST_BACKTRACE=1 and RUST_LIB_BACKTRACE=0.

So we either don't print anyhow errors anymore, or just change CI to set RUST_BACKTRACE=1 and RUST_LIB_BACKTRACE=0 to get rid of it.

I think maybe the latter is the way to go? We got tons of places in the code where we are printing errors in log statements. And people won't run into this if they don't set RUST_BACKTRACE=1.

@dignifiedquire dignifiedquire removed this from the v0.18.0 milestone Jun 7, 2024
@rklaehn
Copy link
Contributor

rklaehn commented Jun 26, 2024 •
edited
Loading

@Arqu this would be just adding RUST_LIB_BACKTRACE=0 to all ci yaml files where RUST_LOG is set, right?

E.g. here:

    - name: build
      # cross tests are currently broken vor armv7 and aarch64
      # see https://github.com/cross-rs/cross/issues/1311.  So on
      # those platforms we only build but do not run tests.
      run: cross build --all --target ${{ matrix.target }}
      env:
        RUST_LOG: ${{ runner.debug && 'TRACE' || 'DEBUG'}}
>       RUST_LIB_BACKTRACE=1

@Arqu
Copy link
Collaborator

Arqu commented Jun 26, 2024

Yeah, reading the docs you mentioned seems like doing RUST_BACKTRACE=1 and RUST_LIB_BACKTRACE=0 should work for us. And yes, just follow suit on CI yaml files.

It does result in the unfortunate situation where we don't see other lib backtraces, but we already knew that I guess.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rklaehn rklaehn

Labels
None yet
Projects
iroh
Status: 📋 Backlog
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rklaehn @dignifiedquire @Arqu @divagant-martian