1. Overview
Apache Cassandra is a scalable, distributed NoSQL database. Cassandra streams data between nodes and provides continuous availability with no single point of failure. In fact, Cassandra is able to handle large amounts of data with exceptional performance
When developing an application that uses a database, it is highly important to be able to log and debug the executed queries. In this tutorial, we’ll be looking at how to log queries and statements when using Apache Cassandra with Spring Boot.
In our examples, we’ll make use of the Spring Data repository abstraction and the Testcontainers library. We’ll see how to configure Cassandra query logging through Spring configuration. In addition, we’ll explore the Datastax Request Logger. We can configure this built-in component for more advanced logging.
2. Setting Up a Test Environment
In order to demonstrate query logging, we’ll need to set up a test environment. To begin with, we’ll set up test data using Spring Data for Apache Cassandra. Next, we’ll make use of the Testcontainers library to run a Cassandra database container for integration testing.
2.1. Cassandra Repository
Spring Data enables us to create Cassandra repositories based on common Spring interfaces. First, let’s start by defining a simple DAO class:
@Table
public class Person {
@PrimaryKey
private UUID id;
private String firstName;
private String lastName;
public Person(UUID id, String firstName, String lastName) {
this.id = id;
this.firstName = firstName;
this.lastName = lastName;
}
// getters, setters, equals and hash code
}
Then, we’ll define a Spring Data repository for our DAO by extending the CassandraRepository interface:
@Repository
public interface PersonRepository extends CassandraRepository<Person, UUID> {}
Finally, we’ll add two properties in our application.properties file:
spring.data.cassandra.schema-action=create_if_not_exists
spring.data.cassandra.local-datacenter=datacenter1
As a result, Spring Data will automatically create the annotated table for us.
We should note that create_if_not_exists option is not recommended for production systems.
As an alternative, tables can be created by loading a schema.sql script from the standard root classpath.
2.2. Cassandra Container
As a next step, let’s configure and expose a Cassandra container on a specific port:
@Container
public static final CassandraContainer cassandra =
(CassandraContainer) new CassandraContainer("cassandra:3.11.2").withExposedPorts(9042);
Before using the container for integration testing, we’ll need to override test properties required for Spring Data to establish a connection with it:
TestPropertyValues.of(
"spring.data.cassandra.keyspace-name=" + KEYSPACE_NAME,
"spring.data.cassandra.contact-points=" + cassandra.getContainerIpAddress(),
"spring.data.cassandra.port=" + cassandra.getMappedPort(9042)
).applyTo(configurableApplicationContext.getEnvironment());
createKeyspace(cassandra.getCluster());
Finally, before creating any objects/tables, we’ll need to create a Cassandra keyspace. A keyspace is similar to a database in an RDBMS.
2.3. Integration Tests
Now, we have everything in place to start writing our integration tests.
We are interested in logging select, insert, and delete queries. Thus, we will write a couple of tests that will trigger those different types of queries.
First, we’ll write a test for saving and updating a person’s record. We expect this test to execute two inserts and one select database query:
@Test
void givenExistingPersonRecord_whenUpdatingIt_thenRecordIsUpdated() {
UUID personId = UUIDs.timeBased();
Person existingPerson = new Person(personId, "Luka", "Modric");
personRepository.save(existingPerson);
existingPerson.setFirstName("Marko");
personRepository.save(existingPerson);
List<Person> savedPersons = personRepository.findAllById(List.of(personId));
assertThat(savedPersons.get(0).getFirstName()).isEqualTo("Marko");
}
Then, we’ll write a test for saving and deleting an existing person record. We expect this test to execute one insert, delete and select database queries:
@Test
void givenExistingPersonRecord_whenDeletingIt_thenRecordIsDeleted() {
UUID personId = UUIDs.timeBased();
Person existingPerson = new Person(personId, "Luka", "Modric");
personRepository.delete(existingPerson);
List<Person> savedPersons = personRepository.findAllById(List.of(personId));
assertThat(savedPersons.isEmpty()).isTrue();
}
By default, we won’t observe any database queries logged in the console.
3. Spring Data CQL Logging
With Spring Data for Apache Cassandra version 2.0 or higher, is possible to set the log level for the CqlTemplate class in the application.properties:
logging.level.org.springframework.data.cassandra.core.cql.CqlTemplate=DEBUG
Thus, by setting the log level to DEBUG, we enable logging of all executed queries and prepared statements:
2021-09-25 12:41:58.679 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Executing CQL statement [CREATE TABLE IF NOT EXISTS person
(birthdate date, firstname text, id uuid, lastname text, lastpurchaseddate timestamp, lastvisiteddate timestamp, PRIMARY KEY (id));]
2021-09-25 12:42:01.204 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Preparing statement [INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate)
VALUES (?,?,?,?,?,?)] using org.springframework.data.cassandra.core.CassandraTemplate$PreparedStatementHandler@4d16975b
2021-09-25 12:42:01.253 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Executing prepared statement [INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate) VALUES (?,?,?,?,?,?)]
2021-09-25 12:42:01.279 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Preparing statement [INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate)
VALUES (?,?,?,?,?,?)] using org.springframework.data.cassandra.core.CassandraTemplate$PreparedStatementHandler@539dd2d0
2021-09-25 12:42:01.290 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Executing prepared statement [INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate) VALUES (?,?,?,?,?,?)]
2021-09-25 12:42:01.351 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Preparing statement [SELECT * FROM person WHERE id IN (371bb4a0-1ded-11ec-8cad-934f1aec79e6)]
using org.springframework.data.cassandra.core.CassandraTemplate$PreparedStatementHandler@3e61cffd
2021-09-25 12:42:01.370 DEBUG 17856 --- [ main] o.s.data.cassandra.core.cql.CqlTemplate:
Executing prepared statement [SELECT * FROM person WHERE id IN (371bb4a0-1ded-11ec-8cad-934f1aec79e6)]
Unfortunately, using this solution, we won’t see the output of the bound values used in the statements.
4. Datastax Request Tracker
The DataStax request tracker is a session-wide component that gets notified about the outcome of every Cassandra request.
The DataStax Java driver for Apache Cassandra comes with an optional request tracker implementation that logs all requests.
4.1. Noop Request Tracker
The default request tracker implementation is called NoopRequestTracker. Consequently, it doesn’t do anything:
System.setProperty("datastax-java-driver.advanced.request-tracker.class", "NoopRequestTracker");
To set up a different tracker, we should specify a class that implements RequestTracker in the Cassandra configuration or via system properties.
4.2. Request Logger
RequestLogger is a built-in implementation of the RequestTracker that logs every request.
We can enable it by setting specific DataStax Java driver system properties:
System.setProperty("datastax-java-driver.advanced.request-tracker.class", "RequestLogger");
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.success.enabled", "true");
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.slow.enabled", "true");
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.error.enabled", "true");
In this example, we enabled logging of all successful, slow, and failed requests.
Now, when we run our tests, we’ll observe all executed database queries in the log:
2021-09-25 13:06:31.799 INFO 11172 --- [ s0-io-4] c.d.o.d.i.core.tracker.RequestLogger:
[s0|90232530][Node(endPoint=localhost/[0:0:0:0:0:0:0:1]:49281, hostId=c50413d5-03b6-4037-9c46-29f0c0da595a, hashCode=68c305fe)]
Success (6 ms) [6 values] INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate)
VALUES (?,?,?,?,?,?) [birthdate=NULL, firstname='Luka', id=a3ad6890-1df0-11ec-a295-7d319da1858a, lastname='Modric', lastpurchaseddate=NULL, lastvisiteddate=NULL]
2021-09-25 13:06:31.811 INFO 11172 --- [ s0-io-4] c.d.o.d.i.core.tracker.RequestLogger:
[s0|778232359][Node(endPoint=localhost/[0:0:0:0:0:0:0:1]:49281, hostId=c50413d5-03b6-4037-9c46-29f0c0da595a, hashCode=68c305fe)]
Success (4 ms) [6 values] INSERT INTO person (birthdate,firstname,id,lastname,lastpurchaseddate,lastvisiteddate)
VALUES (?,?,?,?,?,?) [birthdate=NULL, firstname='Marko', id=a3ad6890-1df0-11ec-a295-7d319da1858a, lastname='Modric', lastpurchaseddate=NULL, lastvisiteddate=NULL]
2021-09-25 13:06:31.847 INFO 11172 --- [ s0-io-4] c.d.o.d.i.core.tracker.RequestLogger:
[s0|1947131919][Node(endPoint=localhost/[0:0:0:0:0:0:0:1]:49281, hostId=c50413d5-03b6-4037-9c46-29f0c0da595a, hashCode=68c305fe)]
Success (5 ms) [0 values] SELECT * FROM person WHERE id IN (a3ad6890-1df0-11ec-a295-7d319da1858a)
We’ll see all the requests are logged under the category com.datastax.oss.driver.internal.core.tracker.RequestLogger.
In addition, all bound values used in the statements also get logged per default.
4.3. Bound Values
The built-it RequestLogger is a highly customizable component. We can configure the output of the bound values using the following system properties:
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.show-values", "true");
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.max-value-length", "100");
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.max-values", "100");
A formatted representation of a value will be truncated in case it is longer than the value defined by the max-value-length property.
Using the max-values property, we can define the maximum number of bound values to log.
4.4. Additional Options
In our first example, we enabled the logging of slow requests. We can use the threshold property to classify a successful request as slow:
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.slow.threshold ", "1 second");
By default, stack traces are logged for all failed requests. In case we disable them, we’ll only see the exception’s string representation in the log:
System.setProperty("datastax-java-driver.advanced.request-tracker.logs.show-stack-trace", "true");
Successful and slow requests use the INFO log level. On the other hand, failed requests use the ERROR level.
5. Conclusion
In this article, we explored the logging of queries and statements when using Apache Cassandra with Spring Boot.
In the examples, we covered configuring the log level in Spring Data for Apache Cassandra. We saw that Spring Data will log queries, but not the bound values. Finally, we explored the Datastax Request Tracker. It is a highly customizable component we can use to log Cassandra queries together with their bound values.
As always, the source code is available over on GitHub