Exception while deregister()ing on remove

[wictory]

Hi!

I have a problem with tokio-curl throwing an exception when deregister()ing fails @ https://github.com/tokio-rs/tokio-curl/blob/master/src/unix.rs#L235 . The reason deregister() fails for me here is a "Bad file descriptor".

As see it there are multiple possible way of solving this issue: 1) Remove the .expect() call and ignore the error. 2) match the error and only panic on a subset of the cases in std::io::Error. 3) Maybe the issue does not belong to this crate, and the issue has to do with the fact that the exception is not caught in curl-rust @ https://github.com/alexcrichton/curl-rust/blob/master/src/multi.rs#L137

Cheers, waiting to hear what someone else has to say about this.

[wictory]

The error I get is when I use tokio-curl from the telebot crate without doing anything than keeping the connection alive. Rust backtrace:

thread 'main' panicked at 'failed to deregister: Error { repr: Os { code: 9, message: "Bad file descriptor" } }', /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libcore/result.rs
:845
stack backtrace:
   1:     0x55f32f4b03cc - std::sys::imp::backtrace::tracing::imp::write::h9c41d2f69e5caabf
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:42
   2:     0x55f32f4b2afe - std::panicking::default_hook::{{closure}}::h1f61f3c769fffe7a
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:351
   3:     0x55f32f4b2704 - std::panicking::default_hook::hd5bda4e453dfb4be
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:367
   4:     0x55f32f4b2f9b - std::panicking::rust_panic_with_hook::hffbc74969c7b5d87
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:555
   5:     0x55f32f4b2e34 - std::panicking::begin_panic::h3bbdbb2a23440035
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:517
   6:     0x55f32f4b2d59 - std::panicking::begin_panic_fmt::h34f5b320b0f94559
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:501
   7:     0x55f32f4b2ce7 - rust_begin_unwind
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:477
   8:     0x55f32f4da94d - core::panicking::panic_fmt::h1016b85b51d1931f
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libcore/panicking.rs:69
   9:     0x55f32f410df2 - core::result::unwrap_failed::hc1006aeafe0fe326
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libcore/macros.rs:29
  10:     0x55f32f407631 - <core::result::Result<T, E>>::expect::hbad9348962ac74f1
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libcore/result.rs:769
  11:     0x55f32f4221dc - tokio_curl::imp::Data::schedule_socket::h82c7f229ade021fd
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:233
  12:     0x55f32f420723 - tokio_curl::imp::Session::new::{{closure}}::{{closure}}::h2356b4bdfda95ee8
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:89
  13:     0x55f32f4025bc - <scoped_tls::ScopedKey<T>>::with::hdfc00a59966f554c
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/scoped-tls-0.1.0/src/lib.rs:169
  14:     0x55f32f42078e - tokio_curl::imp::Session::new::{{closure}}::h4dcd92ffbd3a68cf
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:89
  15:     0x55f32f43f7b5 - curl::multi::Multi::_socket_function::cb::{{closure}}::h65cddf5c6878a148
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.3/src/multi.rs:139
  16:     0x55f32f4360e1 - <std::panic::AssertUnwindSafe<F> as core::ops::FnOnce<()>>::call_once::ha58ece3ed5c94c3a
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panic.rs:296
  17:     0x55f32f42bc46 - std::panicking::try::do_call::h0bd46c168cd50357
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:460
  18:     0x55f32f4b9efa - __rust_maybe_catch_panic
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libpanic_unwind/lib.rs:98
  19:     0x55f32f42a83b - std::panicking::try::h58aeb48d200ce010
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:436
  20:     0x55f32f42a051 - std::panic::catch_unwind::h8cbf434d4e67df4c
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panic.rs:361
  21:     0x55f32f43792a - curl::panic::catch::hbcb93c015f77c779
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.3/src/panic.rs:17
  22:     0x55f32f43f72a - curl::multi::Multi::_socket_function::cb::hbac72b5ac6e80f5d
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.3/src/multi.rs:137
  23:     0x7fccb19b8f80 - <unknown>
  24:     0x7fccb19bc03b - <unknown>
  25:     0x7fccb19bc0b6 - curl_multi_socket_action
  26:     0x55f32f4401ab - curl::multi::Multi::action::hd80734cb765f1efe
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.3/src/multi.rs:349
  27:     0x55f32f4246d7 - tokio_curl::imp::Data::check_socket::h70ccb855074a7c14
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:383
  28:     0x55f32f4236f3 - tokio_curl::imp::Data::check::h0453dae123abd37c
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:334
  29:     0x55f32f4212f1 - <tokio_curl::imp::Data as futures::future::Future>::poll::{{closure}}::{{closure}}::hcd0b60c824bcac9b
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:155
  30:     0x55f32f41d253 - futures::task_impl::set::{{closure}}::hef0dcace6b886c30
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:50
  31:     0x55f32f406446 - <std::thread::local::LocalKey<T>>::with::hb2718cbb96ba10e5
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/thread/local.rs:253
  32:     0x55f32f41cfdd - futures::task_impl::set::hd9b217db963aaeda
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:47
  33:     0x55f32f41cbd8 - futures::task_impl::with_unpark_event::{{closure}}::h7cf81e90cb401054
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:175
  34:     0x55f32f41d44b - futures::task_impl::with::h89f3d621322c7618
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:59
  35:     0x55f32f41ca1a - futures::task_impl::with_unpark_event::ha23e5f9e56b38ccf
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:169
  36:     0x55f32f4214d7 - <tokio_curl::imp::Data as futures::future::Future>::poll::{{closure}}::ha7080966fd168450
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:154
  37:     0x55f32f4022fc - <scoped_tls::ScopedKey<T>>::set::hb0742c662ee715f1
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/scoped-tls-0.1.0/src/lib.rs:135
  38:     0x55f32f4210b8 - <tokio_curl::imp::Data as futures::future::Future>::poll::h30fcabe8ccd432ad
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-curl-0.1.8/src/unix.rs:143
  39:     0x55f32f41efca - <futures::future::map_err::MapErr<A, F> as futures::future::Future>::poll::h38d55bc714423e53
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/future/map_err.rs:29
  40:     0x55f32f45e101 - <Box<F> as futures::future::Future>::poll::h30ef2826e421f9b9
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/future/mod.rs:103
  41:     0x55f32f45329c - <futures::task_impl::Spawn<F>>::poll_future::{{closure}}::h88dc6cfe95706615
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:312
  42:     0x55f32f4534ce - <futures::task_impl::Spawn<T>>::enter::{{closure}}::hc8c1f5758e71c1d1
  43:     0x55f32f4616bf - futures::task_impl::set::{{closure}}::he6c405c69f455413
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:50
  44:     0x55f32f453bb5 - <std::thread::local::LocalKey<T>>::with::h75c78c90351ea42b
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/thread/local.rs:253
  45:     0x55f32f4615aa - futures::task_impl::set::h2c3ddb5d0e8e788c
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:47
  46:     0x55f32f4533dc - <futures::task_impl::Spawn<T>>::enter::hf6e0be8de68e5b23
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:399
  47:     0x55f32f45323a - <futures::task_impl::Spawn<F>>::poll_future::ha7f0460e1982e9ec
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.9/src/task_impl/mod.rs:312
  48:     0x55f32f46c166 - tokio_core::reactor::Core::dispatch_task::{{closure}}::h96d92c99d94eebb6
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.3/src/reactor/mod.rs:339
  49:     0x55f32f4505ee - <scoped_tls::ScopedKey<T>>::set::ha4224a112cb2f4f0
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/scoped-tls-0.1.0/src/lib.rs:135
  50:     0x55f32f46bb4c - tokio_core::reactor::Core::dispatch_task::h63a5544afe45183d
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.3/src/reactor/mod.rs:339
  51:     0x55f32f46af88 - tokio_core::reactor::Core::dispatch::h8f2c2d48706e3fb2
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.3/src/reactor/mod.rs:299
  52:     0x55f32f46aadb - tokio_core::reactor::Core::poll::h55ea4270c7ef7bd0
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.3/src/reactor/mod.rs:287
  53:     0x55f32f24c990 - tokio_core::reactor::Core::run::h533ebd2e67a3ca7f
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.3/src/reactor/mod.rs:225
  54:     0x55f32f39284f - telebot::bot::RcBot::run::h93ad4d8d5eb97b37
                        at /home/wictory/.cargo/registry/src/github.com-1ecc6299db9ec823/telebot-0.0.9/src/bot.rs:240
  55:     0x55f32f2431ae - todo_telegrambot::main::h9eb3ff24f410ce30
                        at /home/wictory/src/draft/todo-telegrambot/src/main.rs:65
  56:     0x55f32f4b9efa - __rust_maybe_catch_panic
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libpanic_unwind/lib.rs:98
  57:     0x55f32f4b3706 - std::rt::lang_start::ha0568cc91d8c5b09
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panicking.rs:436
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/panic.rs:361
                        at /buildslave/rust-buildbot/slave/nightly-dist-rustc-linux/build/src/libstd/rt.rs:57
  58:     0x55f32f244392 - main
  59:     0x7fccb03f9730 - __libc_start_main
  60:     0x55f32f0bbb98 - _start
  61:                0x0 - <unknown>

[alexcrichton]

Thanks for the report! Sounds like something bad is definitely happening. Is there a way I could reproduce this locally? If it's not easy to do so then could you try using env_logger and gist the logs with RUST_LOG=trace?

[wictory]

Here is a gist with a trace and the code to produce it. https://gist.github.com/wictory/4ef62482716ec1073ec718e6983265be The bug is easy to reproduce given that the telegram servers behave they do now :)

[wictory]

So, the trace is a bit lengthy since it takes a couple of seconds before the bug is triggered.

[alexcrichton]

@wictory hm I wonder if curl is closing the socket itself ahead of time... Are you on Linux? If so can you also run strace (with RUST_LOG enabled) and gist that?

Also, is there an easy-ish way for me to reproduce? E.g. some series of commands.

[wictory]

I'm on Linux, I updated the gist with the output of strace and the program with RUST_LOG=trace on.

[wictory]

If you take the files in the gist (Cargo.toml, Cargo.lock, main.rs); and build a cargo project of it. Then you need a telegram bot api token (which you can get from the botfather on telegram, if you use it). I would rather not give you my api token, at least over this channel :P After this the command is basically cargo run and wait for ~10 sec

[alexcrichton]

@wictory can you try out https://github.com/tokio-rs/tokio-curl/commit/5dea09b2a46f848becb81148df410e4e7545a36e and see if it's fixed for you?

It definitely looks like curl is closing the socket before it's calling our callback, so we definitely can't call deregister. That was added in https://github.com/tokio-rs/tokio-curl/commit/3306b320d38dbb4ff2a42a8587ccf9a4fe2c56cc though so I'm not entirely sure what's up.

[alexcrichton]

Hm no that commit has other problems with it, I'll have to keep thinking.

[wictory]

Yes, I ran it and created a new gist https://gist.github.com/wictory/b806fc3ae12acc640a691f627f398d83

[alexcrichton]

Ok I believe https://github.com/tokio-rs/tokio-curl/commit/6d3cdd1b126b8c739205184f8def4a9700dca91a should handle that. Want to try that on for size?

[wictory]

For size?

[alexcrichton]

Oh sorry, just a phrase. Want to see if that commit works for you?

[wictory]

Ok, this one seems to work, as in, the program I have doesn't crash.

[alexcrichton]

Awesome, thanks for testing! I'll publish a release with that.

[wictory]

Thanks for fixing!