[
https://issues.apache.org/jira/browse/CASSANDRA-13677?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Corentin Chary updated CASSANDRA-13677:
---------------------------------------
Description:
This would now give something like:
{code}
WARN [ReadStage-15] 2017-06-08 12:47:57,799
AbstractLocalAwareExecutorService.java:167 - Uncaught exception on thread
Thread[ReadStage-15,5,main]: {}
java.lang.RuntimeException:
org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException: Command
'Read(biggraphite_metadata.directories columns=* rowfilter=component_0 = criteo
limits=LIMIT 5000 range=(min(-9223372036854775808), min(-9223372036854775808)]
pfilter=names(EMPTY))' took too long (100 > 100ms).
at
org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2591)
~[main/:na]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
~[na:1.8.0_131]
at
org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:162)
~[main/:na]
at
org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$LocalSessionFutureTask.run(AbstractLocalAwareExecutorService.java:134)
[main/:na]
at
org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:109) [main/:na]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
Caused by:
org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException: Command
'Read(biggraphite_metadata.directories columns=* rowfilter=component_0 = criteo
limits=LIMIT 5000 range=(min(-9223372036854775808), min(-9223372036854775808)]
pfilter=names(EMPTY))' took too long (100 > 100ms).
at
org.apache.cassandra.index.sasi.plan.QueryController.checkpoint(QueryController.java:163)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryController.getPartition(QueryController.java:117)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:116)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:71)
~[main/:na]
at
org.apache.cassandra.utils.AbstractIterator.hasNext(AbstractIterator.java:47)
~[main/:na]
at
org.apache.cassandra.db.transform.BasePartitions.hasNext(BasePartitions.java:92)
~[main/:na]
at
org.apache.cassandra.db.partitions.UnfilteredPartitionIterators$Serializer.serialize(UnfilteredPartitionIterators.java:310)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.build(ReadResponse.java:145)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:138)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:134)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse.createDataResponse(ReadResponse.java:76)
~[main/:na]
at
org.apache.cassandra.db.ReadCommand.createResponse(ReadCommand.java:333)
~[main/:na]
at
org.apache.cassandra.service.StorageProxy$LocalReadRunnable.runMayThrow(StorageProxy.java:1884)
~[main/:na]
at
org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2587)
~[main/:na]
... 5 common frames omitted
{code}
Not having the query makes it super hard to debug. Even worse, because it stops
potentially before the slow_query threshold, it won't appear as one.
was:
This would now give something like:
{code}
WARN [ReadStage-15] 2017-06-08 12:47:57,799
AbstractLocalAwareExecutorService.java:167 - Uncaught exception on thread
Thread[ReadStage-15,5,main]: {}
java.lang.RuntimeException:
org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException: Command
'Read(biggraphite_metadata.directories columns=* rowfilter=component_0 = criteo
limits=LIMIT 5000 range=(min(-9223372036854775808), min(-9223372036854775808)]
pfilter=names(EMPTY))' took too long (100 > 100ms).
at
org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2591)
~[main/:na]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
~[na:1.8.0_131]
at
org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:162)
~[main/:na]
at
org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$LocalSessionFutureTask.run(AbstractLocalAwareExecutorService.java:134)
[main/:na]
at
org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:109) [main/:na]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
Caused by:
org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException: Command
'Read(biggraphite_metadata.directories columns=* rowfilter=component_0 = criteo
limits=LIMIT 5000 range=(min(-9223372036854775808), min(-9223372036854775808)]
pfilter=names(EMPTY))' took too long (100 > 100ms).
at
org.apache.cassandra.index.sasi.plan.QueryController.checkpoint(QueryController.java:163)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryController.getPartition(QueryController.java:117)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:116)
~[main/:na]
at
org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:71)
~[main/:na]
at
org.apache.cassandra.utils.AbstractIterator.hasNext(AbstractIterator.java:47)
~[main/:na]
at
org.apache.cassandra.db.transform.BasePartitions.hasNext(BasePartitions.java:92)
~[main/:na]
at
org.apache.cassandra.db.partitions.UnfilteredPartitionIterators$Serializer.serialize(UnfilteredPartitionIterators.java:310)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.build(ReadResponse.java:145)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:138)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:134)
~[main/:na]
at
org.apache.cassandra.db.ReadResponse.createDataResponse(ReadResponse.java:76)
~[main/:na]
at
org.apache.cassandra.db.ReadCommand.createResponse(ReadCommand.java:333)
~[main/:na]
at
org.apache.cassandra.service.StorageProxy$LocalReadRunnable.runMayThrow(StorageProxy.java:1884)
~[main/:na]
at
org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2587)
~[main/:na]
... 5 common frames omitted
{code}
Not having the query makes it super hard to debug
> Make SASI timeouts easier to debug
> ----------------------------------
>
> Key: CASSANDRA-13677
> URL: https://issues.apache.org/jira/browse/CASSANDRA-13677
> Project: Cassandra
> Issue Type: Improvement
> Components: sasi
> Reporter: Corentin Chary
> Assignee: Corentin Chary
> Priority: Minor
> Fix For: 4.x
>
> Attachments: 0001-SASI-Make-timeouts-easier-to-debug.patch
>
>
> This would now give something like:
> {code}
> WARN [ReadStage-15] 2017-06-08 12:47:57,799
> AbstractLocalAwareExecutorService.java:167 - Uncaught exception on thread
> Thread[ReadStage-15,5,main]: {}
> java.lang.RuntimeException:
> org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException:
> Command 'Read(biggraphite_metadata.directories columns=*
> rowfilter=component_0 = criteo limits=LIMIT 5000
> range=(min(-9223372036854775808), min(-9223372036854775808)]
> pfilter=names(EMPTY))' took too long (100 > 100ms).
> at
> org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2591)
> ~[main/:na]
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> ~[na:1.8.0_131]
> at
> org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:162)
> ~[main/:na]
> at
> org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$LocalSessionFutureTask.run(AbstractLocalAwareExecutorService.java:134)
> [main/:na]
> at
> org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:109) [main/:na]
> at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
> Caused by:
> org.apache.cassandra.index.sasi.exceptions.TimeQuotaExceededException:
> Command 'Read(biggraphite_metadata.directories columns=*
> rowfilter=component_0 = criteo limits=LIMIT 5000
> range=(min(-9223372036854775808), min(-9223372036854775808)]
> pfilter=names(EMPTY))' took too long (100 > 100ms).
> at
> org.apache.cassandra.index.sasi.plan.QueryController.checkpoint(QueryController.java:163)
> ~[main/:na]
> at
> org.apache.cassandra.index.sasi.plan.QueryController.getPartition(QueryController.java:117)
> ~[main/:na]
> at
> org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:116)
> ~[main/:na]
> at
> org.apache.cassandra.index.sasi.plan.QueryPlan$ResultIterator.computeNext(QueryPlan.java:71)
> ~[main/:na]
> at
> org.apache.cassandra.utils.AbstractIterator.hasNext(AbstractIterator.java:47)
> ~[main/:na]
> at
> org.apache.cassandra.db.transform.BasePartitions.hasNext(BasePartitions.java:92)
> ~[main/:na]
> at
> org.apache.cassandra.db.partitions.UnfilteredPartitionIterators$Serializer.serialize(UnfilteredPartitionIterators.java:310)
> ~[main/:na]
> at
> org.apache.cassandra.db.ReadResponse$LocalDataResponse.build(ReadResponse.java:145)
> ~[main/:na]
> at
> org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:138)
> ~[main/:na]
> at
> org.apache.cassandra.db.ReadResponse$LocalDataResponse.<init>(ReadResponse.java:134)
> ~[main/:na]
> at
> org.apache.cassandra.db.ReadResponse.createDataResponse(ReadResponse.java:76)
> ~[main/:na]
> at
> org.apache.cassandra.db.ReadCommand.createResponse(ReadCommand.java:333)
> ~[main/:na]
> at
> org.apache.cassandra.service.StorageProxy$LocalReadRunnable.runMayThrow(StorageProxy.java:1884)
> ~[main/:na]
> at
> org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2587)
> ~[main/:na]
> ... 5 common frames omitted
> {code}
> Not having the query makes it super hard to debug. Even worse, because it
> stops potentially before the slow_query threshold, it won't appear as one.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@cassandra.apache.org
For additional commands, e-mail: commits-h...@cassandra.apache.org
