Summary
This article deals with a misleading NPE that could confuse users.
A java.lang.NullPointerException
(NPE) can be seen as a consequence of a number of simple CQL statements, like for example CREATE TYPE, or ALTER TABLE, however the CQL statement will complete.
The problem is not the actual CQL statement but rather the slowLog facility that throws the NPE.
Symptoms
This stack is thrown after a CQL statement is run:
ERROR [SharedPool-Worker-1] 2016-12-07 16:19:57,071 QueryMessage.java:135 - Unexpected error during query
java.lang.NullPointerException: null
at org.apache.cassandra.cql3.statements.CFStatement.columnFamily(CFStatement.java:62) ~[cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at com.datastax.bdp.cassandra.cql3.StatementUtils.getColumnFamily(StatementUtils.java:114) ~[dse-core-4.8.5.jar:4.8.5]
at com.datastax.bdp.cassandra.cql3.CqlSlowLogPlugin.maybeRecord(CqlSlowLogPlugin.java:157) ~[dse-core-4.8.5.jar:4.8.5]
at com.datastax.bdp.cassandra.cql3.DseQueryHandler$Operation.executeWithTiming(DseQueryHandler.java:216) ~[dse-core-4.8.5.jar:4.8.5]
at com.datastax.bdp.cassandra.cql3.DseQueryHandler$Operation.executeWithAuditLogging(DseQueryHandler.java:259) ~[dse-core-4.8.5.jar:4.8.5]
at com.datastax.bdp.cassandra.cql3.DseQueryHandler.process(DseQueryHandler.java:94) ~[dse-core-4.8.5.jar:4.8.5]
at org.apache.cassandra.transport.messages.QueryMessage.execute(QueryMessage.java:122) ~[cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:439) [cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at org.apache.cassandra.transport.Message$Dispatcher.channelRead0(Message.java:335) [cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105) [netty-all-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:307) [netty-all-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:32) [netty-all-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:298) [netty-all-4.0.34.Final.jar:4.0.34.Final]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_101]
at org.apache.cassandra.concurrent.AbstractTracingAwareExecutorService$FutureTask.run(AbstractTracingAwareExecutorService.java:164) [cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) [cassandra-all-2.1.13.1131.jar:2.1.13.1131]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]
Cause
This issue is tracked in the internal jira:
DSP-10930 - “Slow query log NPEs instead of logging slow statement”.
Affected versions: DSE 4.7.9, 4.8.9, 5.0.2
Solution
The jira is fixed in 4.8.11 and 5.0.3