[
https://issues.apache.org/jira/browse/NIFI-7811?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Matt Burgess updated NIFI-7811:
-------------------------------
Affects Version/s: (was: 1.11.4)
Status: Patch Available (was: In Progress)
> PrometheusReportingTask starts even if there's a port clash and it cannot
> possibly work (and the logs are unhelpful)
> --------------------------------------------------------------------------------------------------------------------
>
> Key: NIFI-7811
> URL: https://issues.apache.org/jira/browse/NIFI-7811
> Project: Apache NiFi
> Issue Type: Bug
> Components: Core Framework
> Reporter: Chris Sampson
> Assignee: Matt Burgess
> Priority: Major
> Time Spent: 10m
> Remaining Estimate: 0h
>
> A PrometheusReportingTask that would be unable to work properly (e.g. due to
> a port clash within an environment) successfully enables and continues to try
> operating even when it cannot realistically report metrics.
> The logs that appear during the scheduled executions are also very unhelpful:
> {quote}
> 2020-09-15 13:10:43,007 ERROR [Timer-Driven Process Thread-6]
> o.a.n.r.p.PrometheusReportingTask
> PrometheusReportingTask[id=91e352aa-0174-1000-ffff-ffffd5947ec5] Error
> running task PrometheusReportingTask[id=91e352aa-0174-1000-ffff-ffffd5947ec5]
> due to java.lang.NullPointerException
> {quote}
> The easiest way I've found to replicate this is to configure two identical
> PrometheusReportingTasks in the same NiFi instance (e.g. both using the
> default port of 9092).
> Note that on initial startup of the second task, the following logs do appear
> (but can easily be missed):
> {code:java}
> 2020-09-15 13:10:43,006 ERROR [Timer-Driven Process Thread-5]
> o.a.n.r.p.PrometheusReportingTask
> PrometheusReportingTask[id=91e352aa-0174-1000-ffff-ffffd5947ec5] Failed to
> start Jetty server: java.io.IOException: Failed to bind to /0.0.0.0:9092
> java.io.IOException: Failed to bind to /0.0.0.0:9092
> at
> org.eclipse.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:346)
> at
> org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:308)
> at
> org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
> at
> org.eclipse.jetty.server.ServerConnector.doStart(ServerConnector.java:236)
> at
> org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
> at org.eclipse.jetty.server.Server.doStart(Server.java:396)
> at
> org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
> at
> org.apache.nifi.reporting.prometheus.PrometheusServer.<init>(PrometheusServer.java:92)
> at
> org.apache.nifi.reporting.prometheus.PrometheusReportingTask.onScheduled(PrometheusReportingTask.java:100)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:142)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:130)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:75)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotation(ReflectionUtils.java:52)
> at
> org.apache.nifi.controller.scheduling.StandardProcessScheduler$2.run(StandardProcessScheduler.java:222)
> at org.apache.nifi.engine.FlowEngine$2.run(FlowEngine.java:110)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.net.BindException: Address already in use
> at sun.nio.ch.Net.bind0(Native Method)
> at sun.nio.ch.Net.bind(Net.java:433)
> at sun.nio.ch.Net.bind(Net.java:425)
> at
> sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
> at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:85)
> at
> org.eclipse.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:342)
> ... 25 common frames omitted
> {code}
> Also, when subsequently stopping the task:
> {code:java}
> 2020-09-15 13:13:26,091 ERROR [Timer-Driven Process Thread-8]
> org.apache.nifi.util.ReflectionUtils Failed while invoking annotated method
> 'public void
> org.apache.nifi.reporting.prometheus.PrometheusReportingTask.OnStopped()
> throws java.lang.Exception' with arguments '[]'.
> java.lang.reflect.InvocationTargetException: null
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:142)
> at
> org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:130)
> at
> org.apache.nifi.util.ReflectionUtils.quietlyInvokeMethodsWithAnnotations(ReflectionUtils.java:268)
> at
> org.apache.nifi.util.ReflectionUtils.quietlyInvokeMethodsWithAnnotation(ReflectionUtils.java:90)
> at
> org.apache.nifi.controller.scheduling.StandardProcessScheduler$3.run(StandardProcessScheduler.java:286)
> at org.apache.nifi.engine.FlowEngine$2.run(FlowEngine.java:110)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.lang.NullPointerException: null
> at
> org.apache.nifi.reporting.prometheus.PrometheusReportingTask.OnStopped(PrometheusReportingTask.java:140)
> ... 17 common frames omitted
> {code}
> It would seem sensible to either (or both):
> * Prevent the task from being enabled in the first place (if it cannot
> possibly report its metrics)
> * Improve the logging such that when the task executes on schedule it logs
> something more meaningful
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
