[
https://issues.apache.org/jira/browse/KUDU-3792?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Gabriella Lotz updated KUDU-3792:
---------------------------------
Description:
While running auto_leader_rebalancer-test under TSAN, the tablet server crashed
a few times with:
{code:java}
F hdr_histogram.cc:181] Check failed: value >= 0 (-8247342489905103 vs. 0)
@ kudu::HdrHistogram::IncrementBy()
@ kudu::Histogram::Increment()
@ kudu::tablet::AlterSchemaOp::Finish()::$_0::operator()(){code}
AlterSchemaOp::Finish() records the op's duration into a histogram. The
original code stored the elapsed time in a uint64_t:
{code:java}
uint64_t op_duration_usec =
(MonoTime::Now() - state_->start_time()).ToMicroseconds();
metrics->alter_schema_duration->Increment(op_duration_usec);{code}
(MonoTime::Now() - state_->start_time()) is a MonoDelta that can be negative (I
believe from a racy or not-yet-set start_time under heavy load).
ToMicroseconds() then returns a negative int64_t, which wraps to a huge value
when assigned to the uint64_t. HdrHistogram::Increment() takes an int64_t, so
it sees a large negative number and its CHECK(value >= 0) aborts the whole
tablet server.
Recording a duration metric shouldn't be able to crash the process. write_op.cc
has the same pattern and the same latent bug.
h3. Proposed fix
In alter_schema_op.cc and write_op.cc, compute the delta as a signed int64_t
and skip recording it when it's negative:
{code:java}
const int64_t op_duration_usec =
(MonoTime::Now() - state_->start_time()).ToMicroseconds();
if (PREDICT_TRUE(op_duration_usec >= 0)) {
metrics->alter_schema_duration->Increment(op_duration_usec);
}{code}
was:
While running auto_leader_rebalancer-test under TSAN, the tablet server crashed
a few times with:
{code:java}
F hdr_histogram.cc:181] Check failed: value >= 0 (-8247342489905103 vs. 0)
@ kudu::HdrHistogram::IncrementBy()
@ kudu::Histogram::Increment()
@ kudu::tablet::AlterSchemaOp::Finish()::$_0::operator()(){code}
AlterSchemaOp::Finish() records the op's duration into a histogram. The
original code stored the elapsed time in a uint64_t:
{code:java}
uint64_t op_duration_usec =
(MonoTime::Now() - state_->start_time()).ToMicroseconds();
metrics->alter_schema_duration->Increment(op_duration_usec);{code}
(MonoTime::Now() - state_->start_time()) is a MonoDelta that can be negative (I
believe from a racy or not-yet-set start_time under heavy load).
ToMicroseconds() then returns a negative int64_t, which wraps to a huge value
when assigned to the uint64_t. HdrHistogram::Increment() takes an int64_t, so
it sees a large negative number and its CHECK(value >= 0) aborts the whole
tablet server.
Recording a duration metric shouldn't be able to crash the process. write_op.cc
has the same pattern and the same latent bug.
h3. Proposed fix
In alter_schema_op.cc and write_op.cc, compute the delta as a signed int64_t
and skip recording it when it's negative:
{code:java}
const int64_t op_duration_usec =
(MonoTime::Now() - state_->start_time()).ToMicroseconds();
if (PREDICT_TRUE(op_duration_usec >= 0)) {
metrics->alter_schema_duration->Increment(op_duration_usec);
}{code}
> Fix tablet server crash from negative op_duration
> -------------------------------------------------
>
> Key: KUDU-3792
> URL: https://issues.apache.org/jira/browse/KUDU-3792
> Project: Kudu
> Issue Type: Bug
> Reporter: Gabriella Lotz
> Priority: Major
>
> While running auto_leader_rebalancer-test under TSAN, the tablet server
> crashed a few times with:
> {code:java}
> F hdr_histogram.cc:181] Check failed: value >= 0 (-8247342489905103 vs. 0)
> @ kudu::HdrHistogram::IncrementBy()
> @ kudu::Histogram::Increment()
> @ kudu::tablet::AlterSchemaOp::Finish()::$_0::operator()(){code}
> AlterSchemaOp::Finish() records the op's duration into a histogram. The
> original code stored the elapsed time in a uint64_t:
> {code:java}
> uint64_t op_duration_usec =
> (MonoTime::Now() - state_->start_time()).ToMicroseconds();
> metrics->alter_schema_duration->Increment(op_duration_usec);{code}
> (MonoTime::Now() - state_->start_time()) is a MonoDelta that can be negative
> (I believe from a racy or not-yet-set start_time under heavy load).
> ToMicroseconds() then returns a negative int64_t, which wraps to a huge value
> when assigned to the uint64_t. HdrHistogram::Increment() takes an int64_t, so
> it sees a large negative number and its CHECK(value >= 0) aborts the whole
> tablet server.
> Recording a duration metric shouldn't be able to crash the process.
> write_op.cc has the same pattern and the same latent bug.
> h3. Proposed fix
> In alter_schema_op.cc and write_op.cc, compute the delta as a signed int64_t
> and skip recording it when it's negative:
> {code:java}
> const int64_t op_duration_usec =
> (MonoTime::Now() - state_->start_time()).ToMicroseconds();
> if (PREDICT_TRUE(op_duration_usec >= 0)) {
> metrics->alter_schema_duration->Increment(op_duration_usec);
> }{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
