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

cancellation of get_lsn_by_timestamp handler prints full anyhow backtrace #7406

Closed
problame opened this issue Apr 17, 2024 · 0 comments · Fixed by #7949
Closed

cancellation of get_lsn_by_timestamp handler prints full anyhow backtrace #7406

problame opened this issue Apr 17, 2024 · 0 comments · Fixed by #7949
Assignees
@yliang412
Labels
a/observability Area: related to observability c/storage/pageserver Component: storage: pageserver m/good_first_issue Moment: when doing your first Neon contributions

Comments

@problame
Copy link
Contributor

problame commented Apr 17, 2024 •
edited
Loading 

2024-04-17T10:53:55.286353Z ERROR request{method=GET path=/v1/tenant/cebe21e8c0b2e7449eab58f0c196dd39/timeline/eb672319d49d517df248c7dc739a5e5b/get_lsn_by_timestamp request_id=241fe2a1-8f6f-460b-bbae-285fdf17e5b2}: Cancelled request finished with an error: InternalServerError(request was cancelled

Stack backtrace:
   0: anyhow::__private::format_err
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.71/src/lib.rs:669:13
   1: pageserver::http::routes::<impl core::convert::From<pageserver::tenant::timeline::PageReconstructError> for utils::http::error::ApiError>::from
             at /home/admin/neon/pageserver/src/http/routes.rs:164:47
   2: <core::result::Result<T,F> as core::ops::try_trait::FromResidual<core::result::Result<core::convert::Infallible,E>>>::from_residual
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/result.rs:1959:27
   3: pageserver::http::routes::get_lsn_by_timestamp_handler::{{closure}}::{{closure}}
             at /home/admin/neon/pageserver/src/http/routes.rs:734:18
   4: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.37/src/instrument.rs:272:9
   5: pageserver::http::routes::get_lsn_by_timestamp_handler::{{closure}}
             at /home/admin/neon/pageserver/src/http/routes.rs:695:1
   6: pageserver::http::routes::api_handler::{{closure}}::{{closure}}::{{closure}}::{{closure}}
             at /home/admin/neon/pageserver/src/http/routes.rs:2227:48
   7: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.37/src/instrument.rs:272:9
   8: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/future/future.rs:124:9
   9: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  10: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
      tokio::runtime::task::core::Core<T,S>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  11: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  12: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/panic/unwind_safe.rs:272:9
  13: std::panicking::try::do_call
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:554:40
  14: __rust_try
  15: std::panicking::try
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:518:19
  16: std::panic::catch_unwind
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panic.rs:142:14
  17: tokio::runtime::task::harness::poll_future
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
  18: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
  19: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
  20: tokio::runtime::task::raw::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
  21: tokio::runtime::task::raw::RawTask::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
  22: tokio::runtime::task::LocalNotified<S>::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:427:9
  23: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:576:13
  24: tokio::runtime::coop::with_budget
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:107:5
      tokio::runtime::coop::budget
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:73:5
      tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:575:9
  25: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:526:24
  26: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:491:21
  27: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/scoped.rs:40:9
  28: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:26
  29: std::thread::local::LocalKey<T>::try_with
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/thread/local.rs:286:16
  30: std::thread::local::LocalKey<T>::with
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/thread/local.rs:262:9
  31: tokio::runtime::context::set_scheduler
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:9
  32: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:486:9
  33: tokio::runtime::context::runtime::enter_runtime
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/runtime.rs:65:16
  34: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:478:5
  35: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:447:45
  36: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/task.rs:42:21
  37: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  38: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
      tokio::runtime::task::core::Core<T,S>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  39: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  40: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/panic/unwind_safe.rs:272:9
  41: std::panicking::try::do_call
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:554:40
  42: __rust_try
  43: std::panicking::try
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:518:19
  44: std::panic::catch_unwind
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panic.rs:142:14
  45: tokio::runtime::task::harness::poll_future
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
  46: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
  47: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
  48: tokio::runtime::task::raw::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
  49: tokio::runtime::task::raw::RawTask::poll
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
  50: tokio::runtime::task::UnownedTask<S>::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:464:9
  51: tokio::runtime::blocking::pool::Task::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:159:9
  52: tokio::runtime::blocking::pool::Inner::run
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:513:17
  53: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/admin/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:471:13
  54: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/sys_common/backtrace.rs:155:18
  55: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/thread/mod.rs:529:17
  56: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/panic/unwind_safe.rs:272:9
  57: std::panicking::try::do_call
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:554:40
  58: __rust_try
  59: std::panicking::try
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panicking.rs:518:19
  60: std::panic::catch_unwind
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/panic.rs:142:14
      std::thread::Builder::spawn_unchecked_::{{closure}}
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/thread/mod.rs:528:30
  61: core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/core/src/ops/function.rs:250:5
  62: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/alloc/src/boxed.rs:2015:9
      <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/alloc/src/boxed.rs:2015:9
      std::sys::pal::unix::thread::Thread::new::thread_start
             at /rustc/aedd173a2c086e558c2b66d3743b344f977621a7/library/std/src/sys/pal/unix/thread.rs:108:17
  63: start_thread
  64: clone)
@problame problame self-assigned this Apr 17, 2024
@problame problame added c/storage/pageserver Component: storage: pageserver a/observability Area: related to observability m/good_first_issue Moment: when doing your first Neon contributions labels Apr 17, 2024
@problame problame removed their assignment Apr 17, 2024
@yliang412 yliang412 mentioned this issue Jun 4, 2024
Merged
5 tasks
yliang412 added a commit that referenced this issue Jun 6, 2024
@yliang412
refactor(pageserver): designated api error type for cancelled request (…
630cfbe 
…#7949)

Closes #7406.

## Problem

When a `get_lsn_by_timestamp` request is cancelled, an anyhow error is
exposed to handle that case, which verbosely logs the error. However, we
don't benefit from having the full backtrace provided by anyhow in this
case.

## Summary of changes

This PR introduces a new `ApiError` type to handle errors caused by
cancelled request more robustly.
-  A new enum variant `ApiError::Cancelled`
- Currently the cancelled request is mapped to status code 500.
- Need to handle this error in proxy's `http_util` as well.
- Added a failpoint test to simulate cancelled `get_lsn_by_timestamp`
request.

Signed-off-by: Yuchen Liang <yuchen@neon.tech>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@yliang412 yliang412

Labels
a/observability Area: related to observability c/storage/pageserver Component: storage: pageserver m/good_first_issue Moment: when doing your first Neon contributions
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

refactor(pageserver): designated api error type for cancelled request neondatabase/neon
2 participants
@problame @yliang412