dongjoon-hyun commented on code in PR #918:
URL:
https://github.com/apache/spark-kubernetes-operator/pull/918#discussion_r4186033306
##########
spark-operator/src/main/java/org/apache/spark/k8s/operator/metrics/source/KubernetesMetricsInterceptor.java:
##########
@@ -102,21 +122,30 @@ public void before(BasicBuilder builder, HttpRequest
request, RequestTags tags)
}
/**
- * Called after a non-WebSocket HTTP response is received. The body might or
might not be already
- * consumed.
+ * Called after an HTTP response is received. The body might or might not be
already consumed.
*
* <p>Should be used to analyze response codes and headers, original
response shouldn't be
* altered.
*
+ * <p>fabric8 also calls this for a WebSocket upgrade response with a {@code
null} consumer, and
+ * again for an HTTP request re-sent after {@link
#afterFailure(BasicBuilder, HttpResponse,
+ * RequestTags)}. The latency of a re-sent response is measured from the
previous response.
+ *
* @param request the original request sent to the server.
* @param response the response received from the server.
+ * @param consumer the consumer of the response body, or {@code null} for a
WebSocket upgrade.
*/
@Override
public void after(
HttpRequest request,
HttpResponse<?> response,
AsyncBody.Consumer<List<ByteBuffer>> consumer) {
- updateResponseMetrics(response, System.nanoTime());
+ TimedConsumer timedConsumer = consumer == null ? null :
consumer.unwrap(TimedConsumer.class);
+ if (timedConsumer != null) {
+ long now = System.nanoTime();
+ responseLatency.update(now -
timedConsumer.startTimeNanos().getAndSet(now));
Review Comment:
nit: Now that `getAndSet(...)` changes the start time, every
`KubernetesMetricsInterceptor` on a client shares the same clock. fabric8
passes the same outermost consumer to `after(...)` of all interceptors, and
`unwrap(TimedConsumer.class)` returns the outermost `TimedConsumer` for each of
them. For example, a subclass of `SparkOperator` could override
`getClientInterceptors(...)` and add a subclass of
`KubernetesMetricsInterceptor` next to the default one.
`KubernetesClientFactory` keeps both, since the key is the class name. Then the
second one records only the gap between the two `after(...)` calls. In my test
with 3 GETs delayed by 100 ms, the sums of the two histograms were 433 ms and
0.6 ms, while both recorded the latency correctly with the previous revision.
This is a corner case, so mentioning it in the Javadoc would be enough.
Alternatively, `after(...)` could look for the `TimedConsumer` created by this
instance.
##########
docs/configuration.md:
##########
@@ -259,6 +259,11 @@ has a retry left for it, even if it does not retry it,
e.g. on a request timeout
a client which never retries, i.e. a Kubernetes event write or the recording
of the Kueue
`PodsReady` condition, is not counted there when it gets no response.
+`kubernetes.client.http.response.latency.nanos` ends when the response headers
arrive, so it does
+not include reading the body. A request re-sent after a `401` is measured from
the `401`, whose
Review Comment:
This holds when the token is refreshed synchronously, e.g. with a service
account token file, an exec credential plugin or an `OAuthTokenProvider`. But
with an OIDC auth provider, `TokenRefreshInterceptor#afterFailure` returns the
pending future of `OpenIDConnectionUtils#resolveOIDCTokenFromAuthConfig`, which
calls the IdP with `sendAsync`. Then fabric8 runs `after(...)` of the `401`
before the refresh, and re-sends the request only when the refresh completes.
So the refresh time goes into the latency of the re-sent request instead. In my
test with a 300 ms refresh, a `401` returned after 100 ms was recorded as 105
ms, and the re-sent `200` returned after 50 ms as ~360 ms. With a synchronous
refresh of the same length, they were 410 ms and 54 ms.
The sum of the two values is the same either way. How about describing that
instead? e.g.
> A request re-sent after a `401` is recorded twice, and the two values add
up to the time from sending it until the re-sent response arrives, including
the token refresh.
Could you also align the Javadoc of `after(...)` (L132) and `TimedConsumer`
(L262-263) with it? The same goes for `from sending each HTTP request` in the
migration guide.
##########
spark-operator/src/test/java/org/apache/spark/k8s/operator/metrics/source/KubernetesMetricsInterceptorTest.java:
##########
@@ -125,6 +136,103 @@ void testWhenKubernetesServerNotWorking() {
}
}
+ @Test
+ @Order(3)
+ void testResponseLatency() {
+ KubernetesMetricsInterceptor metricsInterceptor = new
KubernetesMetricsInterceptor();
+ List<Interceptor> interceptors = List.of(metricsInterceptor);
+ try (KubernetesClient client =
+ KubernetesClientFactory.buildKubernetesClient(
+ interceptors, kubernetesClient.getConfiguration())) {
+ ConfigMap configMap = createConfigMap();
+ mockServer
+ .expect()
+ .get()
+ .delay(50)
+ .withPath(CONFIG_MAP_PATH)
+ .andReturn(200, configMap)
+ .once();
+ client.resource(configMap).get();
+
+ Map<String, Metric> map =
metricsInterceptor.metricRegistry().getMetrics();
+ Histogram latency = (Histogram) map.get("http.response.latency.nanos");
Review Comment:
nit: Meters now go through `meterCount(...)`, but the three tests still keep
a `Map<String, Metric>` only for the histogram cast, and the WebSocket test
mixes both styles in one `untilAsserted(...)`. How about
`metricsInterceptor.metricRegistry().getHistograms().get("http.response.latency.nanos")`,
or a helper next to `meterCount(...)`? FYI,
`KubernetesClientFactoryTest#meterCount` has the same name and signature but
creates a missing meter, so a misspelled name returns `0` there and fails here.
##########
spark-operator/src/test/java/org/apache/spark/k8s/operator/metrics/source/KubernetesMetricsInterceptorTest.java:
##########
@@ -125,6 +136,103 @@ void testWhenKubernetesServerNotWorking() {
}
}
+ @Test
+ @Order(3)
+ void testResponseLatency() {
+ KubernetesMetricsInterceptor metricsInterceptor = new
KubernetesMetricsInterceptor();
+ List<Interceptor> interceptors = List.of(metricsInterceptor);
+ try (KubernetesClient client =
+ KubernetesClientFactory.buildKubernetesClient(
+ interceptors, kubernetesClient.getConfiguration())) {
+ ConfigMap configMap = createConfigMap();
+ mockServer
+ .expect()
+ .get()
+ .delay(50)
+ .withPath(CONFIG_MAP_PATH)
+ .andReturn(200, configMap)
+ .once();
+ client.resource(configMap).get();
+
+ Map<String, Metric> map =
metricsInterceptor.metricRegistry().getMetrics();
+ Histogram latency = (Histogram) map.get("http.response.latency.nanos");
+ Assertions.assertEquals(1, latency.getCount());
+ Assertions.assertTrue(latency.getSnapshot().getMax() >= 50_000_000L);
+ Assertions.assertTrue(latency.getSnapshot().getMax() < 30_000_000_000L);
+ }
+ }
+
+ @Test
+ @Order(4)
+ void testResponseLatencyOfResentRequest() {
+ KubernetesMetricsInterceptor metricsInterceptor = new
KubernetesMetricsInterceptor();
+ List<Interceptor> interceptors = List.of(metricsInterceptor);
+ Config config =
+ new ConfigBuilder(kubernetesClient.getConfiguration())
+ .withOauthTokenProvider(() -> "token")
+ .build();
+ try (KubernetesClient client =
+ KubernetesClientFactory.buildKubernetesClient(interceptors, config)) {
+ ConfigMap configMap = createConfigMap();
+ mockServer
+ .expect()
+ .get()
+ .delay(200)
+ .withPath(CONFIG_MAP_PATH)
+ .andReturn(HTTP_UNAUTHORIZED, null)
Review Comment:
nit: The `.delay(200)` works here only because `null` is serialized into the
4-byte body `null`. fabric8 mockwebserver 7.8.0 delays only a non-empty body
(`HttpServerRequestHandler`). With an empty body, the delay would be silently
dropped, and the assertion at L193 would fail with only `expected: <true> but
was: <false>`. How about returning an explicit body, e.g. a `Status` with the
code `401`? Could you also add messages with the snapshot values to the timing
assertions?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
