You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Stefan Miklosovic (Jira)" <ji...@apache.org> on 2024/10/09 00:14:00 UTC

[jira] [Commented] (CASSANDRA-19332) Dropwizard Meter causes timeouts when infrequently used

    [ https://issues.apache.org/jira/browse/CASSANDRA-19332?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17887727#comment-17887727 ] 

Stefan Miklosovic commented on CASSANDRA-19332:
-----------------------------------------------

[~aweisberg] [~mmuzaf] patch for Dropwizard got merged here (1) and released in 4.2.28 (already released). 

So, now the path we should go with is to bump Dropwizard to 4.2.28 and we are done?

(1) [https://github.com/dropwizard/metrics/pull/4480]

> Dropwizard Meter causes timeouts when infrequently used
> -------------------------------------------------------
>
>                 Key: CASSANDRA-19332
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-19332
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Observability/Metrics
>            Reporter: Ariel Weisberg
>            Assignee: Ariel Weisberg
>            Priority: Normal
>             Fix For: 4.0.x, 4.1.x, 5.0.x, 5.x
>
>         Attachments: ci_summary_4.1.html, ci_summary_5.0.html, ci_summary_trunk.html, result_details_4.1.tar.gz, result_details_5.0.tar.gz, result_details_trunk.tar.gz
>
>
> Observed instances of timeouts on clusters with long uptime and infrequently used tables and possibly just request paths such as not using CAS for large fractions of a year.
> CAS seems to be more severely impacted because it has more metrics in the request path such as latency measurements for prepare, propose, and the read from the underlying table.
> Tracing showed ~600-800 milliseconds for these operations in between the “appending to memtable” and “sending a response” events. Reads had a delay between finishing the construction of the iterator and sending the read response.
> Stack traces dumped every 100 milliseconds using {{sjk}} shows that in prepare and propose a lot of time was being spent in {{{}Meter.tickIfNecessary{}}}.
> {code:java}
> Thread [2537] RUNNABLE at 2024-01-25T21:14:48.218 - MutationStage-2
> com.codahale.metrics.Meter.tickIfNecessary(Meter.java:71)
> com.codahale.metrics.Meter.mark(Meter.java:55)
> com.codahale.metrics.Meter.mark(Meter.java:46)
> com.codahale.metrics.Timer.update(Timer.java:150)
> com.codahale.metrics.Timer.update(Timer.java:86)
> org.apache.cassandra.metrics.LatencyMetrics.addNano(LatencyMetrics.java:159)
> org.apache.cassandra.service.paxos.PaxosState.prepare(PaxosState.java:92)
> Thread [2539] RUNNABLE at 2024-01-25T21:14:48.520 - MutationStage-4
> com.codahale.metrics.Meter.tickIfNecessary(Meter.java:72)
> com.codahale.metrics.Meter.mark(Meter.java:55)
> com.codahale.metrics.Meter.mark(Meter.java:46)
> com.codahale.metrics.Timer.update(Timer.java:150)
> com.codahale.metrics.Timer.update(Timer.java:86)
> org.apache.cassandra.metrics.LatencyMetrics.addNano(LatencyMetrics.java:159)
> org.apache.cassandra.service.paxos.PaxosState.propose(PaxosState.java:127){code}
> {{tickIfNecessary}} does a linear amount of work proportional to the time since the last time the metric was updated/read/created and this can actually take a measurable amount of time even in a tight loop. On my M2 MBP it was 1.5 milliseconds for a day, ~200 days took ~74 milliseconds. Before it warmed up it was 140 milliseconds.
> A quick fix is to schedule a task to read all the meters once a day so it isn’t done in the request path and we have a more incremental amount to process at a time.
> Also observed that {{tickIfNecessary}} is not 100% thread safe in that if it takes longer than 5 seconds to run the loop it can end up with multiple threads attempting to run the loop at once and then they will concurrently run {{EWMA.tick}} which probably results in some ticks not being performed.
> This issue is still present in the latest version of {{Metrics}} if using {{{}EWMA{}}}, but {{SlidingWindowTimeAverages}} looks like it has a bounded amount of work required to tick.  Switching would change how our metrics work since the two don't have the same behavior.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org