[ 
https://issues.apache.org/jira/browse/CASSANDRA-5520?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Brandon Williams resolved CASSANDRA-5520.
-----------------------------------------

    Resolution: Invalid

bq. However, the event-level breakdown shows no such large duration

It doesn't need to, the entire request time just needs to exceed the rpc 
timeout.
                
> Query tracing session info inconsistent with events info
> --------------------------------------------------------
>
>                 Key: CASSANDRA-5520
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-5520
>             Project: Cassandra
>          Issue Type: Bug
>    Affects Versions: 1.2.4
>         Environment: Linux
>            Reporter: Ilya Kirnos
>
> Session info for a trace is showing that a query took > 10 seconds (it timed 
> out).
> cqlsh:system_traces> select session_id, duration, request from sessions where 
> session_id = c7e36a30-af3a-11e2-9ec9-772ec39805fe;
>  session_id                           | duration | request
> --------------------------------------+----------+----------------
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | 10000230 | multiget_slice
> However, the event-level breakdown shows no such large duration:
> cqlsh:system_traces> select * from events where session_id = 
> c7e36a30-af3a-11e2-9ec9-772ec39805fe;
>  session_id                           | event_id                             
> | activity                                     | source         | 
> source_elapsed | thread
> --------------------------------------+--------------------------------------+----------------------------------------------+----------------+----------------+------------------------
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e36a30-af3a-11e2-9480-e9d811e0fc18 
> |         Message received from /50.112.90.147 |    50.112.4.16 |             
> 19 |              Thread-57
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e36a31-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.252.153.16 |  50.112.90.147 |            
> 246 |     WRITE-/50.112.4.16
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-9480-e9d811e0fc18 
> |         Message received from /50.112.90.147 |    50.112.4.16 |            
> 259 |              Thread-57
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.248.106.37 |  50.112.90.147 |            
> 253 |    WRITE-/50.112.79.52
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-b8dc-a7032a583115 
> |         Message received from /50.112.90.147 | 50.112.213.136 |             
> 25 |              Thread-94
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-9480-e9d811e0fc18 
> | Executing single-partition query on CardHash |    50.112.4.16 |            
> 421 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-9ec9-772ec39805fe 
> |           Sending message to /10.252.151.214 |  50.112.90.147 |            
> 310 |  WRITE-/50.112.213.136
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-b8dc-a7032a583115 
> |         Message received from /50.112.90.147 | 50.112.213.136 |            
> 106 |              Thread-94
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-9480-e9d811e0fc18 
> |                 Acquiring sstable references |    50.112.4.16 |            
> 444 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.248.106.37 |  50.112.90.147 |            
> 352 |    WRITE-/50.112.79.52
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-b8dc-a7032a583115 
> | Executing single-partition query on CardHash | 50.112.213.136 |            
> 144 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-9480-e9d811e0fc18 
> |                    Merging memtable contents |    50.112.4.16 |            
> 472 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.248.95.237 |  50.112.90.147 |            
> 362 |  WRITE-/50.112.201.218
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-b8dc-a7032a583115 
> |                 Acquiring sstable references | 50.112.213.136 |            
> 164 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-9480-e9d811e0fc18 
> |   Merging data from memtables and 0 sstables |    50.112.4.16 |            
> 510 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-9ec9-772ec39805fe 
> |           Sending message to /10.252.151.214 |  50.112.90.147 |            
> 376 |  WRITE-/50.112.213.136
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-b8dc-a7032a583115 
> |                    Merging memtable contents | 50.112.213.136 |            
> 195 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-9480-e9d811e0fc18 
> |           Read 0 live cells and 0 tombstoned |    50.112.4.16 |            
> 530 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.248.95.237 |  50.112.90.147 |            
> 401 |  WRITE-/50.112.201.218
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-b8dc-a7032a583115 
> | Executing single-partition query on CardHash | 50.112.213.136 |            
> 202 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-9480-e9d811e0fc18 
> |         Enqueuing response to /50.112.90.147 |    50.112.4.16 |            
> 572 |         ReadStage:5329
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-9ec9-772ec39805fe 
> |            Sending message to /10.252.153.16 |  50.112.90.147 |            
> 489 |     WRITE-/50.112.4.16
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-b8dc-a7032a583115 
> |                 Acquiring sstable references | 50.112.213.136 |            
> 215 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39147-af3a-11e2-9480-e9d811e0fc18 
> | Executing single-partition query on CardHash |    50.112.4.16 |            
> 610 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39147-af3a-11e2-b8dc-a7032a583115 
> |   Merging data from memtables and 0 sstables | 50.112.213.136 |            
> 239 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39148-af3a-11e2-9480-e9d811e0fc18 
> |                 Acquiring sstable references |    50.112.4.16 |            
> 625 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39148-af3a-11e2-b8dc-a7032a583115 
> |                    Merging memtable contents | 50.112.213.136 |            
> 242 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39149-af3a-11e2-9480-e9d811e0fc18 
> |            Sending message to /10.252.152.81 |    50.112.4.16 |            
> 627 |   WRITE-/50.112.90.147
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39149-af3a-11e2-b8dc-a7032a583115 
> |           Read 0 live cells and 0 tombstoned | 50.112.213.136 |            
> 258 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914a-af3a-11e2-9480-e9d811e0fc18 
> |                    Merging memtable contents |    50.112.4.16 |            
> 646 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914a-af3a-11e2-b8dc-a7032a583115 
> |   Merging data from memtables and 0 sstables | 50.112.213.136 |            
> 287 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914b-af3a-11e2-9480-e9d811e0fc18 
> |   Merging data from memtables and 0 sstables |    50.112.4.16 |            
> 679 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914b-af3a-11e2-b8dc-a7032a583115 
> |         Enqueuing response to /50.112.90.147 | 50.112.213.136 |            
> 301 |           ReadStage:11
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914c-af3a-11e2-9480-e9d811e0fc18 
> |           Read 0 live cells and 0 tombstoned |    50.112.4.16 |            
> 704 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914c-af3a-11e2-b8dc-a7032a583115 
> |           Read 0 live cells and 0 tombstoned | 50.112.213.136 |            
> 311 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914d-af3a-11e2-9480-e9d811e0fc18 
> |         Enqueuing response to /50.112.90.147 |    50.112.4.16 |            
> 763 |         ReadStage:5330
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914d-af3a-11e2-b8dc-a7032a583115 
> |         Enqueuing response to /50.112.90.147 | 50.112.213.136 |            
> 354 |           ReadStage:41
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914e-af3a-11e2-b8dc-a7032a583115 
> |            Sending message to /10.252.152.81 | 50.112.213.136 |            
> 374 |   WRITE-/50.112.90.147
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b850-af3a-11e2-9ec9-772ec39805fe 
> |        Message received from /50.112.213.136 |  50.112.90.147 |           
> 1289 |              Thread-80
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b850-af3a-11e2-9f00-0b1bd79b59b0 
> |         Message received from /50.112.90.147 |   50.112.79.52 |             
> 28 |              Thread-71
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b851-af3a-11e2-9ec9-772ec39805fe 
> |     Processing response from /50.112.213.136 |  50.112.90.147 |           
> 1370 | RequestResponseStage:8
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b852-af3a-11e2-9ec9-772ec39805fe 
> |           Message received from /50.112.4.16 |  50.112.90.147 |           
> 1533 |            Thread-1435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b853-af3a-11e2-9ec9-772ec39805fe 
> |        Processing response from /50.112.4.16 |  50.112.90.147 |           
> 1598 | RequestResponseStage:7
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df60-af3a-11e2-9ec9-772ec39805fe 
> |          Message received from /50.112.79.52 |  50.112.90.147 |           
> 2527 |             Thread-143
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df60-af3a-11e2-9f00-0b1bd79b59b0 
> |         Message received from /50.112.90.147 |   50.112.79.52 |            
> 280 |              Thread-71
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df61-af3a-11e2-9ec9-772ec39805fe 
> |       Processing response from /50.112.79.52 |  50.112.90.147 |           
> 2604 | RequestResponseStage:6
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df61-af3a-11e2-9f00-0b1bd79b59b0 
> | Executing single-partition query on CardHash |   50.112.79.52 |            
> 424 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df62-af3a-11e2-9f00-0b1bd79b59b0 
> |                 Acquiring sstable references |   50.112.79.52 |            
> 445 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df63-af3a-11e2-9f00-0b1bd79b59b0 
> |                    Merging memtable contents |   50.112.79.52 |            
> 474 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df64-af3a-11e2-9f00-0b1bd79b59b0 
> |   Merging data from memtables and 0 sstables |   50.112.79.52 |            
> 525 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df65-af3a-11e2-9f00-0b1bd79b59b0 
> |           Read 0 live cells and 0 tombstoned |   50.112.79.52 |            
> 545 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df66-af3a-11e2-9f00-0b1bd79b59b0 
> |         Enqueuing response to /50.112.90.147 |   50.112.79.52 |            
> 603 |         ReadStage:6435
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df67-af3a-11e2-9f00-0b1bd79b59b0 
> | Executing single-partition query on CardHash |   50.112.79.52 |            
> 617 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df68-af3a-11e2-9f00-0b1bd79b59b0 
> |                 Acquiring sstable references |   50.112.79.52 |            
> 632 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df69-af3a-11e2-9f00-0b1bd79b59b0 
> |                    Merging memtable contents |   50.112.79.52 |            
> 656 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6a-af3a-11e2-9f00-0b1bd79b59b0 
> |            Sending message to /10.252.152.81 |   50.112.79.52 |            
> 657 |   WRITE-/50.112.90.147
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6b-af3a-11e2-9f00-0b1bd79b59b0 
> |   Merging data from memtables and 0 sstables |   50.112.79.52 |            
> 697 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6c-af3a-11e2-9f00-0b1bd79b59b0 
> |           Read 0 live cells and 0 tombstoned |   50.112.79.52 |            
> 718 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6d-af3a-11e2-9f00-0b1bd79b59b0 
> |         Enqueuing response to /50.112.90.147 |   50.112.79.52 |            
> 766 |         ReadStage:6436
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40670-af3a-11e2-b266-75b700b21012 
> |         Message received from /50.112.90.147 | 50.112.201.218 |             
> 23 |              Thread-47
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40671-af3a-11e2-b266-75b700b21012 
> |         Message received from /50.112.90.147 | 50.112.201.218 |             
> 81 |              Thread-47
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40672-af3a-11e2-b266-75b700b21012 
> | Executing single-partition query on CardHash | 50.112.201.218 |            
> 150 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40673-af3a-11e2-b266-75b700b21012 
> | Executing single-partition query on CardHash | 50.112.201.218 |            
> 158 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40674-af3a-11e2-b266-75b700b21012 
> |                 Acquiring sstable references | 50.112.201.218 |            
> 175 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40675-af3a-11e2-b266-75b700b21012 
> |                 Acquiring sstable references | 50.112.201.218 |            
> 176 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40676-af3a-11e2-b266-75b700b21012 
> |                    Merging memtable contents | 50.112.201.218 |            
> 201 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40677-af3a-11e2-b266-75b700b21012 
> |                    Merging memtable contents | 50.112.201.218 |            
> 201 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40678-af3a-11e2-b266-75b700b21012 
> |   Merging data from memtables and 0 sstables | 50.112.201.218 |            
> 240 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40679-af3a-11e2-b266-75b700b21012 
> |   Merging data from memtables and 0 sstables | 50.112.201.218 |            
> 243 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067a-af3a-11e2-b266-75b700b21012 
> |           Read 0 live cells and 0 tombstoned | 50.112.201.218 |            
> 264 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067b-af3a-11e2-b266-75b700b21012 
> |           Read 0 live cells and 0 tombstoned | 50.112.201.218 |            
> 264 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067c-af3a-11e2-b266-75b700b21012 
> |         Enqueuing response to /50.112.90.147 | 50.112.201.218 |            
> 310 |           ReadStage:60
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067d-af3a-11e2-b266-75b700b21012 
> |         Enqueuing response to /50.112.90.147 | 50.112.201.218 |            
> 310 |           ReadStage:58
>  c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067e-af3a-11e2-b266-75b700b21012 
> |            Sending message to /10.252.152.81 | 50.112.201.218 |            
> 369 |   WRITE-/50.112.90.147

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Reply via email to