wenjin272 commented on code in PR #955: URL: https://github.com/apache/flink-agents/pull/955#discussion_r3869538936
########## runtime/src/main/java/org/apache/flink/agents/runtime/metrics/ToolExecutionMetricRecorder.java: ########## @@ -0,0 +1,109 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.flink.agents.runtime.metrics; + +import org.apache.flink.agents.api.trace.ExecutionReporter; +import org.apache.flink.agents.api.trace.ExecutionTraceContext; +import org.apache.flink.agents.api.trace.ToolExecutionMetadataKeys; +import org.apache.flink.metrics.Histogram; + +/** Records Tool metrics and additional Skill and MCP projections. */ +final class ToolExecutionMetricRecorder implements ExecutionMetricRecorder { + + static final String NUM_TOOL_CALLS_SUCCEEDED = "numOfToolCallsSucceeded"; + static final String NUM_TOOL_CALLS_FAILED = "numOfToolCallsFailed"; + static final String TOOL_CALL_LATENCY_MS = "toolCallLatencyMs"; + + static final String NUM_SKILL_LOADS = "numOfSkillLoads"; + static final String SKILL_LOAD_LATENCY_MS = "skillLoadLatencyMs"; + + static final String NUM_MCP_TOOL_CALLS_SUCCEEDED = "numOfMcpToolCallsSucceeded"; + static final String NUM_MCP_TOOL_CALLS_FAILED = "numOfMcpToolCallsFailed"; + static final String MCP_TOOL_CALL_LATENCY_MS = "mcpToolCallLatencyMs"; + + @Override + public String entityType() { + return ExecutionReporter.EntityTypes.TOOL; + } + + @Override + public void record( + FlinkAgentsMetricGroupImpl actionMetricGroup, + ExecutionTraceContext traceContext, + Outcome outcome, + Long latencyMs) { + String toolName = traceContext.getEntityName(); + if (!isBlank(toolName)) { + recordOutcome( + actionMetricGroup.getSubGroup("tool", toolName), Review Comment: `toolName` comes directly from the LLM-generated tool call, and `ToolCallAction` reports lifecycle events even when resource lookup fails. Therefore, every hallucinated or invalid tool name creates a new `tool=<name>` metric group here. Since these groups are not removed, arbitrary model output can cause unbounded metric cardinality and eventually exhaust the task or metrics backend. Please only create per-tool groups for configured tool names and aggregate unknown names into a fixed bucket such as `unknown`. ########## runtime/src/main/java/org/apache/flink/agents/runtime/operator/ActionExecutionOperator.java: ########## @@ -251,35 +251,41 @@ public void processElement(StreamRecord<IN> record) throws Exception { if (record.hasTimestamp()) { inputEvent.setSourceTimestamp(record.getTimestamp()); } + builtInMetrics.markInputEventReceived(inputEvent); - eventRouter.getKeySegmentQueue().addKeyToLastSegment(getCurrentKey()); + Object key = getCurrentKey(); + try { + eventRouter.getKeySegmentQueue().addKeyToLastSegment(key); - if (stateManager.hasMoreActionTasks()) { - // If there are already actions being processed for the current key, the newly incoming - // event should be queued and processed later. Therefore, we add it to - // pendingInputEventsState. - stateManager.addPendingInputEvent(inputEvent); - } else { - // Otherwise, the new event is processed immediately. - processInputEvent(getCurrentKey(), inputEvent); + if (stateManager.hasMoreActionTasks()) { + // If there are already actions being processed for the current key, the newly + // incoming event should be queued and processed later. Therefore, we add it to + // pendingInputEventsState. + enqueuePendingInputEvent(inputEvent); + return; + } + } catch (Exception e) { + builtInMetrics.markInputEventFailed(inputEvent); + throw e; } + + // Otherwise, the new event is processed immediately. Its failures are attributed to the + // input run created by processInputEvent. + processInputEvent(key, inputEvent); } /** Resolves one context key for an input and reuses it for the entire agent run. */ private void processInputEvent(Object key, Event inputEvent) throws Exception { - processEvent(key, resolveContextKey(key), inputEvent); - } - - /** - * Processes an incoming event for the given key and may submit a new mail - * `tryProcessActionTaskForKey` to continue processing. - */ - private void processEvent(Object key, String contextKey, Event event) throws Exception { - processEvent( - key, - contextKey, - event, - ExecutionTraceContext.forInputRun(contextKey, agentPlan.getAgentName())); + String contextKey = resolveContextKey(key); Review Comment: `markInputEventReceived()` has already stored timing for this event, but `resolveContextKey()` can throw, for example while converting a Python key. Because this call runs before `markInputRunStarted()` and outside both failure handlers, such an input is never counted as failed and its entry remains in `receivedInputNanos` until restart. Please catch failures during context-key and trace-context creation and call `markInputEventFailed(inputEvent)`, or include this setup in a broader failure boundary around `processInputEvent()`. ########## runtime/src/main/java/org/apache/flink/agents/runtime/metrics/BuiltInActionMetrics.java: ########## @@ -19,26 +19,123 @@ package org.apache.flink.agents.runtime.metrics; +import org.apache.flink.agents.api.Event; +import org.apache.flink.agents.api.trace.ExecutionLifecycleEvents; +import org.apache.flink.agents.api.trace.ExecutionTraceContext; import org.apache.flink.metrics.Counter; +import org.apache.flink.metrics.Histogram; import org.apache.flink.metrics.Meter; -/** - * ActionMetricGroup class extends FlinkAgentsMetricGroupImpl and is used to monitor and measure the - * performance metrics of executing actions. It provides metrics for the total number of actions - * executed and the number of actions executed per second. - */ +import java.util.HashMap; +import java.util.Map; +import java.util.OptionalLong; +import java.util.concurrent.TimeUnit; +import java.util.function.LongSupplier; + +/** Tracks execution rate, scheduling latency, and current task/execution counts for one Action. */ public class BuiltInActionMetrics { + static final String ACTION_SCHEDULING_LATENCY_MS = "actionSchedulingLatencyMs"; + static final String ACTION_EXECUTION_LATENCY_MS = "actionExecutionLatencyMs"; + static final String NUM_PENDING_ACTION_TASKS = "numOfPendingActionTasks"; + static final String NUM_ACTIVE_ACTION_EXECUTIONS = "numOfActiveActionExecutions"; + private final Meter numOfActionsExecutedPerSec; + private final Histogram schedulingLatencyHistogram; + private final Histogram executionLatencyHistogram; + private final CurrentCountGauge pendingActionTasks; + private final CurrentCountGauge activeActionExecutions; + private final LongSupplier nanoTime; + + private final Map<String, Long> initialTaskEnqueueNanos = new HashMap<>(); + private final Map<String, OptionalLong> activeExecutions = new HashMap<>(); public BuiltInActionMetrics(FlinkAgentsMetricGroupImpl parentMetricGroup) { + this(parentMetricGroup, System::nanoTime); + } + + BuiltInActionMetrics(FlinkAgentsMetricGroupImpl parentMetricGroup, LongSupplier nanoTime) { Counter numOfActionsExecuted = parentMetricGroup.getCounter("numOfActionsExecuted"); this.numOfActionsExecutedPerSec = parentMetricGroup.getMeter("numOfActionsExecutedPerSec", numOfActionsExecuted); + this.schedulingLatencyHistogram = + parentMetricGroup.getHistogram(ACTION_SCHEDULING_LATENCY_MS); + this.executionLatencyHistogram = + parentMetricGroup.getHistogram(ACTION_EXECUTION_LATENCY_MS); + this.pendingActionTasks = + new CurrentCountGauge(parentMetricGroup, NUM_PENDING_ACTION_TASKS); + this.activeActionExecutions = + new CurrentCountGauge(parentMetricGroup, NUM_ACTIVE_ACTION_EXECUTIONS); + this.nanoTime = nanoTime; } /** Marks that an action has finished executing. */ public void markActionExecuted() { numOfActionsExecutedPerSec.markEvent(); } + + void actionTaskEnqueued(String executionId, boolean executionStarted) { + pendingActionTasks.increment(); + if (!executionStarted && !isBlank(executionId)) { + initialTaskEnqueueNanos.putIfAbsent(executionId, nanoTime.getAsLong()); + } + } + + void actionTaskDequeued(String executionId, boolean executionStarted) { + pendingActionTasks.decrement(); + if (executionStarted || isBlank(executionId)) { + return; + } + + Long enqueueNanos = initialTaskEnqueueNanos.remove(executionId); + if (enqueueNanos != null) { + schedulingLatencyHistogram.update( + TimeUnit.NANOSECONDS.toMillis( + Math.max(0L, nanoTime.getAsLong() - enqueueNanos))); + } + } + + void restoreActionTask(String executionId, boolean executionStarted) { + pendingActionTasks.increment(); + if (executionStarted + && !isBlank(executionId) + && activeExecutions.putIfAbsent(executionId, OptionalLong.empty()) == null) { + activeActionExecutions.increment(); + } + } + + void executionEventObserved(Event event, ExecutionTraceContext traceContext) { + String executionId = traceContext.getExecutionId(); + if (isBlank(executionId)) { + return; + } + + if (ExecutionLifecycleEvents.EXECUTION_STARTED_EVENT_TYPE.equals(event.getType())) { + if (activeExecutions.putIfAbsent(executionId, OptionalLong.of(nanoTime.getAsLong())) + == null) { + activeActionExecutions.increment(); + } + return; + } + + if (!ExecutionLifecycleEvents.EXECUTION_FINISHED_EVENT_TYPE.equals(event.getType()) Review Comment: After recovery, `restoreActionTask()` increments `activeActionExecutions` for a restored task whose execution had already started. If durable state shows that the action completed before the failure, the operator emits `execution_reused` instead of `execution_finished` or `execution_failed`. This branch ignores that event, so the restored execution remains in `activeExecutions` and `numOfActiveActionExecutions` never returns to zero. Please handle `execution_reused` as a terminal event and add a restore-to-reused regression test. No latency sample needs to be recorded when the restored start timestamp is unavailable. -- 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]
