TRACING
Enables or disables tracing for all CQL statements in the current CQLSH session.
Tracing can show tracing input from any or all nodes in the cluster.
Use tracing to troubleshoot performance problems.
Detailed transaction information related to internal operations is captured in the system_traces
keyspace.
To enable or disable tracing for the entire cluster, run nodetool settraceprobability
for each node.
For information about probabilistic tracing, see nodetool settraceprobability.
When a query runs in a tracing session, a session ID is shown in the query results.
In addition, an entry with the high-level details such as session ID, client, and session length, is written to the system_traces.session
table.
Details for each operation are written to the system_traces.events
table.
The session ID is used by the SHOW SESSION tracing_session_id command to display detailed event information. |
Tracing information is saved for 24 hours by default. This can be overridden by setting tracetype_query_ttl
to some seconds in the cassandra.yaml; this will affect new trace data after the node is restarted.
To save tracing data that has already been written for longer, copy the data to another location.
Synopsis
TRACING [ ON | OFF ]
Syntax legend
Syntax conventions | Description |
---|---|
UPPERCASE |
Literal keyword. |
Lowercase |
Not literal. |
|
Variable value. Replace with a user-defined value. |
|
Optional.
Square brackets ( |
|
Group.
Parentheses ( |
|
Or.
A vertical bar ( |
|
Repeatable.
An ellipsis ( |
|
Single quotation ( |
|
Map collection.
Braces ( |
Set, list, map, or tuple.
Angle brackets ( |
|
|
End CQL statement.
A semicolon ( |
|
Separate the command line options from the command arguments with two hyphens ( |
|
Search CQL only: Single quotation marks ( |
|
Search CQL only: Identify the entity and literal value to overwrite the XML element in the schema and solrConfig files. |
ON
-
Enables tracing.
OFF
-
Disables tracing.
Examples
Tracing a write request
The following example shows tracing activity on a three node cluster. The cluster has a keyspace that has a replication factor of three, and an employee table similar to the table in Using a compound primary key.
The tracing shows that the coordinator performs these actions:
-
Identifies the target nodes for replication of the row.
-
Writes the row to the commit log and memtable.
-
Confirms completion of the request.
Turn on tracing:
TRACING ON
Insert a record into the cyclist_name
table:
INSERT INTO cycling.cyclist_name (
id,
lastname,
firstname
) VALUES (
e7ae5cf3-d358-4d99-b900-85902fda9bb0,
'FRAME',
'Alex'
);
The request and each step are captured and displayed:
Tracing session: 9b378c70-b114-11e6-89b5-b7fad52e1885
activity | timestamp | source | source_elapsed | client
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Execute CQL3 query | 2016-11-22 16:34:34.300000 | 127.0.0.1 | 0 | 127.0.0.1
Parsing INSERT INTO cycling.cyclist_name (id, lastname, firstname)
VALUES (e7ae5cf3-d358-4d99-b900-85902fda9bb0, 'FRAME','Alex'); [Native-Transport-Requests-1] | 2016-11-22 16:34:34.305000 | 127.0.0.1 | 5935 | 127.0.0.1
Preparing statement [Native-Transport-Requests-1] | 2016-11-22 16:34:34.308000 | 127.0.0.1 | 9199 | 127.0.0.1
Determining replicas for mutation [Native-Transport-Requests-1] | 2016-11-22 16:34:34.330000 | 127.0.0.1 | 30530 | 127.0.0.1
Appending to commitlog [MutationStage-3] | 2016-11-22 16:34:34.330000 | 127.0.0.1 | 30979 | 127.0.0.1
Adding to cyclist_name memtable [MutationStage-3] | 2016-11-22 16:34:34.330000 | 127.0.0.1 | 31510 | 127.0.0.1
Request complete | 2016-11-22 16:34:34.333633 | 127.0.0.1 | 33633 | 127.0.0.1
The |
Tracing a sequential scan
A single row is spread across multiple SSTables.
Reading one row involves reading data from multiple SSTables, as shown by the trace for this request to read rows from the cyclist_name
table:
SELECT *
FROM cycling.cyclist_name;
The query results display first, followed by the session ID and session details:
id | firstname | lastname
--------------------------------------+-----------+-----------------
e7ae5cf3-d358-4d99-b900-85902fda9bb0 | Alex | FRAME
fb372533-eb95-4bb4-8685-6ef61e994caa | Michael | MATTHEWS
5b6962dd-3f90-4c93-8f61-eabfa4a803e2 | Marianne | VOS
220844bf-4860-49d6-9a4b-6b5d3a79cbfb | Paolo | TIRALONGO
6ab09bec-e68e-48d9-a5f8-97e6fb4c9b47 | Steven | KRUIKSWIJK
e7cd5752-bc0d-4157-a80f-7523add8dbcd | Anna | VAN DER BREGGEN
(6 rows)
Tracing session: 117c1440-b116-11e6-89b5-b7fad52e1885
activity | timestamp | source | source_elapsed | client
-------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
Execute CQL3 query | 2016-11-22 16:45:02.212000 | 127.0.0.1 | 0 | 127.0.0.1
Parsing SELECT * FROM cycling.cyclist_name ; [Native-Transport-Requests-1] | 2016-11-22 16:45:02.212000 | 127.0.0.1 | 372 | 127.0.0.1
Preparing statement [Native-Transport-Requests-1] | 2016-11-22 16:45:02.212000 | 127.0.0.1 | 541 | 127.0.0.1
Computing ranges to query [Native-Transport-Requests-1] | 2016-11-22 16:45:02.213000 | 127.0.0.1 | 807 | 127.0.0.1
Submitting range requests on 257 ranges with a concurrency of 257 (0.3 rows per range expected) [Native-Transport-Requests-1] | 2016-11-22 16:45:02.213000 | 127.0.0.1 | 1632 | 127.0.0.1
Submitted 1 concurrent range requests [Native-Transport-Requests-1] | 2016-11-22 16:45:02.215000 | 127.0.0.1 | 3002 | 127.0.0.1
Executing seq scan across 1 sstables for (min(-9223372036854775808), min(-9223372036854775808)] [ReadStage-2] | 2016-11-22 16:45:02.215000 | 127.0.0.1 | 3130 | 127.0.0.1
Read 6 live and 0 tombstone cells [ReadStage-2] | 2016-11-22 16:45:02.216000 | 127.0.0.1 | 3928 | 127.0.0.1
Request complete | 2016-11-22 16:45:02.216252 | 127.0.0.1 | 4252 | 127.0.0.1