Problem

How to trace the execution of CQL queries in Cassandra and API Gateway?

Resolution

The examples below were tested for API Gateway 7.7 (using log4j2.yaml) and Cassandra 2.2.12:

1. Session tracing

Use "TRACING ON"/"TRACING OFF" to enable/disable tracing for all CQL statements in the current CQLSH session.

cqlsh> TRACING ON
cqlsh> SELECT dateof(now()) FROM system.local ;
cqlsh> TRACING OFF
cqlsh> select activity, source, source_elapsed from system_traces.events;

2. Cluster/global tracing

To enable tracing for one request out of a 1000 in the entire cluster one can run "nodetool settraceprobability 0.001" for each node.

To disable tracing run "nodetool settraceprobability 0" for each node.

Similarly, the requests executed while "nodetool settraceprobability 0.001" are logged in the system_traces.events table and can be queried with:

cqlsh> select * from system_traces.events;

3. Driver tracing

As per DataStax Java driver logging the following loggers can be used:

• com.datastax.driver.core.Connection
• com.datastax.driver.core.Session
• com.datastax.driver.core.Cluster
• com.datastax.driver.core.RequestHandler
• com.datastax.driver.core.Message
• com.datastax.driver.core.QueryLogger (NORMAL, SLOW, ERROR)

The attached log4j2.yaml sample can be used in apigateway/system/conf/. It:

• has the above loggers on "level: trace"
• uses com.datastax.driver.core.QueryLogger.NORMAL (logs all normal queries)
• writes the information in a separate log file (my_Cassandra.log - path to be adjusted at line 5)
• uses regex filter to eliminate (does not log) Selects on "api_portal_portaltimestamp" table
  • regex + OnMatch + OnMismatch can be used/adapted to only include queries on a specific table.

Sample log output:

2021-06-17 14:23:05,940 TRACE c.d.d.c.Connection$11 [client-side-only-cluster-id-nio-worker-1] Connection[localhost/127.0.0.1:9042-2, inFlight=1, closed=false], stream 31040, request sent successfully

2021-06-17 14:23:05,940 TRACE c.d.d.c.Connection$Dispatcher [client-side-only-cluster-id-nio-worker-1] Connection[localhost/127.0.0.1:9042-2, inFlight=1, closed=false], stream 31040, received: ROWS [3 columns]

2021-06-17 14:23:05,940 TRACE c.d.d.c.RequestHandler [client-side-only-cluster-id-nio-worker-1] [69943558-0] Setting final result

2021-06-17 14:23:05,940 TRACE c.d.d.c.QueryLogger [client-side-only-cluster-id-nio-worker-1] [client-side-only-cluster-id] [localhost/127.0.0.1:9042] Query completed normally, took 0 ms: [1 bound values] SELECT * FROM xfcb58d3a_aea1_4457_bc27_92ddb64a41c6_group_2."api_portal_portalconfigstore" WHERE key = ? limit 1; [key:'portal']