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
