cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ilya Kirnos (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CASSANDRA-5520) Query tracing session info inconsistent with events info
Date Sun, 28 Apr 2013 06:50:15 GMT
Ilya Kirnos created CASSANDRA-5520:
--------------------------------------

             Summary: 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

Mime
View raw message