0.18.0 Release Issue on OSX

[sync]

Get the following error:

thread 'main' panicked at 'Cannot start a runtime from within a runtime. This happens because a function (like `block_on`) attempted to block the current thread while the thread is being used to drive asynchronous tasks.', /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/enter.rs:19:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
 ERROR reqwest::blocking::client > Failed to communicate successful startup: Ok(())

I had no issue with the previous version: 0.17.0

Cargo file:

[package]
name = "segment-recover-bot"
version = "0.1.0"
authors = ["Anthony Mittaz <sync@me.com>"]
edition = "2018"
exclude = ["test/*"]

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
reqwest = { version = "0.10", features = ["json"] }
tokio = { version = "0.2", features = ["full"] }
lazy_static = "1.4.0"
url = { version = "2.1.1" }
serde = { version = "1.0", features = ["derive"] }
serde_json = "1.0"
regex = "1"
err-derive = "0.2"
sentry = "0.18.0"
chrono = { version = "0.4", features = ["serde"] }
either = { version = "1.5", features = ["serde"] }
futures-timer = "3.0"

warp = "0.2"
strum = "0.17.1"
strum_macros = "0.17.1"
log = "0.4"
pretty_env_logger = "0.4"
bytes = "0.5"
github_webhook_message_validator = "0.1.2"
hex = "0.4.2"
dotenv = "0.15.0"
graphql_client = "0.8.0"

[dev-dependencies]
httpmock = "0.3.4"
env_logger = "0.7"

[sync]

is there anything i could do to help / debug the issue ? i am already super happy sentry has taken the time to write a sdk for rust and 0.17x works really well so we are in no rush btw. But more than happy to help.

[jan-auer]

@sync Thanks for sharing this information. Could you please enable RUST_BACKTRACE=1 and share the backtrace you get from this?

The error message suggests nested tokio runtimes. In the 0.18.0 release, we upgraded to reqwest 0.10.0 and use the blocking client. While it is driven in a background thread, the client is started in the main thread. Potentially, this might be the culprit.

I'll try to fix this and would greatly appreciate your help with creating a small repro. Are you running sentry::init after starting a tokio runtime? If so, could you try to move the sentry::init call earlier and check if the problem still persists? Thank you!

[jhelwig]

Probably as minimal of a repro as I can come up with.

[dependencies]
sentry = "0.18.0"
tokio = { version = "0.2.11", features = ["full"] }

#[tokio::main]
async fn main() -> Result<(), ()> {
    let sentry_dsn = std::env::var("SENTRY_DSN").expect("SENTRY_DSN must be set");
    let guard = sentry::init(sentry_dsn);

    println!("Hello, world!");

    drop(guard);

    Ok(())
}

[sync]

Here you go

08:55 $ RUST_BACKTRACE=full cargo run --bin web
    Finished dev [unoptimized + debuginfo] target(s) in 0.14s
     Running `target/debug/web`
thread 'main' panicked at 'Cannot start a runtime from within a runtime. This happens because a function (like `block_on`) attempted to block the current thread while the thread is being used to drive asynchronous tasks.', /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/enter.rs:19:5
stack backtrace:
   0:        0x10209a215 - backtrace::backtrace::libunwind::trace::hb16ec6045891ce5a
                               at /Users/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1:        0x10209a215 - backtrace::backtrace::trace_unsynchronized::hcacbd0efdffd74c6
                               at /Users/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2:        0x10209a215 - std::sys_common::backtrace::_print_fmt::h39e22de9d6757d12
                               at src/libstd/sys_common/backtrace.rs:77
   3:        0x10209a215 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h415ddd0ba88caaaf
                               at src/libstd/sys_common/backtrace.rs:61
   4:        0x1020ba6b0 - core::fmt::write::h3335552e2df81c1d
                               at src/libcore/fmt/mod.rs:1028
   5:        0x10209593b - std::io::Write::write_fmt::he6837371b9a45188
                               at src/libstd/io/mod.rs:1412
   6:        0x10209c203 - std::sys_common::backtrace::_print::h89459d14ba97f5fa
                               at src/libstd/sys_common/backtrace.rs:65
   7:        0x10209c203 - std::sys_common::backtrace::print::ha4c6688e811b8829
                               at src/libstd/sys_common/backtrace.rs:50
   8:        0x10209c203 - std::panicking::default_hook::{{closure}}::h708e66cfeb0483ba
                               at src/libstd/panicking.rs:188
   9:        0x10209bf0a - std::panicking::default_hook::h39ea8ddf674c04ec
                               at src/libstd/panicking.rs:205
  10:        0x10209c8cb - std::panicking::rust_panic_with_hook::h9db77b22c2255a16
                               at src/libstd/panicking.rs:464
  11:        0x1020c3d5c - tokio::util::slab::page::Shared<T>::alloc_page::h5f7c9aa4589f8b71
  12:        0x101c52e87 - tokio::runtime::enter::enter::h605dac9a1285f8b6
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/enter.rs:19
  13:        0x101c0113f - tokio::runtime::blocking::shutdown::Receiver::wait::ha742d2fc85b4f4dd
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/blocking/shutdown.rs:38
  14:        0x101bfa600 - <tokio::runtime::blocking::pool::BlockingPool as core::ops::drop::Drop>::drop::hefb3ac9e6b79f523
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/blocking/pool.rs:116
  15:        0x101a0c4e5 - core::ptr::real_drop_in_place::h3ace56973c05ddc2
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/ptr/mod.rs:175
  16:        0x101a19722 - core::ptr::real_drop_in_place::hd384fcf31edeff1c
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/ptr/mod.rs:175
  17:        0x1019f9fd1 - reqwest::blocking::wait::enter::hac6e34211dc6065f
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.10.2/src/blocking/wait.rs:74
  18:        0x1019f7ccf - reqwest::blocking::wait::timeout::h39d937549bf9fff5
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.10.2/src/blocking/wait.rs:14
  19:        0x1019f414d - reqwest::blocking::client::ClientHandle::new::hcaf9e1f636484163
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.10.2/src/blocking/client.rs:696
  20:        0x1019f325d - reqwest::blocking::client::ClientBuilder::build::h0bbcb9eadc424f2d
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.10.2/src/blocking/client.rs:95
  21:        0x10181890f - sentry::transport::ReqwestHttpTransport::new_internal::http_client::{{closure}}::h9fc44f97cb2c2003
  22:        0x1017febcf - core::option::Option<T>::unwrap_or_else::ha11435ccbe6d2f39
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/option.rs:419
  23:        0x1018185d7 - sentry::transport::ReqwestHttpTransport::new_internal::http_client::hb4f891ac7a86a82f
  24:        0x101816f5e - sentry::transport::ReqwestHttpTransport::new_internal::h8c4694acfb08d000
  25:        0x101816d78 - <sentry::transport::DefaultTransportFactory as core::clone::Clone>::clone::h7f75f4aaf1695f3b
  26:        0x1018169ad - sentry::hub::Hub::add_breadcrumb::{{closure}}::hdc312c2acce6a7cd
  27:        0x10182f66d - sentry::client::parse_crate_name::{{closure}}::h548915556bc998d9
  28:        0x1016c76c0 - <sentry::client::Client as core::convert::From<T>>::from::hcc4cd15bf022f865
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/sentry-0.18.0/src/client.rs:244
  29:        0x1016c719d - <T as core::convert::Into<U>>::into::h090ffcf4281b301e
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/convert.rs:547
  30:        0x1016c725a - sentry::client::init::hb27136f55a2426ea
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/sentry-0.18.0/src/client.rs:650
  31:        0x1016e4ce5 - web::main::{{closure}}::h27feef068b99a416
                               at src/bin/web.rs:289
  32:        0x101715b0d - <std::future::GenFuture<T> as core::future::future::Future>::poll::{{closure}}::h950b04fbe23379b0
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/future.rs:43
  33:        0x1017137d8 - std::future::set_task_context::hd2dac08527303800
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/future.rs:79
  34:        0x101714b42 - <std::future::GenFuture<T> as core::future::future::Future>::poll::hc0220fbaa2386f01
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/future.rs:43
  35:        0x1016ac15a - tokio::runtime::enter::Enter::block_on::h5be849a6e97b05d9
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/enter.rs:100
  36:        0x1016901c3 - tokio::runtime::thread_pool::ThreadPool::block_on::hd13990d5d7ca8d3d
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/thread_pool/mod.rs:93
  37:        0x101710d1f - tokio::runtime::Runtime::block_on::{{closure}}::hf52d2037d7722732
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/mod.rs:413
  38:        0x10161d1b8 - tokio::runtime::context::enter::hfb3f3d94ef36ab6d
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/context.rs:72
  39:        0x1016b33d4 - tokio::runtime::handle::Handle::enter::h083bb04cefc98614
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/handle.rs:34
  40:        0x101710b9a - tokio::runtime::Runtime::block_on::h88537e2762871364
                               at /Users/anthony.mittaz/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.11/src/runtime/mod.rs:408
  41:        0x101716fa8 - web::main::h68bd07012f799c78
                               at src/bin/web.rs:285
  42:        0x10166c962 - std::rt::lang_start::{{closure}}::h7a9d78694ff5d5c9
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/rt.rs:61
  43:        0x10209c328 - std::rt::lang_start_internal::{{closure}}::hccd7db6d8a0ebab5
                               at src/libstd/rt.rs:48
  44:        0x10209c328 - std::panicking::try::do_call::hd5a3af8d00c06681
                               at src/libstd/panicking.rs:287
  45:        0x10209fadf - __rust_maybe_catch_panic
                               at src/libpanic_unwind/lib.rs:78
  46:        0x10209cd1e - std::panicking::try::h7a0bd4c078131d2f
                               at src/libstd/panicking.rs:265
  47:        0x10209cd1e - std::panic::catch_unwind::h75c3fbe62776ab10
                               at src/libstd/panic.rs:396
  48:        0x10209cd1e - std::rt::lang_start_internal::haa52aabac43378ff
                               at src/libstd/rt.rs:47
  49:        0x10166c942 - std::rt::lang_start::h8a0ff6f96c05cbd2
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/rt.rs:61
  50:        0x101717012 - web::main::h68bd07012f799c78

[jan-auer]

Thank you both, this confirms.

The proper fix is to move client initialization into the worker thread that is spawned for background event submission. I will look into creating a PR for this and also add a test case.

[vasilakisfil]

Just updated to latest tokio and I got the same issue.. I think the problem here is that Sentry uses the blocking variant of reqwest. Is there a way to change that so that it uses the non-blocking variant?? I really don't want sentry to block my threads..

edit: I am on linux btw, not OSX

[fhsgoncalves]

Same for me, I'm stuck in the 0.17 version for this reason. (also on linux)

[Swatinem]

I really don't want sentry to block my threads..

It doesn’t. It actually runs all that in a background thread. The problem here is that creating the client was done on the main thread (or the tokio executor in this case). Should be fixed by #186

[amaury1093]

Can we get a v0.18.1 with the fix? 🙏

[Swatinem]

Sorry for the delay. I hope I will be able to push out 0.19 even, in the next 2 weeks hopefully.

[kenoss]

@jan-auer

Are you running sentry::init after starting a tokio runtime? If so, could you try to move the sentry::init call earlier and check if the problem still persists? Thank you!

FYI and for others curious about sentry::init() in async main, notice that initialization would be correctly done if sentry::init() is called in the head of async main.
This is because the initialization of PROCESS_HUB, which is lazy_static, happens in sentry::init() 1 2.

Lots of examples on the internet and documentations (e.g. https://github.com/getsentry/sentry-rust/blob/0.23.0/sentry-actix/src/lib.rs#L23-L28) implicitly depends on that fact.

Edit: Additional info about initialization timing of lazy_static https://matklad.github.io/2020/10/03/fast-thread-locals-in-rust.html .