search

confluentinc / ksql

The database purpose-built for stream processing applications.
https://ksqldb.io
Other
128 stars 1.04k forks source link

Exceptions in the ksql log should print the query id #666

Open apurvam opened 6 years ago

apurvam commented 6 years ago

When exceptions are printed in the log due to failure for a particular query, the stack trace is printed without the query id, like so:

[2018-01-26 17:23:52,325] ERROR Invalid format: abc123|+|false|+|Fhg : null (io.confluent.ksql.structured.SqlPredicate:128)
[2018-01-26 17:23:52,325] ERROR  (io.confluent.ksql.structured.SqlPredicate:126)
java.lang.NullPointerException
        at io.confluent.ksql.structured.SqlPredicate.lambda$getStringKeyPredicate$0(SqlPredicate.java:121)
        at org.apache.kafka.streams.kstream.internals.KStreamFilter$KStreamFilterProcessor.process(KStreamFilter.java:42)
        at org.apache.kafka.streams.processor.internals.ProcessorNode$1.run(ProcessorNode.java:46)
        at org.apache.kafka.streams.processor.internals.StreamsMetricsImpl.measureLatencyNs(StreamsMetricsImpl.java:208)
        at org.apache.kafka.streams.processor.internals.ProcessorNode.process(ProcessorNode.java:124)
        at org.apache.kafka.streams.processor.internals.AbstractProcessorContext.forward(AbstractProcessorContext.java:174)
        at org.apache.kafka.streams.kstream.internals.KStreamTransformValues$KStreamTransformValuesProcessor.process(KStreamTransformValues.java:171)
        at org.apache.kafka.streams.processor.internals.ProcessorNode$1.run(ProcessorNode.java:46)
        at org.apache.kafka.streams.processor.internals.StreamsMetricsImpl.measureLatencyNs(StreamsMetricsImpl.java:208)
        at org.apache.kafka.streams.processor.internals.ProcessorNode.process(ProcessorNode.java:124)
        at org.apache.kafka.streams.processor.internals.AbstractProcessorContext.forward(AbstractProcessorContext.java:174)
        at org.apache.kafka.streams.kstream.internals.KStreamMap$KStreamMapProcessor.process(KStreamMap.java:42)
        at org.apache.kafka.streams.processor.internals.ProcessorNode$1.run(ProcessorNode.java:46)
        at org.apache.kafka.streams.processor.internals.StreamsMetricsImpl.measureLatencyNs(StreamsMetricsImpl.java:208)
        at org.apache.kafka.streams.processor.internals.ProcessorNode.process(ProcessorNode.java:124)
        at org.apache.kafka.streams.processor.internals.AbstractProcessorContext.forward(AbstractProcessorContext.java:174)
        at org.apache.kafka.streams.processor.internals.SourceNode.process(SourceNode.java:80)
        at org.apache.kafka.streams.processor.internals.StreamTask.process(StreamTask.java:219)
        at org.apache.kafka.streams.processor.internals.AssignedStreamsTasks.process(AssignedStreamsTasks.java:94)
        at org.apache.kafka.streams.processor.internals.TaskManager.process(TaskManager.java:421)
        at org.apache.kafka.streams.processor.internals.StreamThread.processAndMaybeCommit(StreamThread.java:924)
        at org.apache.kafka.streams.processor.internals.StreamThread.runOnce(StreamThread.java:804)
        at org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:756)
        at org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:726)

This is not useful when we have multiple concurrent queries as it doesn't help identify the problematic query. All log lines should have the query id as a prefix.

jthack commented 6 years ago

Same issue for us. any news on this @apurvam?

apurvam commented 5 years ago

cc @rodesai @vcrfxia we should consider adding this for our operational readiness.

stevenpyzhang commented 4 years ago

@apurvam How exactly do you recreate this particular error? I'm purposely causing Deserialization Errors in queries and there's enough info from the logs for me to tell what the query is that caused the errors. I'm wondering if it's just this particular error that's being logged poorly.