jtuglu-netflix commented on code in PR #18060:
URL: https://github.com/apache/druid/pull/18060#discussion_r2138984987
##########
indexing-service/src/main/java/org/apache/druid/indexing/overlord/TaskQueue.java:
##########
@@ -1052,21 +1044,43 @@ public Map<String, Task>
getActiveTasksForDatasource(String datasource)
);
}
+ private void emitTaskCompletionLogsAndMetrics(final Task task, final
TaskStatus status)
+ {
+ if (status.isComplete()) {
+ final ServiceMetricEvent.Builder metricBuilder =
ServiceMetricEvent.builder();
+ IndexTaskUtils.setTaskDimensions(metricBuilder, task);
+ IndexTaskUtils.setTaskStatusDimensions(metricBuilder, status);
+
+ emitter.emit(metricBuilder.setMetric("task/run/time",
status.getDuration()));
+
+ log.info(
+ "Completed task[%s] with status[%s] in [%d]ms.",
+ task.getId(), status.getStatusCode(), status.getDuration()
+ );
Review Comment:
I think we can move a log to the end of the `notifyStatus` so it's a good
timestamp marker for when the operations completed.
I also think we should keep this log where it is, since there's a potential
for not logging the proper status/duration in the case of a callback losing the
race to a shutdown.
This way, perhaps only at the expense of lots of logs, we get:
- Timestamp recording when the single notifyStatus completes, and what
task/status it completed with
- Timestamp recording when the completion hook is totally over (resources
are freed + metrics are emitted).
##########
indexing-service/src/main/java/org/apache/druid/indexing/overlord/TaskQueue.java:
##########
@@ -1052,21 +1044,43 @@ public Map<String, Task>
getActiveTasksForDatasource(String datasource)
);
}
+ private void emitTaskCompletionLogsAndMetrics(final Task task, final
TaskStatus status)
+ {
+ if (status.isComplete()) {
+ final ServiceMetricEvent.Builder metricBuilder =
ServiceMetricEvent.builder();
+ IndexTaskUtils.setTaskDimensions(metricBuilder, task);
+ IndexTaskUtils.setTaskStatusDimensions(metricBuilder, status);
+
+ emitter.emit(metricBuilder.setMetric("task/run/time",
status.getDuration()));
+
+ log.info(
+ "Completed task[%s] with status[%s] in [%d]ms.",
+ task.getId(), status.getStatusCode(), status.getDuration()
+ );
Review Comment:
I think we can move a log to the end of the `notifyStatus` so it's a good
timestamp marker for when the operations completed.
I also think we should keep this log where it is, since there's a potential
for not logging the proper status/duration in the case of a callback losing the
race to a shutdown.
This way, perhaps only at the expense of extra logs, we get:
- Timestamp recording when the single notifyStatus completes, and what
task/status it completed with
- Timestamp recording when the completion hook is totally over (resources
are freed + metrics are emitted).
--
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]
