dongjoon-hyun commented on code in PR #949:
URL:
https://github.com/apache/spark-kubernetes-operator/pull/949#discussion_r4295962478
##########
docs/migration_guide.md:
##########
@@ -121,6 +121,14 @@ affect building the project, CI, tests or examples.
`0.5` and `0.999` quantiles of the `operator_sdk_*` histograms are the
median and the 99.9th
percentile instead of the mean and the 99th percentile. A histogram or timer
of a custom metrics
source has no `_sum` unless it is a `SummingHistogram` or a `SummingTimer`.
+- Since 1.1.0, the `operator.sdk` metrics source times the controller
executions, i.e. the
Review Comment:
This item says the timers are exported in seconds with a `_duration_seconds`
suffix unconditionally, but that holds only for the default text-based format
(`PrometheusPullModelHandler.formatMetricsSnapshot`).
With
`spark.kubernetes.operator.metrics.prometheusTextBasedFormatEnabled=false`,
`handle()` falls back to Spark's `PrometheusServlet.getMetricsSnapshot`, which
writes timer snapshots as raw nanoseconds, e.g.
`..._50thPercentile{type="timers"} 1.0E7`, without any `_duration_seconds`
suffix. Compared to the whole seconds of 1.0 (`{type="histograms"}`), the
values grow by about 1e9x. Other Spark sinks (JMX, Console, CSV, ...) also
apply their own duration unit to timers now. Could you mention these cases as
well?
##########
docs/migration_guide.md:
##########
@@ -121,6 +121,14 @@ affect building the project, CI, tests or examples.
`0.5` and `0.999` quantiles of the `operator_sdk_*` histograms are the
median and the 99.9th
Review Comment:
After this PR, the `operator.sdk` source has no histograms anymore, since
all of them become timers. So this sentence about the `0.5` and `0.999`
quantiles of the `operator_sdk_*` histograms now refers to metrics which no
longer exist in 1.1.0, and it reads as contradicting the new item below. Shall
we update or merge it into the new item?
##########
spark-operator/src/main/java/org/apache/spark/k8s/operator/metrics/source/OperatorJosdkMetrics.java:
##########
@@ -152,33 +164,37 @@ public <T> T
timeControllerExecution(ControllerExecution<T> execution) throws Ex
getResourceClass(metadata);
final String execName = execution.name();
- long startTime = clock.getTimeMillis();
+ long startTime = clock.nanoTime();
try {
T result = execution.execute();
+ final long durationNanos = clock.nanoTime() - startTime;
Review Comment:
nit: `clock.nanoTime() - startTime` and the paired cluster-wide/namespaced
`getTimer(...).update(durationNanos, TimeUnit.NANOSECONDS)` calls are
duplicated in both the success and the failure branch. A small private helper,
e.g. `recordDuration(metricsPrefix, namespaceOptional, durationNanos, name,
execName, type)`, would keep both branches in sync.
##########
spark-operator/src/main/java/org/apache/spark/k8s/operator/metrics/source/OperatorJosdkMetrics.java:
##########
@@ -152,33 +164,37 @@ public <T> T
timeControllerExecution(ControllerExecution<T> execution) throws Ex
getResourceClass(metadata);
final String execName = execution.name();
- long startTime = clock.getTimeMillis();
+ long startTime = clock.nanoTime();
try {
T result = execution.execute();
+ final long durationNanos = clock.nanoTime() - startTime;
final String successType = execution.successTypeName(result);
if (resourceClass.isPresent()) {
String metricsPrefix = getMetricNamePrefix(resourceClass.get());
- getHistogram(metricsPrefix, name, execName,
successType).update(toSeconds(startTime));
+ getTimer(metricsPrefix, name, execName, successType)
Review Comment:
Switching from `SummingHistogram` to `SummingTimer` adds a `Meter` (EWMA
state) per metric, and `formatTimer` exports 4 more series per metric: a
duplicate `<name>_count` plus `_m1_rate`, `_m5_rate` and `_m15_rate` under `#
TYPE <name> gauge`, whose family name does not match these samples.
Since there is one metric per namespace x controller x execution x outcome,
this increases the number of exported series by about 50% (8 -> 12 per metric)
for an operator watching many namespaces. Is this cardinality increase
intended? If not, keeping a histogram with an explicit nanoseconds-to-seconds
conversion would avoid it.
##########
spark-operator/src/test/java/org/apache/spark/k8s/operator/metrics/source/OperatorJosdkMetricsTest.java:
##########
@@ -68,30 +77,61 @@ void testTimeControllerExecution() throws Exception {
operatorMetrics.timeControllerExecution(successExecution);
Map<String, Metric> metrics =
operatorMetrics.metricRegistry().getMetrics();
assertEquals(4, metrics.size());
- assertInstanceOf(
- SummingHistogram.class,
metrics.get("sparkapplication.test-controller.reconcile.both"));
-
assertTrue(metrics.containsKey("sparkapplication.testns.test-controller.reconcile.both"));
+ // The execution took 10 ms, which is recorded with sub-second precision
in nanoseconds.
+ long durationNanos = Duration.ofMillis(10).toNanos();
+ assertEquals(
+ durationNanos, recordedNanos(metrics,
"sparkapplication.test-controller.reconcile.both"));
+ assertEquals(
+ durationNanos,
+ recordedNanos(metrics,
"sparkapplication.testns.test-controller.reconcile.both"));
assertTrue(metrics.containsKey("sparkapplication.test-controller.reconcile.success.both"));
assertTrue(
metrics.containsKey("sparkapplication.testns.test-controller.reconcile.success.both"));
FooTestingExecutionBase<SparkApplication> failedExecution = new
FooTestingExecutionBase<>();
- try {
- operatorMetrics.timeControllerExecution(failedExecution);
- } catch (Exception e) {
- assertEquals("Foo exception", e.getMessage());
- assertEquals(8, metrics.size());
-
assertTrue(metrics.containsKey("sparkapplication.test-controller.reconcile.failure"));
- assertTrue(
- metrics.containsKey(
- "sparkapplication.test-controller.reconcile.failure.exception"
- + ".nosuchfieldexception"));
-
assertTrue(metrics.containsKey("sparkapplication.testns.test-controller.reconcile.failure"));
- assertTrue(
- metrics.containsKey(
- "sparkapplication.testns.test-controller.reconcile.failure."
- + "exception.nosuchfieldexception"));
+ Exception e =
+ assertThrows(
+ NoSuchFieldException.class,
+ () -> operatorMetrics.timeControllerExecution(failedExecution));
+ assertEquals("Foo exception", e.getMessage());
+ assertEquals(8, metrics.size());
+ long failureNanos = Duration.ofMillis(5).toNanos();
+ assertEquals(
+ failureNanos,
+ recordedNanos(metrics,
"sparkapplication.test-controller.reconcile.failure"));
+ assertTrue(
+ metrics.containsKey(
+ "sparkapplication.test-controller.reconcile.failure.exception"
+ + ".nosuchfieldexception"));
+ assertEquals(
+ failureNanos,
+ recordedNanos(metrics,
"sparkapplication.testns.test-controller.reconcile.failure"));
+ assertTrue(
+ metrics.containsKey(
+ "sparkapplication.testns.test-controller.reconcile.failure."
+ + "exception.nosuchfieldexception"));
+ }
+
+ @Test
+ void testTimeControllerExecutionIsExportedInSeconds() throws Exception {
+ // A namespace containing "nanos" must not affect the exported name or
unit.
+ ResourceID nanosNamespaceResourceId = new ResourceID("spark-pi",
"team-nanos");
+ operatorMetrics.timeControllerExecution(new
TestingExecutionBase<>(nanosNamespaceResourceId));
+ TestingPrometheusPullModelHandler handler =
+ new
TestingPrometheusPullModelHandler(operatorMetrics.metricRegistry());
+
+ String output = handler.snapshot();
+ for (String baseName :
+ new String[] {
+ "sparkapplication_test_controller_reconcile_both_duration_seconds",
+
"sparkapplication_team_nanos_test_controller_reconcile_both_duration_seconds"
+ }) {
+ assertTrue(output.contains("# TYPE " + baseName + " summary\n"), output);
+ assertTrue(output.contains(baseName + "{quantile=\"0.5\"} 0.01\n"),
output);
+ assertTrue(output.contains(baseName + "_count 1\n"), output);
+ assertTrue(output.contains(baseName + "_sum 0.01\n"), output);
}
+ assertFalse(output.contains("team_seconds"), output);
Review Comment:
The `team-nanos` namespace and this `assertFalse` guard against the `_nanos`
-> `_seconds` renaming of `formatHistogram`, but timers never go through that
code path. So this assertion cannot fail with the current design. It looks like
a leftover of the previous nanos-histogram approach. Could we remove the
`team-nanos` scenario, or replace it with an assertion that covers
`formatTimer`?
##########
spark-operator/src/main/java/org/apache/spark/k8s/operator/metrics/source/OperatorJosdkMetrics.java:
##########
@@ -152,33 +164,37 @@ public <T> T
timeControllerExecution(ControllerExecution<T> execution) throws Ex
getResourceClass(metadata);
final String execName = execution.name();
- long startTime = clock.getTimeMillis();
+ long startTime = clock.nanoTime();
try {
T result = execution.execute();
+ final long durationNanos = clock.nanoTime() - startTime;
final String successType = execution.successTypeName(result);
if (resourceClass.isPresent()) {
String metricsPrefix = getMetricNamePrefix(resourceClass.get());
- getHistogram(metricsPrefix, name, execName,
successType).update(toSeconds(startTime));
+ getTimer(metricsPrefix, name, execName, successType)
+ .update(durationNanos, TimeUnit.NANOSECONDS);
getCounter(metricsPrefix, name, execName, SUCCESS, successType).inc();
if (namespaceOptional.isPresent()) {
- getHistogram(metricsPrefix, namespaceOptional.get(), name, execName,
successType)
- .update(toSeconds(startTime));
+ getTimer(metricsPrefix, namespaceOptional.get(), name, execName,
successType)
+ .update(durationNanos, TimeUnit.NANOSECONDS);
getCounter(metricsPrefix, namespaceOptional.get(), name, execName,
SUCCESS, successType)
.inc();
}
}
return result;
} catch (Exception e) {
+ final long durationNanos = clock.nanoTime() - startTime;
Review Comment:
This is not introduced by this PR, but it remains in the touched code: if
`execution.successTypeName(result)` or a metric update in the success branch
throws after `execution.execute()` succeeded, this `catch` block also records
the `failure` timer and counter for the same execution and rethrows, discarding
the successful result. So a single execution can be counted as both a success
and a failure. It may be worth narrowing the `try` to `execution.execute()`
only, maybe as a follow-up.
--
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]
