search

apache / pinot

Apache Pinot - A realtime distributed OLAP datastore
https://pinot.apache.org/
Apache License 2.0
5.45k stars 1.28k forks source link

Execessive warnings starting up with ServiceManager #5974

Open codefromthecrypt opened 4 years ago

codefromthecrypt commented 4 years ago

When composing Pinot with other services, it looks bad because a lot of warnings spit out. It seems dangerous to turn off loggers, so raising as an issue:

pinot                           | Starting Pinot Service Manager
pinot                           | WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
pinot                           | WARNING: An illegal reflective access operation has occurred
pinot                           | WARNING: Illegal reflective access by org.apache.pinot.spi.plugin.PluginClassLoader (file:/opt/pinot/classes/) to method java.net.URLClassLoader.addURL(java.net.URL)
pinot                           | WARNING: Please consider reporting this to the maintainers of org.apache.pinot.spi.plugin.PluginClassLoader
pinot                           | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
pinot                           | WARNING: All illegal access operations will be denied in a future release
pinot                           | 00:08:32,480 INFO  [main] command.StartServiceManagerCommand (StartServiceManagerCommand.java:164) - Executing command: StartServiceManager -clusterName hypertrace-views -zkAddress zookeeper:2181 -port 7098 -bootstrapConfigPaths [etc/pinot-controller.conf, etc/pinot-broker.conf, etc/pinot-server.conf]
pinot                           | 00:08:32,487 INFO  [main] command.StartServiceManagerCommand (StartServiceManagerCommand.java:285) - Starting a Pinot [SERVICE_MANAGER] at 0.012s since launch
pinot                           | Sep 04, 2020 12:08:33 AM org.glassfish.grizzly.http.server.NetworkListener start
pinot                           | INFO: Started listener bound to [0.0.0.0:7098]
pinot                           | Sep 04, 2020 12:08:33 AM org.glassfish.grizzly.http.server.HttpServer start
pinot                           | INFO: [HttpServer] Started.
pinot                           | 00:08:38,197 INFO  [main] command.StartServiceManagerCommand (StartServiceManagerCommand.java:287) - Started Pinot [SERVICE_MANAGER] instance [ServiceManager_0de922b6d43c_7098] at 5.723s since launch
pinot                           | 00:08:38,252 INFO  [main] command.StartServiceManagerCommand (StartServiceManagerCommand.java:285) - Starting a Pinot [CONTROLLER] at 5.778s since launch
pinot                           | 00:08:39,562 WARN  [ZkClient-EventThread-35-zookeeper:2181] zk.ZkBaseDataAccessor (ZkBaseDataAccessor.java:142) - Node already exists. path: /hypertrace-views/CONTROLLER/LEADER
pinot                           | 00:08:39,579 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.messaging.handling.HelixTaskExecutor@42f3156d, path: /hypertrace-views/CONTROLLER/MESSAGES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,580 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/CONTROLLER, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,581 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/CONFIGS/PARTICIPANT, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,581 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/CONFIGS/RESOURCE, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,582 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/CONFIGS/CLUSTER/hypertrace-views, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,582 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/LIVEINSTANCES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,583 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.controller.GenericHelixController@1ce61929, path: /hypertrace-views/IDEALSTATES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:39,750 WARN  [main] helix.ConfigAccessor (ConfigAccessor.java:650) - No config found at /hypertrace-views/CONFIGS/RESOURCE/leadControllerResource
pinot                           | 00:08:39,838 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,839 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,839 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,840 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,843 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,844 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,844 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,844 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,846 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,846 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,847 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,847 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,848 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,849 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,849 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,851 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,851 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,851 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,852 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,852 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,852 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,853 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,854 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,854 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.
pinot                           | 00:08:39,883 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:39,888 WARN  [HelixController-pipeline-default-hypertrace-views-(a74a56b8_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:39,888 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event a74a56b8_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:39,957 WARN  [HelixController-pipeline-default-hypertrace-views-(b0091713_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:39,957 WARN  [HelixController-pipeline-default-hypertrace-views-(b0091713_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event b0091713_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:39,958 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event b0091713_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:40,002 WARN  [HelixController-pipeline-default-hypertrace-views-(fdb2f105_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:40,002 WARN  [HelixController-pipeline-default-hypertrace-views-(fdb2f105_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event fdb2f105_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:40,003 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event fdb2f105_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:40,073 WARN  [main] healthcheck.ParticipantHealthReportTask (ParticipantHealthReportTask.java:75) - ParticipantHealthReportTimerTask already stopped
pinot                           | 00:08:40,185 WARN  [HelixController-pipeline-default-hypertrace-views-(b377acaa_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:40,186 WARN  [HelixController-pipeline-default-hypertrace-views-(b377acaa_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event b377acaa_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:40,187 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event b377acaa_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:40,266 WARN  [main] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.messaging.handling.HelixTaskExecutor@70e29e14, path: /hypertrace-views/INSTANCES/Controller_0de922b6d43c_9000/MESSAGES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:40,296 WARN  [HelixController-pipeline-default-hypertrace-views-(49e8ed50_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:40,297 WARN  [HelixController-pipeline-default-hypertrace-views-(49e8ed50_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event 49e8ed50_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:40,297 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event 49e8ed50_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:40,385 WARN  [HelixController-pipeline-default-hypertrace-views-(cabdc9ac_DEFAULT)] rebalancer.AutoRebalancer (AutoRebalancer.java:109) - Resource leadControllerResource has tag controller but no configured participants have this tag
pinot                           | 00:08:40,385 WARN  [HelixController-pipeline-default-hypertrace-views-(cabdc9ac_DEFAULT)] controller.LogUtil (LogUtil.java:11) - Event cabdc9ac_DEFAULT : Failed to calculate best possible states for leadControllerResource
pinot                           | 00:08:40,386 WARN  [HelixController-async_tasks-hypertrace-views] controller.LogUtil (LogUtil.java:11) - Event cabdc9ac_DEFAULT : Failed to calculate best possible states for 1 resources.
pinot                           | 00:08:41,125 WARN  [ZkClient-EventThread-53-zookeeper:2181] zk.ZkBaseDataAccessor (ZkBaseDataAccessor.java:410) - Fail to read record for paths: {/hypertrace-views/INSTANCES/Controller_0de922b6d43c_9000/MESSAGES/df515304-0ab1-416f-8217-46bd97f8c96b=-101, /hypertrace-views/INSTANCES/Controller_0de922b6d43c_9000/MESSAGES/a09c90bc-81ea-4c7c-9cbd-44b815efdfc5=-101}
pinot                           | Sep 04, 2020 12:08:41 AM org.glassfish.grizzly.http.server.NetworkListener start
pinot                           | INFO: Started listener bound to [0.0.0.0:9000]
pinot                           | Sep 04, 2020 12:08:41 AM org.glassfish.grizzly.http.server.HttpServer start
pinot                           | INFO: [HttpServer-1] Started.
pinot                           | 00:08:43,966 INFO  [main] command.StartServiceManagerCommand (StartServiceManagerCommand.java:287) - Started Pinot [CONTROLLER] instance [Controller_0de922b6d43c_9000] at 11.492s since launch
pinot                           | 00:08:43,968 INFO  [Start a Pinot [BROKER]] command.StartServiceManagerCommand (StartServiceManagerCommand.java:285) - Starting a Pinot [BROKER] at 11.494s since launch
pinot                           | 00:08:43,968 INFO  [Start a Pinot [SERVER]] command.StartServiceManagerCommand (StartServiceManagerCommand.java:285) - Starting a Pinot [SERVER] at 11.494s since launch
pinot                           | 00:08:44,064 WARN  [Start a Pinot [SERVER]] healthcheck.ParticipantHealthReportTask (ParticipantHealthReportTask.java:75) - ParticipantHealthReportTimerTask already stopped
pinot                           | Sep 04, 2020 12:08:44 AM org.glassfish.grizzly.http.server.NetworkListener start
pinot                           | INFO: Started listener bound to [0.0.0.0:8099]
pinot                           | Sep 04, 2020 12:08:44 AM org.glassfish.grizzly.http.server.HttpServer start
pinot                           | INFO: [HttpServer-2] Started.
pinot                           | 00:08:44,377 WARN  [Start a Pinot [SERVER]] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.messaging.handling.HelixTaskExecutor@3fe2460, path: /hypertrace-views/INSTANCES/Server_0de922b6d43c_8098/MESSAGES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | Sep 04, 2020 12:08:44 AM org.glassfish.grizzly.http.server.NetworkListener start
pinot                           | INFO: Started listener bound to [0.0.0.0:8097]
pinot                           | Sep 04, 2020 12:08:44 AM org.glassfish.grizzly.http.server.HttpServer start
pinot                           | INFO: [HttpServer-3] Started.
pinot                           | 00:08:47,584 WARN  [Start a Pinot [BROKER]] healthcheck.ParticipantHealthReportTask (ParticipantHealthReportTask.java:75) - ParticipantHealthReportTimerTask already stopped
pinot                           | 00:08:47,803 WARN  [Start a Pinot [BROKER]] zk.CallbackHandler (CallbackHandler.java:350) - Callback handler received event in wrong order. Listener: org.apache.helix.messaging.handling.HelixTaskExecutor@4d970008, path: /hypertrace-views/INSTANCES/Broker_0de922b6d43c_8099/MESSAGES, expected types: [CALLBACK, FINALIZE] but was INIT
pinot                           | 00:08:47,848 INFO  [Start a Pinot [BROKER]] command.StartServiceManagerCommand (StartServiceManagerCommand.java:287) - Started Pinot [BROKER] instance [Broker_0de922b6d43c_8099] at 15.374s since launch
pinot                           | 00:08:48,001 INFO  [Start a Pinot [SERVER]] command.StartServiceManagerCommand (StartServiceManagerCommand.java:287) - Started Pinot [SERVER] instance [Server_0de922b6d43c_8098] at 15.527s since launch
codefromthecrypt commented 4 years ago

All of these are helix except the Illegal reflective access by org.apache.pinot.spi.plugin.PluginClassLoader