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.
