As the stracktrace says, class cast exception occurs here:
https://github.com/apache/flink/blob/master/flink-connectors/flink-connector-kafka/src/main/java/org/apache/flink/streaming/connectors/kafka/internals/metrics/KafkaMetricMutableWrapper.java#L37
I found the following metrics to be affected (might be more):
MetricName [name=version, group=app-info, description=Metric
indicating version, tags={client-id=producer-3}]
-> value: "6.2.2-ccs" (String)
MetricName [name=start-time-ms, group=app-info, description=Metric
indicating start-time-ms, tags={client-id=producer-3}]
-> value: 1651654724987 (Long)
MetricName [name=commit-id, group=app-info, description=Metric
indicating commit-id, tags={client-id=producer-3}]
-> value: "2ceb5dc7891720b7" (String)
Problematic code part seems to be introduced with "Bump Kafka version
to 2.8":
https://github.com/apache/flink/commit/b367407d08b6dd69a52886a1c6232a9d8ee2ec0a#diff-bb47c4c2d77fd57da49a6cf5227d43ba352c2ea916776bdae92a7436dea50068
Is this a potential bug introduced in 1.15.0?
Best, Peter
On Wed, May 4, 2022 at 9:58 AM Peter Schrott <pe...@bluerootlabs.io>
wrote:
Sorry for the spamming!
Just after jumping into the debug-session I noticed that there
are indeed exceptions thrown when fetching the metrics on port 9200:
13657 INFO [ScalaTest-run]com.sun.net.httpserver - HttpServer created
http0.0.0.0/0.0.0.0:9200 13658 INFO [ScalaTest-run]com.sun.net.httpserver -
context created: /
13658 INFO [ScalaTest-run]com.sun.net.httpserver - context created:
/metrics
13659 INFO [ScalaTest-run]o.a.f.m.p.PrometheusReporter - Started
PrometheusReporter HTTP server on port9200.
13745 DEBUG [prometheus-http-1-1]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
14028 DEBUG [prometheus-http-1-2]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
14998 DEBUG [prometheus-http-1-3]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
15580 DEBUG [prometheus-http-1-4]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
16022 DEBUG [prometheus-http-1-5]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
16458 DEBUG [prometheus-http-1-1]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
16885 DEBUG [prometheus-http-1-2]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
17381 DEBUG [prometheus-http-1-3]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
17809 DEBUG [prometheus-http-1-4]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
18259 DEBUG [prometheus-http-1-5]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
18695 DEBUG [prometheus-http-1-1]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
19159 DEBUG [prometheus-http-1-2]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
19758 DEBUG [prometheus-http-1-3]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
20112 DEBUG [prometheus-http-1-4]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
20544 DEBUG [prometheus-http-1-5]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
20989 DEBUG [prometheus-http-1-1]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
21419 DEBUG [prometheus-http-1-2]o.a.f.m.p.PrometheusReporter - Invalid
type for
Gaugeorg.apache.flink.runtime.checkpoint.CheckpointStatsTracker$LatestCompletedCheckpointExternalPathGauge@3fae55e7:java.lang.String,
only number types and booleans are supported by this reporter.
21421 DEBUG [prometheus-http-1-2]com.sun.net.httpserver - GET / HTTP/1.1
[200 OK] ()
21847 DEBUG [prometheus-http-1-3]o.a.f.m.p.PrometheusReporter - Invalid
type for
Gaugeorg.apache.flink.connector.kafka.source.metrics.KafkaSourceReaderMetrics$$Lambda$4076/388206242@78846648:java.lang.String,
only number types and booleans are supported by this reporter.
21851 DEBUG [prometheus-http-1-3]com.sun.net.httpserver
-ServerImpl.Exchange (2)
java.lang.ClassCastException:java.lang.Long cannot be cast
tojava.lang.Double at
org.apache.flink.streaming.connectors.kafka.internals.metrics.KafkaMetricMutableWrapper.getValue(KafkaMetricMutableWrapper.java:37)
at
org.apache.flink.streaming.connectors.kafka.internals.metrics.KafkaMetricMutableWrapper.getValue(KafkaMetricMutableWrapper.java:27)
at
org.apache.flink.metrics.prometheus.AbstractPrometheusReporter$2.get(AbstractPrometheusReporter.java:262)
at io.prometheus.client.Gauge.collect(Gauge.java:317) at
io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.findNextElement(CollectorRegistry.java:190)
at
io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.nextElement(CollectorRegistry.java:223)
at
io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.nextElement(CollectorRegistry.java:144)
at
io.prometheus.client.exporter.common.TextFormat.write004(TextFormat.java:22)
at
io.prometheus.client.exporter.HTTPServer$HTTPMetricHandler.handle(HTTPServer.java:60)
at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)
at sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:83) at
com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:82) at
sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:675)
at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)
at
sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:647)
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) 21851 TRACE
[prometheus-http-1-3]com.sun.net.httpserver - Closing
connection:java.nio.channels.SocketChannel[connected local=/127.0.0.1:9200
remote=/127.0.0.1:50508]
For my defence: This jul - slf4j - logback setup is really nasty :O
Best, Peter
On Wed, May 4, 2022 at 9:47 AM Peter Schrott
<pe...@bluerootlabs.io> wrote:
Hi Chesnay,
Thanks for that support! Just for compilation: Running the
"Problem-Job" locally as test in Intellij (as Chesney
suggested above) reproduces the described problem:
➜ ~ curl localhost:9200
curl: (52) Empty reply from server
Doing the same with other jobs metrics are available on
localhost:9200.
One other thing I noticed yesterday in the cluster is that
job/task specific metrics are available for a very short time
after the job is started (for around a few seconds). E.g:
# HELP flink_taskmanager_job_task_backPressuredTimeMsPerSecond
backPressuredTimeMsPerSecond (scope: taskmanager_job_task)
After all tasks are "green" in the webui, the "empty reply
from server" is back.
1)
I changed the prometheus config in my cluster, but as you
saied, it does not have any impact.
2)
For the logging in a test scenario, I also had to add the
following lines in my test class:
SLF4JBridgeHandler.removeHandlersForRootLogger()
SLF4JBridgeHandler.install()
(source:
https://www.slf4j.org/api/org/slf4j/bridge/SLF4JBridgeHandler.html)
As well as resetting log levels for jul in my logback.xml:
<contextListener
class="ch.qos.logback.classic.jul.LevelChangePropagator">
<resetJUL>true</resetJUL> </contextListener>
This infos just for completeness, if someone else stumbles upon.
I set the following loggers to lvl TRACE:
<logger name="com.sun.net.httpserver" level="TRACE"
additive="false"> <appender-ref ref="ASYNC_FILE" /> </logger>
<logger name="org.apache.flink.metrics.prometheus"
level="TRACE" additive="false"> <appender-ref
ref="ASYNC_FILE" /> </logger> <logger
name="io.prometheus.client" level="TRACE" additive="false">
<appender-ref ref="ASYNC_FILE" /> </logger>
When running the job in a local test as suggested above I get
the following log messages:
12701 INFO [ScalaTest-run]com.sun.net.httpserver - HttpServer
created http0.0.0.0/0.0.0.0:9200 12703 INFO
[ScalaTest-run]com.sun.net.httpserver - context created: /
12703 INFO [ScalaTest-run]com.sun.net.httpserver - context created:
/metrics
12704 INFO [ScalaTest-run]o.a.f.m.p.PrometheusReporter - Started
PrometheusReporter HTTP server on port9200.
3)
I have not tried to reproduce in a local cluster yet, as the
issue is also reproducible in the test environment. But
thanks for the hint - could be very helpful!
__
From the observations it does not seem like there is a
problem with the http server itself. I am just making
assumptions: It feels like there is a problem with reading
and providing the metrics. As the issue reproducible in the
local setup I have the comfy option to debug in Intellij now
- I'll spend my day with this if no other hints or ideas arise.
Thanks & Best, Peter
On Tue, May 3, 2022 at 4:01 PM Chesnay Schepler
<ches...@apache.org> wrote:
> I noticed that my config of the PrometheusReporter is
different here. I have: `metrics.reporter.prom.class:
org.apache.flink.metrics.prometheus.PrometheusReporter`.
I will investigate if this is a problem.
That's not a problem.
> Which trace logs are interesting?
The logging config I provided should highlight the
relevant bits (com.sun.net.httpserver).
At least in my local tests this is where any interesting
things were logged.
Note that this part of the code uses java.util.logging,
not slf4j/log4j.
> When running a local flink (start-cluster.sh), I do not
have a certain url/port to access the taskmanager, right?
If you configure a port range it should be as simple as
curl localhost:<port>.
You can find the used port in the taskmanager logs.
Or just try the first N ports in the range ;)
On 03/05/2022 14:11, Peter Schrott wrote:
Hi Chesnay,
Thanks for the code snipped. Which trace logs are
interesting? Of
"org.apache.flink.metrics.prometheus.PrometheusReporter"?
I could also add this logger settings in the environment
where the problem is present.
Other than that, I am not sure how to reproduce this
issue in a local setup. In the cluster where the metrics
are missing I am navigating to the certain taskmanager
and try to access the metrics via the configured
prometheus port. When running a local flink
(start-cluster.sh), I do not have a certain url/port to
access the taskmanager, right?
I noticed that my config of the PrometheusReporter is
different here. I have: `metrics.reporter.prom.class:
org.apache.flink.metrics.prometheus.PrometheusReporter`.
I will investigate if this is a problem.
Unfortunately I can not provide my job at the moment. It
contains business logic and it is tightly coupled with
our Kafka systems. I will check the option of creating a
sample job to reproduce the problem.
Best, Peter
On Tue, May 3, 2022 at 12:48 PM Chesnay Schepler
<ches...@apache.org> wrote:
You'd help me out greatly if you could provide me
with a sample job that runs into the issue.
So far I wasn't able to reproduce the issue,
but it should be clear that there is some given 3
separate reports,
although it is strange that so far it was only
reported for Prometheus.
If one of you is able to reproduce the issue within
a Test and is feeling adventurous,
then you might be able to get more information by
forwarding the java.util.logging
to SLF4J. Below is some code to get you started.
DebuggingTest.java:
class DebuggingTest {
static {
LogManager.getLogManager().getLogger("").setLevel(Level.FINEST);
SLF4JBridgeHandler.removeHandlersForRootLogger();
SLF4JBridgeHandler.install();
miniClusterExtension =
new MiniClusterExtension(
new
MiniClusterResourceConfiguration.Builder()
.setConfiguration(getConfiguration())
.setNumberSlotsPerTaskManager(1)
.build());
}
@RegisterExtension private static final
MiniClusterExtension miniClusterExtension;
private static Configuration getConfiguration() {
final Configuration configuration = new
Configuration();
configuration.setString(
"metrics.reporter.prom.factory.class",
PrometheusReporterFactory.class.getName());
configuration.setString("metrics.reporter.prom.port",
"9200-9300");
return configuration;
}
@Test
void runJob() throws Exception {
<run job>
}
}
pom.xml:
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jul-to-slf4j</artifactId>
<version>1.7.32</version>
</dependency>
log4j2-test.properties:
rootLogger.level = off
rootLogger.appenderRef.test.ref = TestLogger
logger.http.name <http://logger.http.name> =
com.sun.net.httpserver
logger.http.level = trace
appender.testlogger.name <http://appender.testlogger.name> =
TestLogger
appender.testlogger.type = CONSOLE
appender.testlogger.target = SYSTEM_ERR
appender.testlogger.layout.type = PatternLayout
appender.testlogger.layout.pattern = %-4r [%t] %-5p %c %x - %m%n
On 03/05/2022 10:41, ChangZhuo Chen (陳昌倬) wrote:
On Tue, May 03, 2022 at 10:32:03AM +0200, Peter Schrott wrote:
Hi!
I also discovered problems with the PrometheusReporter on Flink
1.15.0,
coming from 1.14.4. I already consulted the mailing list:
https://lists.apache.org/thread/m8ohrfkrq1tqgq7lowr9p226z3yc0fgc
I have not found the underlying problem or a solution to it.
Actually, after re-checking, I see the same log WARNINGS as
ChangZhou described.
As I described, it seems to be an issue with my job. If no job,
or an
example job runs on the taskmanager the basic metrics work just
fine. Maybe
ChangZhou can confirm this?
@ChangZhou what's your job setup? I am running a streaming SQL
job, but
also using data streams API to create the streaming environment
and from
that the table environment and finally using a StatementSet to
execute
multiple SQL statements in one job.
We are running a streaming application with low level API with
Kubernetes operator FlinkDeployment.
