Skip to content

CNDB-18512: Add metrics about fetched/returned cells to the slow query logger - #2564

Open
adelapena wants to merge 1 commit into
mainfrom
CNDB-18512-main
Open

CNDB-18512: Add metrics about fetched/returned cells to the slow query logger#2564
adelapena wants to merge 1 commit into
mainfrom
CNDB-18512-main

Conversation

@adelapena

@adelapena adelapena commented Aug 13, 2026

Copy link
Copy Markdown

What is the issue

The slow query logger shows counts the number of fetched/returned partitions/rows/tombstones. However, it doesn't say the number of fetched/returned cells, nor cell tombstones. This is problematic for incidents where we see slow queries and all query metrics look normal despite of having massive rows.

What does this PR fix and why was it fixed

It adds the number of fetched and returned cells to the log reports produced for slow queries. This is done for both SAI and regular queries.

Differently to the counts of partitions and rows, there are no separate counts of live and deleted cells. This is because having separate counts of live/deleted cells would require to iterate the b-tree of cells checking timestamps or every returned row of every query. Benchmarking has proven that that has a significative impact on performance, so we should probably limit this to just counting cells regardless of liveness info.

This is how the log reports for regular queries would look like:

<SELECT * FROM distributed_test_keyspace.t_0 WHERE k = ? AND c = ? ALLOW FILTERING>, time 204 msec - slow timeout 100 msec/cross-node
  Fetched/returned/tombstones:
    partitions: 1/1/0
    rows: 1/1/0
    cells: 3/3/-

The SAI log reports would look like:

<SELECT * FROM distributed_test_keyspace.t_0 WHERE n > ? ALLOW FILTERING>, was slow 3 times: avg/min/max 202/201/204 msec - slow timeout 100 msec
  SAI slowest query metrics:
    sstablesHit: 3
    segmentsHit: 3
    keysFetched: 5
    partitionsFetched: 3
    partitionsReturned: 3
    partitionTombstonesFetched: 0
    rowsFetched: 5
    rowsReturned: 5
    rowTombstonesFetched: 0
    cellsFetched: 11
    cellsReturned: 11
    ...

Here are some runs of the included JMH benchmarks, showing that the current approach doesn't seem to have a noticeable impact of performance:

ReadCommandExecutionInfoBench with this patch:

     [java] Benchmark                                       (collectionSize)  (enabled)  Mode  Cnt        Score       Error  Units
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1       true  avgt   10   378971.832 ±  1550.965  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1      false  avgt   10   387224.594 ±  2625.383  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100       true  avgt   10  8632622.367 ± 41134.977  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100      false  avgt   10  8513550.972 ± 34949.929  ns/op

     [java] Benchmark                                       (collectionSize)  (enabled)  Mode  Cnt        Score       Error  Units
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1       true  avgt   10   399866.043 ±  3757.132  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1      false  avgt   10   371497.284 ±  3403.850  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100       true  avgt   10  8754278.108 ± 27658.522  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100      false  avgt   10  8947810.908 ± 31871.260  ns/op

ReadCommandExecutionInfoBench on main branch:

     [java] Benchmark                                       (collectionSize)  (enabled)  Mode  Cnt        Score       Error  Units
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1       true  avgt   10   366901.666 ±  5755.936  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1      false  avgt   10   393852.609 ±  2937.295  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100       true  avgt   10  8664451.503 ± 72259.871  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100      false  avgt   10  8650261.390 ± 31970.636  ns/op

     [java] Benchmark                                       (collectionSize)  (enabled)  Mode  Cnt        Score       Error  Units
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1       true  avgt   10   398991.785 ±  3557.741  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation                 1      false  avgt   10   405107.572 ±  3733.606  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100       true  avgt   10  8896887.390 ± 41780.075  ns/op
     [java] ReadCommandExecutionInfoBench.runFastOperation               100      false  avgt   10  8721552.856 ± 31947.872  ns/op

QueryMonitorableExecutionInfoBench with this patch:

     [java] Benchmark                                            (collectionSize)  (enabled)  Mode  Cnt       Score      Error  Units
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1      false  avgt   10  239929.967 ± 1235.564  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1       true  avgt   10  263140.131 ± 1693.898  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100      false  avgt   10  419729.244 ± 1652.791  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100       true  avgt   10  426651.719 ± 1665.732  ns/op

     [java] Benchmark                                            (collectionSize)  (enabled)  Mode  Cnt       Score      Error  Units
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1       true  avgt   10  251559.435 ± 2249.120  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1      false  avgt   10  238255.888 ± 1148.742  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100       true  avgt   10  433454.617 ± 1427.334  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100      false  avgt   10  416087.187 ± 2593.538  ns/op

QueryMonitorableExecutionInfoBench on main branch:

     [java] Benchmark                                            (collectionSize)  (enabled)  Mode  Cnt       Score      Error  Units
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1       true  avgt   10  249044.062 ± 1052.077  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1      false  avgt   10  238268.592 ± 3380.588  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100       true  avgt   10  434175.615 ± 2261.294  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100      false  avgt   10  415184.194 ± 3747.166  ns/op

     [java] Benchmark                                            (collectionSize)  (enabled)  Mode  Cnt       Score      Error  Units
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1       true  avgt   10  244556.510 ± 1015.289  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation                 1      false  avgt   10  239677.399 ± 1839.077  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100       true  avgt   10  438373.482 ± 1428.749  ns/op
     [java] QueryMonitorableExecutionInfoBench.runFastOperation               100      false  avgt   10  421489.016 ± 1266.341  ns/op

@adelapena adelapena self-assigned this Aug 13, 2026
@github-actions

github-actions Bot commented Aug 13, 2026

Copy link
Copy Markdown

Checklist before you submit for review

  • This PR adheres to the Definition of Done
  • Make sure there is a PR and ticket in the CNDB project updating the Converged Cassandra version
  • Use NoSpamLogger for log lines that may appear frequently in the logs
  • Verify test results on Butler
  • Test coverage for new/modified code is > 80%, check manually at SonarCloud page
  • Proper code formatting
  • Proper title for each commit staring with the project-issue number, like CNDB-1234
  • Each commit has a meaningful description
  • Each commit is not very long and contains related changes
  • Renames, moves and reformatting are in distinct commits
  • All new files should contain the IBM copyright header instead of the Apache License one (no DataStax copyright any longer)

@adelapena
adelapena requested a review from a team August 13, 2026 10:23
@sonarqube-dx-prod

Copy link
Copy Markdown

@plpesvc-ds

Copy link
Copy Markdown

❌ Build ds-cassandra-pr-gate/PR-2564 rejected by Butler


3 regressions found
See build details here


Found 3 new test failures

Test Explanation Runs Upstream
o.a.c.index.sai.cql.VectorCompaction100dTest.testOneToManyCompaction[version=ed enableNVQ=false] REGRESSION 🔴 0 / 30
o.a.c.index.sai.cql.VectorSiftSmallTest.testCompaction[version=fa enableNVQ=true enableFused=true] REGRESSION 🔴 0 / 30
o.a.c.index.sai.cql.VectorTypeTest.lwtTest[version=db enableNVQ=false enableFused=false] REGRESSION 🔴 0 / 30

Found 4 known test failures

@pkolaczk pkolaczk left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks awesome!
One minor thing: can you add some tests of user defined types?
Would a user defined type with 3 fields count as one cell or as 3 cells?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants