Skip to content

restore can panic with sftp #523

Description

@ltratt

When restoreing from sftp I get a lengthy series of panics (see below), seemingly from every thread (the output is thousands of lines so I've cropped out what seems to be the main bit!).

[00:00:01] reading index...               ██████████████████████████████████████[ERROR] error=IO Error (Excluding `io::ErrorKind::WouldBlock`): unexpected end of file.
[ERROR] Waiting on remote sftp subsystem to exit failed: Failed to create sftp from session: the remote process has terminated, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/ltratt/.local/state/.ssh-connectionredact" }), ctl: "/home/ltratt/.local/state/.ssh-connectionbJEUiq/master", master_log: Some("/home/ltratt/.local/state/.ssh-connectionredact/log") }))
[ERROR] error=IO Error (Excluding `io::ErrorKind::WouldBlock`): unexpected end of file.
[ERROR] Waiting on remote sftp subsystem to exit failed: Failed to create sftp from session: the remote process has terminated, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/ltratt/.local/state/.ssh-connectionredact" }), ctl: "/home/ltratt/.local/state/.ssh-connection5o7xdL/master", master_log: Some("/home/ltratt/.local/state/.ssh-connectionredact/log") }))
[WARN] will retry Read (attempt 1) after 1.6585716609999999s because: Unexpected (temporary) at read => sftp error

Context:
   service: sftp
   path: data/redacted
   range: 0-40306685

Source:
   OriginalError: IO Error (Excluding `io::ErrorKind::WouldBlock`): unexpected end of file., curr err raised when cleaning up: Failed to create sftp from session: the remote process has terminated.: Failed to create sftp from session: the remote process has terminated: the remote process has terminated

Backtrace:
   0: core::ops::function::FnOnce::call_once
             at /usr/local/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
   1: core::bool::<impl bool>::then
             at /usr/local/lib/rustlib/src/rust/library/core/src/bool.rs:66:24
   2: opendal_core::types::error::Error::new
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/error.rs:331:18
   3: opendal_service_sftp::error::parse_sftp_error
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-service-sftp-0.57.0/src/error.rs:37:19
   4: core::ops::function::FnOnce::call_once
             at /usr/local/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
   5: core::result::Result<T,E>::map_err
             at /usr/local/lib/rustlib/src/rust/library/core/src/result.rs:968:27
   6: <opendal_service_sftp::core::Manager as fastpool::common::ManageObject>::create::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-service-sftp-0.57.0/src/core.rs:125:14
   7: fastpool::bounded::Pool<M>::get::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/fastpool-1.1.0/src/bounded.rs:311:56
   8: opendal_service_sftp::core::SftpCore::connect::{{closure}}::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/macros/select.rs:705:49
   9: <core::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
             at /usr/local/lib/rustlib/src/rust/library/core/src/future/poll_fn.rs:151:9
  10: opendal_service_sftp::core::SftpCore::connect::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-service-sftp-0.57.0/src/core.rs:81:9
  11: <opendal_service_sftp::backend::SftpBackend as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-service-sftp-0.57.0/src/backend.rs:258:42
  12: <opendal_core::layers::error_context::ErrorContextAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/error_context.rs:90:14
  13: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  14: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  15: <opendal_core::layers::simulate::SimulateAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/simulate.rs:275:37
  16: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  17: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  18: <opendal_core::layers::complete::CompleteAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/complete.rs:81:14
  19: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  20: <opendal_core::layers::correctness_check::CorrectnessAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/correctness_check.rs:132:37
  21: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  22: <opendal_core::layers::type_eraser::TypeEraseAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/type_eraser.rs:68:14
  23: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  24: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /usr/local/lib/rustlib/src/rust/library/core/src/future/future.rs:133:9
  25: <dyn opendal_core::raw::accessor::AccessDyn as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:423:35
  26: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  27: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  28: <backon::retry::Retry<B,T,E,Fut,FutureFn,SF,RF,NF,AF> as core::future::future::Future>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/backon-1.6.0/src/retry.rs:388:47
  29: <opendal_layer_retry::RetryAccessor<A,I> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-layer-retry-0.57.0/src/lib.rs:334:14
  30: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  31: <opendal_core::layers::type_eraser::TypeEraseAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/type_eraser.rs:68:14
  32: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  33: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /usr/local/lib/rustlib/src/rust/library/core/src/future/future.rs:133:9
  34: <dyn opendal_core::raw::accessor::AccessDyn as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:423:35
  35: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  36: <opendal_layer_logging::LoggingAccessor<A,I> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-layer-logging-0.57.0/src/lib.rs:307:14
  37: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  38: <opendal_core::layers::type_eraser::TypeEraseAccessor<A> as opendal_core::raw::layer::LayeredAccess>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/layers/type_eraser.rs:68:14
  39: opendal_core::raw::layer::<impl opendal_core::raw::accessor::Access for L>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/layer.rs:207:47
  40: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /usr/local/lib/rustlib/src/rust/library/core/src/future/future.rs:133:9
  41: <dyn opendal_core::raw::accessor::AccessDyn as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:423:35
  42: <alloc::sync::Arc<T> as opendal_core::raw::accessor::Access>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/accessor.rs:508:53
  43: opendal_core::types::context::read::ReadGenerator::next_reader::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/context/read.rs:197:63
  44: <opendal_core::types::read::buffer_stream::StreamingReader as opendal_core::raw::oio::read::api::Read>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/read/buffer_stream.rs:77:60
  45: <opendal_core::raw::enum_utils::TwoWays<ONE,TWO> as opendal_core::raw::oio::read::api::Read>::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/raw/enum_utils.rs:57:41
  46: <opendal_core::types::read::buffer_stream::BufferStream as futures_core::stream::Stream>::poll_next::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/read/buffer_stream.rs:358:49
  47: <opendal_core::types::read::buffer_stream::BufferStream as futures_core::stream::Stream>::poll_next
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/read/buffer_stream.rs:365:52
  48: <S as futures_core::stream::TryStream>::try_poll_next
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.32/src/stream.rs:206:14
  49: <futures_util::stream::try_stream::try_collect::TryCollect<St,C> as core::future::future::Future>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.32/src/stream/try_stream/try_collect.rs:46:47
  50: opendal_core::types::read::reader::Reader::read::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/read/reader.rs:122:81
  51: opendal_core::types::operator::operator::Operator::read_inner::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/operator/operator.rs:533:44
  52: opendal_core::types::operator::operator::Operator::read_options::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/types/operator/operator.rs:515:60
  53: opendal_core::blocking::operator::Operator::read_options::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/opendal-core-0.57.0/src/blocking/operator.rs:386:68
  54: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:375:24
  55: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/loom/std/unsafe_cell.rs:16:9
  56: tokio::runtime::task::core::Core<T,S>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:364:30
  57: tokio::runtime::task::harness::poll_future::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:535:30
  58: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /usr/local/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:274:9
  59: std::panicking::catch_unwind::do_call
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:581:40
  60: std::panicking::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:544:19
  61: std::panic::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panic.rs:359:14
  62: tokio::runtime::task::harness::poll_future
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:523:18
  63: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:210:27
  64: tokio::runtime::task::harness::Harness<T,S>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:155:20
  65: tokio::runtime::task::raw::RawTask::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:267:18
  66: tokio::runtime::task::LocalNotified<S>::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/mod.rs:510:13
  67: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:761:22
  68: tokio::task::coop::with_budget
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:167:5
  69: tokio::task::coop::budget
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:133:5
  70: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:675:9
  71: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:585:29
  72: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:550:24
  73: tokio::runtime::context::scoped::Scoped<T>::set
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/scoped.rs:40:9
  74: tokio::runtime::context::set_scheduler::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:38
  75: std::thread::local::LocalKey<T>::try_with
             at /usr/local/lib/rustlib/src/rust/library/std/src/thread/local.rs:513:12
  76: std::thread::local::LocalKey<T>::with
             at /usr/local/lib/rustlib/src/rust/library/std/src/thread/local.rs:477:20
  77: tokio::runtime::context::set_scheduler
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:17
  78: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:545:9
  79: tokio::runtime::context::runtime::enter_runtime
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/runtime.rs:65:16
  80: tokio::runtime::scheduler::multi_thread::worker::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:537:5
  81: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:503:45
  82: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/task.rs:42:21
  83: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:375:24
  84: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/loom/std/unsafe_cell.rs:16:9
  85: tokio::runtime::task::core::Core<T,S>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:364:30
  86: tokio::runtime::task::harness::poll_future::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:535:30
  87: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /usr/local/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:274:9
  88: std::panicking::catch_unwind::do_call
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:581:40
  89: std::panicking::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:544:19
  90: std::panic::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panic.rs:359:14
  91: tokio::runtime::task::harness::poll_future
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:523:18
  92: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:210:27
  93: tokio::runtime::task::harness::Harness<T,S>::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:155:20
  94: tokio::runtime::task::raw::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:337:13
  95: tokio::runtime::task::raw::RawTask::poll
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:267:18
  96: tokio::runtime::task::UnownedTask<S>::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/mod.rs:547:13
  97: tokio::runtime::blocking::pool::Task::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:161:19
  98: tokio::runtime::blocking::pool::Inner::run
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:518:22
  99: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at ./.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:474:47
 100: std::sys::backtrace::__rust_begin_short_backtrace
             at /usr/local/lib/rustlib/src/rust/library/std/src/sys/backtrace.rs:166:18
 101: std::thread::lifecycle::spawn_unchecked::{{closure}}::{{closure}}
             at /usr/local/lib/rustlib/src/rust/library/std/src/thread/lifecycle.rs:91:13
 102: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /usr/local/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:274:9
 103: std::panicking::catch_unwind::do_call
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:581:40
 104: std::panicking::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panicking.rs:544:19
 105: std::panic::catch_unwind
             at /usr/local/lib/rustlib/src/rust/library/std/src/panic.rs:359:14
 106: std::thread::lifecycle::spawn_unchecked::{{closure}}
             at /usr/local/lib/rustlib/src/rust/library/std/src/thread/lifecycle.rs:89:26
 107: core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /usr/local/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
 108: <std::sys::thread::unix::Thread>::new::thread_start
 109: _rthread_start
             at /usr/src/lib/librthread/rthread.c:99:11
 110: __tfork_thread
             at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:87:0


[ERROR] error=IO Error (Excluding `io::ErrorKind::WouldBlock`): unexpected end of file.
[ERROR] Waiting on remote sftp subsystem to exit failed: Failed to create sftp from session: the remote process has terminated, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/ltratt/.local/state/.ssh-connectionredact" }), ctl: "/home/ltratt/.local/state/.ssh-connectionvPiu1J/master", master_log: Some("/home/ltratt/.local/state/.ssh-connectionvredact/log") }))
[WARN] will retry Read (attempt 1) after 1.403115422s because: Unexpected (temporary) at read => sftp error

Context:
   service: sftp
   path: data/e9/e98aee94c96e4baba219c1bfb2efb09b6176c989a587f198c25cd2eefad39a31
   range: 40310868-52218824

Source:
   OriginalError: IO Error (Excluding `io::ErrorKind::WouldBlock`): unexpected end of file., curr err raised when cleaning up: Failed to create sftp from session: the remote process has terminated.: Failed to create sftp from session: the remote process has terminated: the remote process has terminated

If I try to restore the same snapshot from s3 I then eventually run into:

[00:00:19] restoring file contents...     ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░  10.69 MiB/957.50 MiB 643.80 KiB/s (ETA 28m)
thread '<unnamed>' (487546) panicked at /home/ltratt/.cargo/git/checkouts/rustic_core-abe509602c0243d0/7df591b/crates/core/src/commands/restore.rs:637:69:
called `Result::unwrap()` on an `Err` value: OpeningFileFailed(Os { code: 13, kind: PermissionDenied, message: "Permission denied" })
[00:00:19] restoring file contents...     ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░  10.69 MiB/957.50 MiB 638.69 KiB/s (ETA 28m)

I don't know which file might be giving that error, as rustic exits after this error. If I keep rerunning restore with the S3 snapshot, I do get a bit further through restoring each time, and eventually I immediately run into the "permission denied" error (with sftp I don't seem to make progress at all). This is on OpenBSD, and happens with either the OpenBSD package, or if I build fresh from git. repairing the repository doesn't seem to make any difference.

[CCing @catap who might have seen this too?]

Metadata

Metadata

Assignees

No one assigned

    Labels

    S-triageStatus: Waiting for a maintainer to triage this issue/PR

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions