search

apache / druid

Apache Druid: a high performance real-time analytics database.
https://druid.apache.org/
Apache License 2.0
13.46k stars 3.7k forks source link

kafka indexing service javascript aggegation cause java.lang.IllegalArgumentException: fromIndex(0) > toIndex(-1 #6091

Closed terry19850829 closed 4 years ago

terry19850829 commented 6 years ago

druid 0.11.0

The log

2018-08-01T15:55:10,837 INFO [task-runner-0-priority-0] io.druid.curator.announcement.Announcer - unannouncing [/druid/announcements/t1-data-druid:8102]
2018-08-01T15:55:10,843 ERROR [task-runner-0-priority-0] io.druid.indexing.overlord.ThreadPoolTaskRunner - Exception while running task[KafkaIndexTask{id=index_kafka_transaction_crm_store_org_ds_test77_0c8ea14246f3652_bccaabbg, type=index_kafka, dataSource=transaction_crm_store_org_ds_test77}]
java.lang.IllegalArgumentException: fromIndex(0) > toIndex(-1)
    at java.util.ArrayList.subListRangeCheck(ArrayList.java:1014) ~[?:1.8.0_171]
    at java.util.ArrayList.subList(ArrayList.java:1004) ~[?:1.8.0_171]
    at io.druid.segment.realtime.appenderator.AppenderatorImpl.persist(AppenderatorImpl.java:381) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.segment.realtime.appenderator.AppenderatorImpl.persistAll(AppenderatorImpl.java:462) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.segment.realtime.appenderator.AppenderatorDriver.persist(AppenderatorDriver.java:258) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.indexing.kafka.KafkaIndexTask.run(KafkaIndexTask.java:532) ~[?:?]
    at io.druid.indexing.overlord.ThreadPoolTaskRunner$ThreadPoolTaskRunnerCallable.call(ThreadPoolTaskRunner.java:436) [druid-indexing-service-0.11.0.jar:0.11.0]
    at io.druid.indexing.overlord.ThreadPoolTaskRunner$ThreadPoolTaskRunnerCallable.call(ThreadPoolTaskRunner.java:408) [druid-indexing-service-0.11.0.jar:0.11.0]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_171]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_171]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_171]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_171]
2018-08-01T15:55:10,847 INFO [task-runner-0-priority-0] io.druid.indexing.overlord.TaskRunnerUtils - Task [index_kafka_transaction_crm_store_org_ds_test77_0c8ea14246f3652_bccaabbg] status changed to [FAILED].
2018-08-01T15:55:10,850 INFO [task-runner-0-priority-0] io.druid.indexing.worker.executor.ExecutorLifecycle - Task completed with status: {
  "id" : "index_kafka_transaction_crm_store_org_ds_test77_0c8ea14246f3652_bccaabbg",
  "status" : "FAILED",
  "duration" : 747
}

config here is ok

...
"metricsSpec": [
      {
        "type": "count",
        "name": "cnt"
      },
      {
        "type": "longSum",
        "name": "amount",
        "fieldName": "original_amount"
      }

    ],
...

add a javascript aggegation like below cause the issue

 {
        "type": "javascript",
        "name": "ef_amount",
        "fieldNames": ["type", "status", "original_amount"],
        "fnAggregate" : "function(current, type, status, original_amount) { if (type == 30 && status == 2000 && original_amount >= 200) { return current + original_amount; } else { return current; }}",
        "fnCombine"   : "function(partialA, partialB) { return partialA + partialB; }",
        "fnReset"     : "function()                   { return 0; }"
      }

Any ideas ?

peon config : -Ddruid.javascript.enable=true

superus+ 6928 5944 7 Aug01 pts/0 00:00:24 java -cp /app/druid/conf/druid/_common:/app/druid/conf/druid/middleManager:/app/druid/lib/* -server -Xms512m -Xmx512m -XX:MaxDirectMemorySize=640m -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager -Ddruid.indexer.runner.classpath=/app/druid/conf/druid/_common:/app/druid/conf/druid/middleManager:/app/druid/lib/* -Ddruid.indexer.task.baseTaskDir=var/druid/task -Ddruid.metadata.storage.connector.password=xxxxx-Ddruid.indexer.fork.property.druid.processing.numThreads=2 -Ddruid.emitter.logging.logLevel=info -Ddruid.emitter=logging -Ddruid.indexer.fork.property.druid.processing.buffer.sizeBytes=134217728 -Ddruid.indexer.task.restoreTasksOnRestart=true -Duser.timezone=UTC -Dfile.encoding.pkg=sun.io -Ddruid.storage.storageDirectory=var/druid/segments -Ddruid.selectors.coordinator.serviceName=druid/coordinator -Ddruid.selectors.indexing.serviceName=druid/overlord -Ddruid.indexing.doubleStorage=double -Ddruid.port=8091 -Ddruid.server.http.numThreads=25 -Ddruid.worker.capacity=10 -Ddruid.javascript.enable=true -Ddruid.zk.paths=/druid -Ddruid.service=druid/middleManager -Ddruid.metadata.storage.connector.user=wosai -Ddruid.metadata.storage.type=mysql -Ddruid.metadata.storage.connector.connectURI=jdbc:mysql://*****/druid_test -Djava.io.tmpdir=var/tmp -Ddruid.extensions.loadList=["druid-avro-extensions", "druid-kafka-indexing-service","mysql-metadata-storage"] -Ddruid.startup.logging.logProperties=true -Ddruid.zk.service.host=t1-data-druid:2181 -Ddruid.monitoring.monitors=["com.metamx.metrics.JvmMonitor"] -Ddruid.indexer.logs.directory=var/druid/indexing-logs -Dfile.encoding=UTF-8 -Ddruid.indexer.task.defaultHadoopCoordinates=["org.apache.hadoop:hadoop-client:2.7.3"] -Ddruid.storage.type=local -Ddruid.indexer.task.hadoopWorkingPath=var/druid/hadoop-tmp -Ddruid.indexer.fork.property.druid.processing.numMergeBuffers=2 -Ddruid.indexer.logs.type=file -Ddruid.processing.numThreads=2 -Ddruid.processing.buffer.sizeBytes=134217728 -Ddruid.processing.numMergeBuffers=2 -Ddruid.metrics.emitter.dimension.dataSource=transaction_crm_store_org_ds_test77 -Ddruid.metrics.emitter.dimension.taskId=index_kafka_transaction_crm_store_org_ds_test77_5ea75723dc838b5_ljkpbhej -Ddruid.host=t1-data-druid -Ddruid.port=8102 -Ddruid.tlsPort=-1 io.druid.cli.Main internal peon var/druid/task/index_kafka_transaction_crm_store_org_ds_test77_5ea75723dc838b5_ljkpbhej/task.json var/druid/task/index_kafka_transaction_crm_store_org_ds_test77_5ea75723dc838b5_ljkpbhej/a874d30a-c5bf-43f3-bfe1-ffd289920c6e/status.json

a2l007 commented 6 years ago

There could be parse exceptions that are getting raised due to which the segment to be persisted has no rows. Could you set reportParseExceptions to true in your config and try running again?

terry19850829 commented 6 years ago

@a2l007 I've config reportParseExceptions before, there is no other suggestion messages.I'll try again.

terry19850829 commented 6 years ago

@a2l007 After add the reportParseExceptions config, the error :

2018-08-02T08:10:49,580 INFO [task-runner-0-priority-0] io.druid.curator.discovery.CuratorDruidNodeAnnouncer - Unannounced [DiscoveryDruidNode{druidNode=DruidNode{serviceName='druid/middleManager', host='t1-data-druid', port=-1, plaintextPort=8101, enablePlaintextPort=true, tlsPort=-1, enableTlsPort=false}, nodeType='peon', services={dataNodeService=DataNodeService{tier='_default_tier', maxSize=0, type=indexer-executor, priority=0}, lookupNodeService=LookupNodeService{lookupTier='__default'}}}].
2018-08-02T08:10:49,580 INFO [task-runner-0-priority-0] io.druid.server.coordination.CuratorDataSegmentServerAnnouncer - Unannouncing self[DruidServerMetadata{name='t1-data-druid:8101', hostAndPort='t1-data-druid:8101', hostAndTlsPort='null', maxSize=0, tier='_default_tier', type=indexer-executor, priority=0}] at [/druid/announcements/t1-data-druid:8101]
2018-08-02T08:10:49,580 INFO [task-runner-0-priority-0] io.druid.curator.announcement.Announcer - unannouncing [/druid/announcements/t1-data-druid:8101]
2018-08-02T08:10:49,591 ERROR [task-runner-0-priority-0] io.druid.indexing.overlord.ThreadPoolTaskRunner - Exception while running task[KafkaIndexTask{id=index_kafka_transaction_crm_store_org_ds_test666_8344e87bbcb308d_jeipmkba, type=index_kafka, dataSource=transaction_crm_store_org_ds_test666}]
java.lang.IllegalArgumentException: fromIndex(0) > toIndex(-1)
    at java.util.ArrayList.subListRangeCheck(ArrayList.java:1014) ~[?:1.8.0_171]
    at java.util.ArrayList.subList(ArrayList.java:1004) ~[?:1.8.0_171]
    at io.druid.segment.realtime.appenderator.AppenderatorImpl.persist(AppenderatorImpl.java:381) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.segment.realtime.appenderator.AppenderatorImpl.persistAll(AppenderatorImpl.java:462) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.segment.realtime.appenderator.AppenderatorDriver.persist(AppenderatorDriver.java:258) ~[druid-server-0.11.0.jar:0.11.0]
    at io.druid.indexing.kafka.KafkaIndexTask.run(KafkaIndexTask.java:532) ~[?:?]
    at io.druid.indexing.overlord.ThreadPoolTaskRunner$ThreadPoolTaskRunnerCallable.call(ThreadPoolTaskRunner.java:436) [druid-indexing-service-0.11.0.jar:0.11.0]
    at io.druid.indexing.overlord.ThreadPoolTaskRunner$ThreadPoolTaskRunnerCallable.call(ThreadPoolTaskRunner.java:408) [druid-indexing-service-0.11.0.jar:0.11.0]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_171]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_171]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_171]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_171]
2018-08-02T08:10:49,596 INFO [task-runner-0-priority-0] io.druid.indexing.overlord.TaskRunnerUtils - Task [index_kafka_transaction_crm_store_org_ds_test666_8344e87bbcb308d_jeipmkba] status changed to [FAILED].
2018-08-02T08:10:49,600 INFO [task-runner-0-priority-0] io.druid.indexing.worker.executor.ExecutorLifecycle - Task completed with status: {
  "id" : "index_kafka_transaction_crm_store_org_ds_test666_8344e87bbcb308d_jeipmkba",
  "status" : "FAILED",
  "duration" : 956
}
2018-08-02T08:10:49,606 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.server.listener.announcer.ListenerResourceAnnouncer.stop()] on object[io.druid.query.lookup.LookupResourceListenerAnnouncer@5514579e].
2018-08-02T08:10:49,607 INFO [main] io.druid.curator.announcement.Announcer - unannouncing [/druid/listeners/lookups/__default/http:t1-data-druid:8101]
2018-08-02T08:10:49,611 INFO [main] io.druid.server.listener.announcer.ListenerResourceAnnouncer - Unannouncing start time on [/druid/listeners/lookups/__default/http:t1-data-druid:8101]
2018-08-02T08:10:49,616 INFO [main] org.eclipse.jetty.server.AbstractConnector - Stopped ServerConnector@76a6f045{HTTP/1.1,[http/1.1]}{0.0.0.0:8101}
2018-08-02T08:10:49,618 INFO [main] org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.s.ServletContextHandler@2a484710{/,null,UNAVAILABLE}
2018-08-02T08:10:49,621 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.indexing.worker.executor.ExecutorLifecycle.stop() throws java.lang.Exception] on object[io.druid.indexing.worker.executor.ExecutorLifecycle@1c046c92].
2018-08-02T08:10:49,621 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.indexing.overlord.ThreadPoolTaskRunner.stop()] on object[io.druid.indexing.overlord.ThreadPoolTaskRunner@177ede17].
2018-08-02T08:10:49,622 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.curator.announcement.Announcer.stop()] on object[io.druid.curator.announcement.Announcer@100aa331].
2018-08-02T08:10:49,622 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.discovery.DruidLeaderClient.stop()] on object[io.druid.discovery.DruidLeaderClient@2fe2965c].
2018-08-02T08:10:49,622 INFO [main] io.druid.discovery.DruidLeaderClient - Stopped.
2018-08-02T08:10:49,622 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.curator.discovery.ServerDiscoverySelector.stop() throws java.io.IOException] on object[io.druid.curator.discovery.ServerDiscoverySelector@35787726].
2018-08-02T08:10:49,625 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void com.metamx.metrics.MonitorScheduler.stop()] on object[com.metamx.metrics.MonitorScheduler@6a3fbcb1].
2018-08-02T08:10:49,625 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.query.lookup.LookupReferencesManager.stop()] on object[io.druid.query.lookup.LookupReferencesManager@a54acec].
2018-08-02T08:10:49,625 INFO [main] io.druid.query.lookup.LookupReferencesManager - LookupReferencesManager is stopping.
2018-08-02T08:10:49,625 INFO [LookupReferencesManager-MainThread] io.druid.query.lookup.LookupReferencesManager - Lookup Management loop exited, Lookup notices are not handled anymore.
2018-08-02T08:10:49,625 INFO [main] io.druid.query.lookup.LookupReferencesManager - LookupReferencesManager is stopped.
2018-08-02T08:10:49,625 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.discovery.DruidLeaderClient.stop()] on object[io.druid.discovery.DruidLeaderClient@f613067].
2018-08-02T08:10:49,626 INFO [main] io.druid.discovery.DruidLeaderClient - Stopped.
2018-08-02T08:10:49,626 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.curator.discovery.ServerDiscoverySelector.stop() throws java.io.IOException] on object[io.druid.curator.discovery.ServerDiscoverySelector@778a1250].
2018-08-02T08:10:49,626 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider.stop()] on object[io.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider@656a3d6b].
2018-08-02T08:10:49,626 INFO [main] io.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider - stopping
2018-08-02T08:10:49,626 INFO [main] io.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider - stopped
2018-08-02T08:10:49,626 INFO [main] com.metamx.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void com.metamx.http.client.NettyHttpClient.stop()] on object[com.metamx.http.client.NettyHttpClient@322204dc].
2018-08-02T08:10:49,663 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void com.metamx.emitter.service.ServiceEmitter.close() throws java.io.IOException] on object[ServiceEmitter{serviceDimensions={service=druid/middleManager, host=t1-data-druid:8101, version=0.11.0}, emitter=LoggingEmitter{log=com.metamx.common.logger.Logger@47a7a101, level=INFO}}].
2018-08-02T08:10:49,663 INFO [main] com.metamx.emitter.core.LoggingEmitter - Close: started [false]
2018-08-02T08:10:49,663 INFO [main] io.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking stop method[public void io.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner.stop()] on object[io.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner@45292ec1].
Heap
 garbage-first heap   total 524288K, used 200191K [0x00000000e0000000, 0x00000000e0101000, 0x0000000100000000)
  region size 1024K, 197 young (201728K), 29 survivors (29696K)
 Metaspace       used 45873K, capacity 46502K, committed 46848K, reserved 1089536K
  class space    used 5872K, capacity 6065K, committed 6144K, reserved 1048576K

There is no useful plus message.

terry19850829 commented 6 years ago

When I remove the javascript aggr, the supervisor just works and the datasource generated.

stale[bot] commented 5 years ago

This issue has been marked as stale due to 280 days of inactivity. It will be closed in 2 weeks if no further activity occurs. If this issue is still relevant, please simply write any comment. Even if closed, you can still revive the issue at any time or discuss it on the dev@druid.apache.org list. Thank you for your contributions.

stale[bot] commented 4 years ago

This issue has been marked as stale due to 280 days of inactivity. It will be closed in 4 weeks if no further activity occurs. If this issue is still relevant, please simply write any comment. Even if closed, you can still revive the issue at any time or discuss it on the dev@druid.apache.org list. Thank you for your contributions.