CORE-8618 crash_tracker: record uncaught startup exceptions #24854
Conversation
pgellert
requested review from
michael-redpanda and
a team
and removed request for
a team and
michael-redpanda
pgellert
requested review from
BenPope,
michael-redpanda and
IoannisRP
and removed request for
a team
CI test resultstest results on build#60910
test results on build#60955
test results on build#61003
test results on build#61107
test results on build#61168
test results on build#61179
|
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
1dc3a86 to
09ccff8
Compare
|
force-push: rebase to |
| // Create the crash recorder file | ||
| auto f = co_await ss::open_file_dma( | ||
| _crash_report_file_name.c_str(), | ||
| ss::open_flags::create | ss::open_flags::rw); |
| _crash_report_file_name.c_str(), | ||
| ss::open_flags::create | ss::open_flags::rw); | ||
| co_await f.close(); | ||
| co_await ss::sync_directory(_crash_report_file_name.parent_path().string()); |
There was a problem hiding this comment.
are you protecting against a certain scenario by syncing the directory here? a comment would probably be helpful since it's likely important?
There was a problem hiding this comment.
I've added this comment:
Sync the parent dir to ensure that the new file is observable to the ::open() call below and to later restarts of the process
Let me know if that explains it well enough.
There was a problem hiding this comment.
it doesn't hurt anything, but you don't really need to do the sync for these cases--it's only good for if the actual node crashes.
There was a problem hiding this comment.
Makes sense. I've removed it now since it's not necessary.
| for (const auto& frag : _serde_output) { | ||
| auto written = ::write(_fd, frag.get(), frag.size()); | ||
| if (written == -1) { | ||
| return false; |
There was a problem hiding this comment.
I wouldn't expect us to be able to continue to write to the file descriptor if an earlier ::write() call failed. Am I missing something here? But I also don't see any problems with continuing to try to write (the man page doesn't say that this would be a problem), so I've changed the code to continue to try to write here.
| co_await ss::sync_directory( | ||
| _crash_report_file_name.parent_path().string()); |
There was a problem hiding this comment.
sync is probably unnecessary, but maybe you could provide a little context on what you're trying to protect against?
There was a problem hiding this comment.
This is the comment I've added:
Sync the parent dir to ensure that later restarts of the process cannot observe this file
Let me know if it explains it well enough.
There was a problem hiding this comment.
visibility is handled by the kernel. process restarts don't need the sync. it doesn't hurt anything, except performance if you were doing many syncs.
src/v/crash_tracker/recorder.cc
Outdated
| std::lock_guard<ss::util::spinlock> g(_writer_lock); | ||
| co_await _writer.release(); |
There was a problem hiding this comment.
can you comment on the use of a spinlock here compared to a blocking mutex? generally i would think that holding a spinlock for anything other than the tiniest of cpu-bound critical sections (and release here is performing I/O) would not perform as well as a blocking mutex where the kernel can put a blocking thread to sleep and understand the chain of dependencies.
There was a problem hiding this comment.
I've added this comment now:
The writer has shared state, so accessing it from multiple threads
is guarded by this lock. We are using the async-signal safe
ss::util::spinlock instead of more efficient locking mechanisms like the
seastar primitives or std::mutex to ensure that we can safely use the
lock in a singal handler context.
This lock will be used in signal handlers in a follow-up PR so it needs to be async-signal safe. The pthread mutex isn't: https://man7.org/linux/man-pages/man3/pthread_mutex_lock.3.html.
The standard seastar concurrency primitives are also not available in the signal handler because the signal handler runs outside of the reactor. ss::util::spinlock is specifically an async-signal safe spinlock that seastar uses in its signal handlers: https://github.com/scylladb/seastar/blob/c3f33c116ecde6f37cea6f656e1dfed2a4cd26a2/include/seastar/util/spinlock.hh#L85-L88
I am not worried about the performance overhead of the spinlock because all of the code paths where the lock is used are outside of performance-critical sections (startup, shutdown, mid-crash), and I don't expect the lock to be contended except for some highly unlikely scenarios (eg. segfault while already recording a failure).
src/v/crash_tracker/recorder.cc
Outdated
| // If the recorder is already locked, give up to prevent possible deadlocks. | ||
| // For example, an assertion failure while recording a segfault may lead to | ||
| // a deadlock if we unconditionally waited for the lock here. | ||
| std::unique_lock<ss::util::spinlock> g(_writer_lock, std::try_to_lock); |
There was a problem hiding this comment.
Answered here: #24854 (comment)
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
09ccff8 to
c7e2ba2
Compare
|
force-push: address code review feedback |
Defines it under `${datadir}/crash_reports` to store crash reports.
It needs to be special-cased in the `compute_storage.py` script to
ensure it isn't mistaken for a log file directory.
Define a custom exception for `crash_loop_limit_reached` to allow pattern matching for it in a follow up commit. We specifically do not want to record `crash_loop_limit_reached` errors as crashes because they are generally not informative crashes. Recording them as real crashes would build up garbage on disk, which would lead to real crash logs expiring on disk earlier.
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
c7e2ba2 to
cfae5ae
Compare
|
force-push: rebased to dev now that the base PR (#24828) merged |
|
|
||
| void prepared_writer::write() { | ||
| vassert(_state == state::filled, "Unexpected state: {}", _state); | ||
| _state = state::written; |
There was a problem hiding this comment.
Is this transition correct if try_write_crash() fails? Should failure be represented in the state machine?
There was a problem hiding this comment.
Is this transition correct if
try_write_crash()fails?
Yes, it's correct though I get that the naming is a bit misleading. Maybe consumed would be a better name to represent this state.
Should failure be represented in the state machine?
We could add a separate failure state in the state machine but at the moment it is identical to the written state so I think it's simpler as is.
| cd.stacktrace.begin() + pos, | ||
| cd.stacktrace.size() - pos, |
There was a problem hiding this comment.
nitpick: You could use std::next/prev if there's a lint complaint about pointer arithmetic here.
There was a problem hiding this comment.
Nice, thank you! Let me carry this onto a follow-up PR unless any more changes come up for this PR.
There was a problem hiding this comment.
I kept it as cd.stacktrace.begin() + pos because std::next(cd.stacktrace.begin(), static_cast<std::ptrdiff_t>(pos)) seems overly verbose, and it's not failing the automated linting checks.
| while (written < frag.size()) { | ||
| auto res = ::write( | ||
| _fd, frag.get() + written, frag.size() - written); | ||
| if (res == -1) { |
There was a problem hiding this comment.
did you consider retrying on EINTR? it's niche, but still possible. and you did state that you were avoiding seastar I/O because you cared about signal handling...
There was a problem hiding this comment.
Maybe also EAGAIN, but I don't think this should happen here
There was a problem hiding this comment.
did you consider retrying on EINTR?
Yeah, it makes sense to retry on EINTR. I've added this now.
and you did state that you were avoiding seastar I/O because you cared about signal handling...
I care about signal handler and seastar I/O for a different reason. It's that it is not safe to perform seastar I/O in a signal handler. Nevertheless, handling signals interrupting I/O (EINTR) is a net reliability improvement, so it makes sense to add it.
Maybe also EAGAIN, but I don't think this should happen here
The man page tells me EAGAIN is only for (non-blocking) sockets, so I don't think we need to handle that here. (https://man7.org/linux/man-pages/man2/write.2.html)
| auto f = co_await ss::open_file_dma( | ||
| _crash_report_file_name.c_str(), | ||
| ss::open_flags::create | ss::open_flags::rw | ss::open_flags::truncate | ||
| | ss::open_flags::exclusive); |
There was a problem hiding this comment.
my original comment about using exclusive here was actually a note to myself to revisit my comment after finishing the review, but i forgot. the problem with exclusive is that this open will fail if the file already exists on disk. is that going to be an issue, or is exclusive behavior desired? my hunch is that you may not want it, but the note to myself was just to ask if you wanted it.
There was a problem hiding this comment.
is that going to be an issue, or is exclusive behavior desired?
Exclusive is beneficial but not required here. We always want to create a not-yet-existing file here to ensure that we are not overwriting previous crash reports. The commit crash_tracker: prepare and release crash log file ensures that the file we open doesn't exist yet. Using exclusive here asserts that the file does not exist yet, which I believe is useful, at least as a sanity check.
| co_await ss::sync_directory( | ||
| _crash_report_file_name.parent_path().string()); |
There was a problem hiding this comment.
visibility is handled by the kernel. process restarts don't need the sync. it doesn't hurt anything, except performance if you were doing many syncs.
|
@pgellert the note about exclusive flag is probably the importnat one |
src/v/crash_tracker/recorder.cc
Outdated
| } | ||
|
|
||
| ss::future<> recorder::stop() { | ||
| std::lock_guard<ss::util::spinlock> g(_writer_lock); |
There was a problem hiding this comment.
commented here #24883 (review) not sure exactly the relationship between these PRs in terms of where reviews should happen.
There was a problem hiding this comment.
Thanks, yeah let's discuss it on this PR. #24883 stacks on this one and only the last 4 commits are new there. Github's not great with stacked PRs so I just usually just add a bolded note about it to the cover letter but it's still easy to miss.
There was a problem hiding this comment.
can you comment on what you mean by async-signal safe here and what concurrency you are trying to limit, exactly?
@michael-redpanda had a similar question I answered above: #24854 (comment)
async-signal safety: https://man7.org/linux/man-pages/man7/signal-safety.7.html
if the you're holding this lock and the current thread handles a signal that tries to acquire the same lock, then it's going to be a deadlock, no?
Not with try_lock. I am planning to use try_lock to acquire the lock in the signal handler to make sure it cannot deadlock. You can see the target final implementation in my POC PR's recorder.cc file here: https://github.com/redpanda-data/redpanda/pull/24493/files#diff-f90b64a3764bede06ac5ec9f14bd838d8d3147eefcc70cb6b8b7817b3a74ed95
maybe we can design this so that we don't need any locking? holding a spinlock while doing I/O and co_awaiting futures doesn't feel like a great idea.
I chose the spinlock because it is a primitive provided by seastar, so I prefer to use that instead of using raw std::atomic. But I can be convinced otherwise. An alternative I can think of is making prepared_writer thread-safe by using CAS operations on the _state held in prepared_writer.
There was a problem hiding this comment.
Let me know what you think. If given this context you think that a spinlock is reasonable I would add change the comment around it to the following:
/// The writer has shared state, so accessing it from multiple threads
/// is guarded by this lock. We use the async-signal-safe
/// `ss::util::spinlock` instead of more efficient locking mechanisms (e.g.,
/// Seastar primitives or `std::mutex`) because this lock needs to be safe
/// to acquire in a signal handler context. For reference, see the
/// signal-safety guidelines:
/// https://man7.org/linux/man-pages/man7/signal-safety.7.html.
///
/// While this lock ensures mutual exclusion for access to `_writer`, it is
/// also used to ensure the visibility of changes to `_writer`'s state
/// across threads. For example, if `start()` is called on thread T0,
/// `record_crash_sighandler()` on thread T3, and `stop()` again on T0, the
/// lock guarantees visibility and prevents data races in the state of
/// `_writer`.
///
/// Note: care must be taken to avoid deadlock. In signal handlers, only use
/// try_lock to try to ensure the signal handler is not blocked forever.
There was a problem hiding this comment.
if all you are trying to do is safely set a flag so that a shutdown signal handler doesn't conflict with other executions, you could use the spinlock around access to the flag only. holding the spinlock around co_await sounds like a recipe for problems?
also, is there any information on why we are writing all the signal handling ourselves? seastar has ss::engine::handle_signal too, but presumably that isn't good enough?
There was a problem hiding this comment.
if all you are trying to do is safely set a flag so that a shutdown signal handler doesn't conflict with other executions, you could use the spinlock around access to the flag only. holding the spinlock around co_await sounds like a recipe for problems?
I believe the spinlock is also protecting the buffers held by prepared_writer to ensure multiple threads don't attempt to write to the buffers at the same time.
also, is there any information on why we are writing all the signal handling ourselves? seastar has ss::engine::handle_signal too, but presumably that isn't good enough?
We can dig into this, but reading through the code I think it replaces the current action with whatever function you provide it. So if we used it to register say SIGSEGV, I believe it replaces Seastar's SEGV handler. Very much could be wrong but we'll look into it. Also I believe we want to ensure a certain ordering (either our handlers first or Seastar's handlers first, can't exactly remember).
There was a problem hiding this comment.
is there any information on why we are writing all the signal handling ourselves? seastar has ss::engine::handle_signal too, but presumably that isn't good enough?
The main reason is that Seastar's ss::engine::handle_signal is designed for efficiently handling user signals (e.g., SIGUSR1, SIGUSR2, SIGINT, SIGTERM, SIGHUP) but it is unsuitable for crash signals (like SIGABRT during an OOM scenario). Signal handlers configured through handle_signal are scheduled to run asynchronously on the reactor (the relevant code is here: https://github.com/scylladb/seastar/blob/1822136684ed0942e49e5299e86393534d465633/src/core/reactor.cc#L730C24-L749). However, for crash scenarios we need a synchronous signal handler to execute minimal, safe actions (e.g., writing out crash data) before termination, without relying on the reactor to pick up the signal later, as that would be unreliable.
Regarding signal handler ordering: Seastar's handler terminates the process as its last step, so redpanda's signal handler must execute first. I intend to wrap Seastar's handler to ensure it still runs after ours, although we could technically just replace seastar's signal handler wholesale with ours. (We can also discuss this further in the upcoming signal handler PR.)
There was a problem hiding this comment.
if all you are trying to do is safely set a flag so that a shutdown signal handler doesn't conflict with other executions, you could use the spinlock around access to the flag only. holding the spinlock around co_await sounds like a recipe for problems?
We won't actually block on this spinlock ever. I've reworked the code now to assert that we never block on the spinlock instead of just knowing that this is the case.
Mainly I'm using the lock to provide visibility guarantees. With the caveat that I do use it to prevent sighandlers from concurrently accessing the writer while start/stop/record_crash_exception/another call of record_crash_sighandler is running.
We could replace the spinlock with raw atomics. It would look something like this: e82f211. But I personally prefer the lock version because it is easier to work with (lock_guard > ss::defer, no need to select memory ordering).
There was a problem hiding this comment.
As discussed offline, I've reworked this now to use two std::atomic<bool>s for concurrency control instead of the spinlock.
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
cfae5ae to
d2779c7
Compare
|
force-push: address code review (remove directory sync, avoid blocking on spinlock, handle |
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
d2779c7 to
07386cb
Compare
|
force-push: reworked the concurrency control around |
Retry command for Build#61168please wait until all jobs are finished before running the slash command |
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
07386cb to
ed68cc6
Compare
|
force-push: address @michael-redpanda's review comments left on #24883 (#24883 (comment), #24883 (comment), #24883 (comment))
|
Introduces the core stateful writer which is used to write out `crash_description` serde objects to crash report files. It is able to write out the crash reports in an async-signal-safe way by: * using only async signal safe syscalls * pre-allocating all the memory necessary to construct, serialize and write our `crash_description` objects to disk * not allocating in fill() and write(), i.e. on the signal handler path Ref: https://man7.org/linux/man-pages/man7/signal-safety.7.html The `prepared_writer` is hooked up to the `recorder` in a later commit of this PR. Note that fill() may race with other calls of fill() or with release(), and the class safely breaks this race. These races can occur if multiple signals arrive on different threads at the same time, or if a signal arrives concurrently with release() being called on shard 0.
Implement the logic to choose a unique crash log file name, and hook up the code for preparing the crash recording code and the crash file cleanup code on clean shutdown.
Implement the recording of startup exceptions into crash files.
Add some simple ducktape tests to assert that crash reports are being generater (or not generated) as expected. The contents of the crash files are going to be validated as a follow up once the contents are actually printed to logs.
pgellert
force-pushed
the
crashlog/record-startup-exc
branch
from
ed68cc6 to
5d3e146
Compare
|
force-push: improve the code comments, otherwise it is a noop |
This PR adds functionality to record crashes caused by an exception during startup as crash reports to disk. This is the first step to implement the core crash recording project which aims to persist information about redpanda broker crashes to disk to help debugging.
The PR implements the core functionality of preparing state to allow writing crash reports in an async-signal-safe way, so that this code can be reused in signal handlers in follow-up PRs.
The crash reports are going to be stored under the data directory. The filenames are constructed as:
${datadir}/crash_reports/${broker_start_time_ms}_${random}.crash.Reports are serialized using
serdeandiobuf(with pre-reserved) memory, and the implementation relies on their allocation-free behaviour to ensure that writing crash files in signal handlers is reliable even in OOM scenarios. (This will become important in a follow-up PR when the signal handlers are actually hooked up.)To write to the crash reports, we need to use the low-level
open()function here instead of the seastar API or higher-level C++ primitives because we need to be able to manipulate the file using async-signal-safe, allocation-free functions inside signal handlers. Ref: https://man7.org/linux/man-pages/man7/signal-safety.7.htmlFixes https://redpandadata.atlassian.net/browse/CORE-8618
Backports Required
Release Notes