Exception thrown when issuing segmentMetadata query

Has anyone seen this before? Or have any pointers for figuring out whats going on? Hopefully I’m just doing
something stupid.

I’m ingesting data using multiple realtime nodes from Kafka 8. I’m using druid 0.7.1.1, Oracle jdk 8. Deep storage in S3.

The following queries are executed against a broker node. Any help would be greatly appreciated. thanks!

url: http://druid05:8081/druid/v2/?pretty
query: {
“queryType”:“segmentMetadata”,
“dataSource”:“stage_tetris_log”,
“intervals”:[ “2015-05-12T00:00:00.000/2015-05-14T10:00:00.000” ]
}

result;

{
“error” : “io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis”
}

Here is a timeboundary query execution:

url: http://druid05:8081/druid/v2/?pretty

query: {
“queryType” : “timeBoundary”,
“dataSource”: “stage_tetris_log”
}

result;

[ {
“timestamp” : “2015-05-12T18:02:52.000Z”,
“result” : {
“maxTime” : “2015-05-13T01:42:22.000Z”,
“minTime” : “2015-05-12T18:02:52.000Z”
} } ]

Hi rick,
can you share full stack trace of the error from historical/broker logs ?

Hi Nishant,

Here you go. The exception is produced by a historical node. Let me know if you need any other info.

thanks,

Rick

2015-05-13T15:50:10,079 ERROR [qtp1930401429-18] io.druid.server.QueryResource - Exception handling request: {class=io.druid.server.QueryResource, exceptionType=class java.lang.ClassCastException, exceptionMessage=io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis, exception=java.lang.ClassCastException: io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis, query=io.druid.query.metadata.metadata.SegmentMetadataQuery@b3c7b7c0, peer=172.31.41.23}

java.lang.ClassCastException: io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis

at io.druid.query.metadata.SegmentMetadataQueryQueryToolChest$4.compare(SegmentMetadataQueryQueryToolChest.java:222) ~[druid-processing-0.7.1.1.jar:0.7.1.1]

at com.google.common.collect.NullsFirstOrdering.compare(NullsFirstOrdering.java:44) ~[guava-16.0.1.jar:?]

at com.metamx.common.guava.MergeIterator$1.compare(MergeIterator.java:46) ~[java-util-0.26.15.jar:?]

at com.metamx.common.guava.MergeIterator$1.compare(MergeIterator.java:42) ~[java-util-0.26.15.jar:?]

at java.util.PriorityQueue.siftUpUsingComparator(PriorityQueue.java:669) ~[?:1.8.0_45]

at java.util.PriorityQueue.siftUp(PriorityQueue.java:645) ~[?:1.8.0_45]

at java.util.PriorityQueue.offer(PriorityQueue.java:344) ~[?:1.8.0_45]

at java.util.PriorityQueue.add(PriorityQueue.java:321) ~[?:1.8.0_45]

at com.metamx.common.guava.MergeIterator.(MergeIterator.java:55) ~[java-util-0.26.15.jar:?]

at com.metamx.common.guava.MergeIterable.iterator(MergeIterable.java:49) ~[java-util-0.26.15.jar:?]

at io.druid.query.ChainedExecutionQueryRunner$1.make(ChainedExecutionQueryRunner.java:162) ~[druid-processing-0.7.1.1.jar:0.7.1.1]

at com.metamx.common.guava.BaseSequence.toYielder(BaseSequence.java:78) ~[java-util-0.26.15.jar:?]

at com.metamx.common.guava.MappedSequence.toYielder(MappedSequence.java:46) ~[java-util-0.26.15.jar:?]

at io.druid.server.QueryResource.doPost(QueryResource.java:161) [druid-server-0.7.1.1.jar:0.7.1.1]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_45]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_45]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_45]

at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_45]

at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1511) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1442) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1391) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1381) [jersey-server-1.17.1.jar:1.17.1]

at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416) [jersey-servlet-1.17.1.jar:1.17.1]

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:538) [jersey-servlet-1.17.1.jar:1.17.1]

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:716) [jersey-servlet-1.17.1.jar:1.17.1]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api-3.1.0.jar:3.1.0]

at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:278) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:268) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:180) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:93) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:120) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:132) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:129) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:206) [guice-servlet-4.0-beta.jar:?]

at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:129) [guice-servlet-4.0-beta.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83) [jetty-servlets-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:364) [jetty-servlets-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) [jetty-servlet-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:221) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1125) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) [jetty-servlet-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1059) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.Server.handle(Server.java:497) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248) [jetty-server-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:620) [jetty-util-9.2.5.v20141112.jar:9.2.5.v20141112]

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:540) [jetty-util-9.2.5.v20141112.jar:9.2.5.v20141112]

at java.lang.Thread.run(Thread.java:745) [?:1.8.0_45]

Also FYI.

I have seen this exception here and there (from the same class).

throw new ISE(“Merging when a merge isn’t supposed to happen[%s], [%s]”, arg1, arg2);

thanks.

oh, and the related log output from the broker log.

2015-05-13T15:51:04,897 INFO [qtp789315095-40 - /druid/v2/?pretty] io.druid.server.QueryResource - io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis [e439b369-7548-4ced-88a6-fa362ab9bed3]

2015-05-13T15:51:04,897 DEBUG [qtp789315095-40 - /druid/v2/?pretty] com.metamx.emitter.core.LoggingEmitter - Event [{“service”:“druid/stage/broker”,“host”:“172.31.41.23:8081”,“feed”:“druid_requests”,“remoteAddr”:“172.31.2.135”,“timestamp”:“2015-05-13T15:51:04.897Z”,“queryStats”:{“success”:false,“interrupted”:true,“reason”:“io.druid.query.QueryInterruptedException: io.druid.query.Result cannot be cast to io.druid.query.metadata.metadata.SegmentAnalysis”},“query”:{“queryType”:“segmentMetadata”,“dataSource”:{“type”:“table”,“name”:“stage_tetris_install”},“intervals”:{“type”:“LegacySegmentSpec”,“intervals”:[“2015-05-12T00:00:00.000Z/2015-05-14T10:00:00.000Z”]},“toInclude”:{“type”:“all”},“merge”:false,“context”:{“queryId”:“e439b369-7548-4ced-88a6-fa362ab9bed3”,“timeout”:300000}}}]

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpConnection - org.eclipse.jetty.server.HttpConnection$SendCallback@2af08ef8[PROCESSING][i=ResponseInfo{HTTP/1.1 500 null,106,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@430dfed] generate: NEED_HEADER (null,[p=0,l=106,c=106,r=106],true)@START

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpConnection - org.eclipse.jetty.server.HttpConnection$SendCallback@2af08ef8[PROCESSING][i=ResponseInfo{HTTP/1.1 500 null,106,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@430dfed] generate: FLUSH ([p=0,l=151,c=8192,r=151],[p=0,l=106,c=106,r=106],true)@COMPLETING

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.io.WriteFlusher - write: WriteFlusher@3301bb1{IDLE} [HeapByteBuffer@9f4a0b07[p=0,l=151,c=8192,r=151]={<<<HTTP/1.1 500 Serv…v20141112)\r\n\r\n>>>esponse-Context: …\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@3f8259eb[p=0,l=106,c=106,r=106]={<<<{\n “error” : “io…mentAnalysis”\n}>>>}]

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.io.WriteFlusher - update WriteFlusher@3301bb1{WRITING}:IDLE–>WRITING

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.io.ChannelEndPoint - flushed 257 SelectChannelEndPoint@1208d9b8{/172.31.2.135:34218<->8081,Open,in,out,-,W,300000,HttpConnection}{io=0,kio=0,kro=1}

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.io.WriteFlusher - update WriteFlusher@3301bb1{IDLE}:WRITING–>IDLE

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpConnection - org.eclipse.jetty.server.HttpConnection$SendCallback@2af08ef8[PROCESSING][i=ResponseInfo{HTTP/1.1 500 null,106,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@430dfed] generate: DONE ([p=151,l=151,c=8192,r=0],[p=106,l=106,c=106,r=0],true)@END

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.Server - RESPONSE /druid/v2/ 500 handled=true

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpChannelState - HttpChannelState@5259558{s=DISPATCHED i=true a=null} unhandle DISPATCHED

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.http.HttpParser - parseNext s=CONTENT HeapByteBuffer@c27e0726[p=283,l=283,c=16384,r=0]={POST /druid/v2/?p…:00:00.000" ] }<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00…\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.http.HttpParser - CONTENT --> END

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpChannel - HttpChannelOverHttp@be27b8c{r=1,c=true,a=COMPLETED,uri=/druid/v2/} messageComplete

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpInput - HttpInputOverHTTP@179905 EOF

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.io.ChannelEndPoint - filled 0 SelectChannelEndPoint@1208d9b8{/172.31.2.135:34218<->8081,Open,in,out,-,-,300000,HttpConnection}{io=0,kio=0,kro=1}

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpConnection - HttpConnection@759c4111{FILLING} filled 0

2015-05-13T15:51:04,898 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.server.HttpInput - HttpInputOverHTTP@179905 eof EOF

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.http.HttpParser - reset HttpParser{s=END,137 of 137}

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40 - /druid/v2/?pretty] org.eclipse.jetty.http.HttpParser - END --> START

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40] org.eclipse.jetty.server.HttpChannel - HttpChannelOverHttp@be27b8c{r=1,c=false,a=IDLE,uri=-} handle exit, result COMPLETE

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40] org.eclipse.jetty.io.ChannelEndPoint - filled 0 SelectChannelEndPoint@1208d9b8{/172.31.2.135:34218<->8081,Open,in,out,-,-,300000,HttpConnection}{io=0,kio=0,kro=1}

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40] org.eclipse.jetty.io.ChannelEndPoint - filled 0 SelectChannelEndPoint@1208d9b8{/172.31.2.135:34218<->8081,Open,in,out,-,-,300000,HttpConnection}{io=0,kio=0,kro=1}

2015-05-13T15:51:04,899 DEBUG [qtp789315095-40] org.eclipse.jetty.http.HttpParser - parseNext s=START HeapByteBuffer@c27e0726[p=0,l=0,c=16384,r=0]={<<<>>>POST /druid/v2/?p…\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}

and the historical config:

druid.host=172.31.40.251:8083
druid.port=8083
druid.service=druid/stage/historical

We can only 1 scan segment in parallel with these configs.

Our intermediate buffer is also very small so longer topNs will be slow.

druid.processing.buffer.sizeBytes=100000000
#druid.processing.buffer.sizeBytes=1073741824
druid.processing.numThreads=1

druid.segmentCache.locations=[{“path”: “/mnt/druid/historical/indexCache”, “maxSize”: 10000000000}]
druid.server.maxSize=10000000000

#druid.historical.cache.useCache=true
#druid.historical.cache.populateCache=true

druid.monitoring.monitors=[“com.metamx.metrics.JvmMonitor”,“io.druid.server.metrics.ServerMonitor”]On Wednesday, May 13, 2015 at 8:57:17 AM UTC-7,

Rick Badertscher wrote:

Hi rick,
It seems this error can be caused due to configuration issue on your realtime node,

How many partitions are you creating for an interval ?

I wonder if you are setting up your shardSpec correctly for realtime nodes ?

similar exceptions have been reported here -

https://groups.google.com/forum/?utm_medium=email&utm_source=footer#!searchin/druid-user/segmentMetadata$20Merging$20when$20a$20merge/druid-user/ElielY4w_FI/-0rUV7bvidIJ

Hi Nishant,

Thanks, I think you are right that this has something to do with druid partitioning.

Here’s a summary of my ingestion setup:

4 Kafka topics, each has 16 partitions.

2 Realtime nodes. Both configured with the exact same spec file (which describes all 4 Kafka data sources) save one difference which is the shardSpec definition.

for one realtime node its: {“linear”, partitionNum=0} and the other is {“linear”, partitionNum=1}. The Kafka consumer group id is the same for both real time nodes.

It’s possible I interpreted the docs wrong, but I understood this to be a valid configuration, which would split the ingestion load across realtime nodes, no replication). I am aware of the issue with replication with this configuration as referenced here http://druid.io/docs/latest/Ingestion-overview.html.

Its also very possible there is some other aspect of my configuration which is incorrect.

My plan ultimately was likely to abandon realtime nodes altogether in favor of a tranquility bridge from Kafka to druid using realtime tasks, etc., which seems to be the favored approach. Although this was planned for the next iteration, was hoping to get things limping along with the realtime node approach.

Is there anything above that jumps out at you as incorrect. ??

The following druid doc excerpt pretty much describes my config:

For example, let’s say your topic is split across Kafka partitions 1, 2, & 3 and you have 2 real-time nodes with linear shard specs 1 & 2. Both of the real-time nodes are in the same consumer group. Real-time node 1 may consume data from partitions 1 & 3, and real-time node 2 may consume data from partition 2. Querying for your data through the broker will yield correct results.

I am going to take a closer look at how druid partitioning is behaving.

thanks,

Rick

So I think the problem has been resolved for now. It was one of 2 things.

I redeployed fully clean with 2 changes.

  1. Changed the shardSpec #'s from 0 & 1, to 1 & 2, to try and mirror the docs more closely.

  2. The Kafka topics had been setup with 16 partitions and a replication factor of 2. I changed the replication factor to 1.

I’m certain it must have been the Kafka topic replication. I think I was confused about topic replication vs druid segment replication.This was probably causing duplicate segments ? or something.

Thanks very much for the prompt attention.

One related question, is there an existing template or example implementation of a Java program would consume Kafka messages and forward them to Druid via tranquility, I’ve seen this mentioned but haven’t yet run across such a thing. ?

thanks again,

Rick