cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Brandon Williams (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (CASSANDRA-5520) Query tracing session info inconsistent with events info
Date Tue, 30 Apr 2013 23:10:15 GMT

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

Brandon Williams edited comment on CASSANDRA-5520 at 4/30/13 11:08 PM:
-----------------------------------------------------------------------

The events may not always add up to the total. There are at least two ways sessions and events
can be inconsistent with each other: first, there are events happening after the session has
ended, and second, there are too few events to explain why the session ended so late.  You
seem to have the latter case.

                
      was (Author: brandon.williams):
    The events may not always add up to the total. There are at least two ways sessions and
events can be inconsistent with each other: first, there are events happening after the session
has ended, and second, there are too few events to explain why the session ended so late.
 You see to have the latter case.

                  
> 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 /xxx.xxx.90.147 | xxx.xxx.4.16 | 19 | Thread-57
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e36a31-af3a-11e2-9ec9-772ec39805fe | Sending
message to /xxx.xxx.153.16 | xxx.xxx.90.147 | 246 | WRITE-/xxx.xxx.4.16
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-9480-e9d811e0fc18 | Message
received from /xxx.xxx.90.147 | xxx.xxx.4.16 | 259 | Thread-57
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-9ec9-772ec39805fe | Sending
message to /10.248.106.37 | xxx.xxx.90.147 | 253 | WRITE-/xxx.xxx.79.52
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39140-af3a-11e2-b8dc-a7032a583115 | Message
received from /xxx.xxx.90.147 | xxx.xxx.213.136 | 25 | Thread-94
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-9480-e9d811e0fc18 | Executing
single-partition query on CardHash | xxx.xxx.4.16 | 421 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-9ec9-772ec39805fe | Sending
message to /xxx.xxx.151.214 | xxx.xxx.90.147 | 310 | WRITE-/xxx.xxx.213.136
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39141-af3a-11e2-b8dc-a7032a583115 | Message
received from /xxx.xxx.90.147 | xxx.xxx.213.136 | 106 | Thread-94
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-9480-e9d811e0fc18 | Acquiring
sstable references | xxx.xxx.4.16 | 444 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-9ec9-772ec39805fe | Sending
message to /10.248.106.37 | xxx.xxx.90.147 | 352 | WRITE-/xxx.xxx.79.52
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39142-af3a-11e2-b8dc-a7032a583115 | Executing
single-partition query on CardHash | xxx.xxx.213.136 | 144 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-9480-e9d811e0fc18 | Merging
memtable contents | xxx.xxx.4.16 | 472 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-9ec9-772ec39805fe | Sending
message to /10.248.95.237 | xxx.xxx.90.147 | 362 | WRITE-/xxx.xxx.201.218
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39143-af3a-11e2-b8dc-a7032a583115 | Acquiring
sstable references | xxx.xxx.213.136 | 164 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-9480-e9d811e0fc18 | Merging
data from memtables and 0 sstables | xxx.xxx.4.16 | 510 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-9ec9-772ec39805fe | Sending
message to /xxx.xxx.151.214 | xxx.xxx.90.147 | 376 | WRITE-/xxx.xxx.213.136
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39144-af3a-11e2-b8dc-a7032a583115 | Merging
memtable contents | xxx.xxx.213.136 | 195 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-9480-e9d811e0fc18 | Read 0
live cells and 0 tombstoned | xxx.xxx.4.16 | 530 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-9ec9-772ec39805fe | Sending
message to /10.248.95.237 | xxx.xxx.90.147 | 401 | WRITE-/xxx.xxx.201.218
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39145-af3a-11e2-b8dc-a7032a583115 | Executing
single-partition query on CardHash | xxx.xxx.213.136 | 202 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-9480-e9d811e0fc18 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.4.16 | 572 | ReadStage:5329
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-9ec9-772ec39805fe | Sending
message to /xxx.xxx.153.16 | xxx.xxx.90.147 | 489 | WRITE-/xxx.xxx.4.16
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39146-af3a-11e2-b8dc-a7032a583115 | Acquiring
sstable references | xxx.xxx.213.136 | 215 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39147-af3a-11e2-9480-e9d811e0fc18 | Executing
single-partition query on CardHash | xxx.xxx.4.16 | 610 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39147-af3a-11e2-b8dc-a7032a583115 | Merging
data from memtables and 0 sstables | xxx.xxx.213.136 | 239 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39148-af3a-11e2-9480-e9d811e0fc18 | Acquiring
sstable references | xxx.xxx.4.16 | 625 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39148-af3a-11e2-b8dc-a7032a583115 | Merging
memtable contents | xxx.xxx.213.136 | 242 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39149-af3a-11e2-9480-e9d811e0fc18 | Sending
message to /xxx.xxx.152.81 | xxx.xxx.4.16 | 627 | WRITE-/xxx.xxx.90.147
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e39149-af3a-11e2-b8dc-a7032a583115 | Read 0
live cells and 0 tombstoned | xxx.xxx.213.136 | 258 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914a-af3a-11e2-9480-e9d811e0fc18 | Merging
memtable contents | xxx.xxx.4.16 | 646 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914a-af3a-11e2-b8dc-a7032a583115 | Merging
data from memtables and 0 sstables | xxx.xxx.213.136 | 287 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914b-af3a-11e2-9480-e9d811e0fc18 | Merging
data from memtables and 0 sstables | xxx.xxx.4.16 | 679 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914b-af3a-11e2-b8dc-a7032a583115 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.213.136 | 301 | ReadStage:11
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914c-af3a-11e2-9480-e9d811e0fc18 | Read 0
live cells and 0 tombstoned | xxx.xxx.4.16 | 704 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914c-af3a-11e2-b8dc-a7032a583115 | Read 0
live cells and 0 tombstoned | xxx.xxx.213.136 | 311 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914d-af3a-11e2-9480-e9d811e0fc18 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.4.16 | 763 | ReadStage:5330
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914d-af3a-11e2-b8dc-a7032a583115 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.213.136 | 354 | ReadStage:41
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3914e-af3a-11e2-b8dc-a7032a583115 | Sending
message to /xxx.xxx.152.81 | xxx.xxx.213.136 | 374 | WRITE-/xxx.xxx.90.147
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b850-af3a-11e2-9ec9-772ec39805fe | Message
received from /xxx.xxx.213.136 | xxx.xxx.90.147 | 1289 | Thread-80
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b850-af3a-11e2-9f00-0b1bd79b59b0 | Message
received from /xxx.xxx.90.147 | xxx.xxx.79.52 | 28 | Thread-71
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b851-af3a-11e2-9ec9-772ec39805fe | Processing
response from /xxx.xxx.213.136 | xxx.xxx.90.147 | 1370 | RequestResponseStage:8
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b852-af3a-11e2-9ec9-772ec39805fe | Message
received from /xxx.xxx.4.16 | xxx.xxx.90.147 | 1533 | Thread-1435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3b853-af3a-11e2-9ec9-772ec39805fe | Processing
response from /xxx.xxx.4.16 | xxx.xxx.90.147 | 1598 | RequestResponseStage:7
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df60-af3a-11e2-9ec9-772ec39805fe | Message
received from /xxx.xxx.79.52 | xxx.xxx.90.147 | 2527 | Thread-143
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df60-af3a-11e2-9f00-0b1bd79b59b0 | Message
received from /xxx.xxx.90.147 | xxx.xxx.79.52 | 280 | Thread-71
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df61-af3a-11e2-9ec9-772ec39805fe | Processing
response from /xxx.xxx.79.52 | xxx.xxx.90.147 | 2604 | RequestResponseStage:6
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df61-af3a-11e2-9f00-0b1bd79b59b0 | Executing
single-partition query on CardHash | xxx.xxx.79.52 | 424 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df62-af3a-11e2-9f00-0b1bd79b59b0 | Acquiring
sstable references | xxx.xxx.79.52 | 445 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df63-af3a-11e2-9f00-0b1bd79b59b0 | Merging
memtable contents | xxx.xxx.79.52 | 474 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df64-af3a-11e2-9f00-0b1bd79b59b0 | Merging
data from memtables and 0 sstables | xxx.xxx.79.52 | 525 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df65-af3a-11e2-9f00-0b1bd79b59b0 | Read 0
live cells and 0 tombstoned | xxx.xxx.79.52 | 545 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df66-af3a-11e2-9f00-0b1bd79b59b0 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.79.52 | 603 | ReadStage:6435
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df67-af3a-11e2-9f00-0b1bd79b59b0 | Executing
single-partition query on CardHash | xxx.xxx.79.52 | 617 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df68-af3a-11e2-9f00-0b1bd79b59b0 | Acquiring
sstable references | xxx.xxx.79.52 | 632 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df69-af3a-11e2-9f00-0b1bd79b59b0 | Merging
memtable contents | xxx.xxx.79.52 | 656 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6a-af3a-11e2-9f00-0b1bd79b59b0 | Sending
message to /xxx.xxx.152.81 | xxx.xxx.79.52 | 657 | WRITE-/xxx.xxx.90.147
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6b-af3a-11e2-9f00-0b1bd79b59b0 | Merging
data from memtables and 0 sstables | xxx.xxx.79.52 | 697 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6c-af3a-11e2-9f00-0b1bd79b59b0 | Read 0
live cells and 0 tombstoned | xxx.xxx.79.52 | 718 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e3df6d-af3a-11e2-9f00-0b1bd79b59b0 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.79.52 | 766 | ReadStage:6436
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40670-af3a-11e2-b266-75b700b21012 | Message
received from /xxx.xxx.90.147 | xxx.xxx.201.218 | 23 | Thread-47
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40671-af3a-11e2-b266-75b700b21012 | Message
received from /xxx.xxx.90.147 | xxx.xxx.201.218 | 81 | Thread-47
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40672-af3a-11e2-b266-75b700b21012 | Executing
single-partition query on CardHash | xxx.xxx.201.218 | 150 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40673-af3a-11e2-b266-75b700b21012 | Executing
single-partition query on CardHash | xxx.xxx.201.218 | 158 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40674-af3a-11e2-b266-75b700b21012 | Acquiring
sstable references | xxx.xxx.201.218 | 175 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40675-af3a-11e2-b266-75b700b21012 | Acquiring
sstable references | xxx.xxx.201.218 | 176 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40676-af3a-11e2-b266-75b700b21012 | Merging
memtable contents | xxx.xxx.201.218 | 201 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40677-af3a-11e2-b266-75b700b21012 | Merging
memtable contents | xxx.xxx.201.218 | 201 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40678-af3a-11e2-b266-75b700b21012 | Merging
data from memtables and 0 sstables | xxx.xxx.201.218 | 240 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e40679-af3a-11e2-b266-75b700b21012 | Merging
data from memtables and 0 sstables | xxx.xxx.201.218 | 243 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067a-af3a-11e2-b266-75b700b21012 | Read 0
live cells and 0 tombstoned | xxx.xxx.201.218 | 264 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067b-af3a-11e2-b266-75b700b21012 | Read 0
live cells and 0 tombstoned | xxx.xxx.201.218 | 264 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067c-af3a-11e2-b266-75b700b21012 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.201.218 | 310 | ReadStage:60
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067d-af3a-11e2-b266-75b700b21012 | Enqueuing
response to /xxx.xxx.90.147 | xxx.xxx.201.218 | 310 | ReadStage:58
> c7e36a30-af3a-11e2-9ec9-772ec39805fe | c7e4067e-af3a-11e2-b266-75b700b21012 | Sending
message to /xxx.xxx.152.81 | xxx.xxx.201.218 | 369 | WRITE-/xxx.xxx.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

Mime
View raw message