Problems with Advisors

[shuaidaia]

Why do advisors only return information about calling AI for the second time, and cannot obtain information about calling Tools for the first time, which makes my observabAfter method unable to obtain the name and parameters of the calling tool.
My example:

public class CustomizeLoggerAdvisor implements CallAdvisor, StreamAdvisor {

    private Integer order;

    @NotNull
    @Override
    public String getName() {
        return this.getClass().getSimpleName();
    }

    @Override
    public int getOrder() {
        return null != order ? order : 1;
    }

    private ChatClientRequest before(ChatClientRequest request) {
        log.info("AI Request: {}", request.prompt().getContents());
        log.info("AI Request Message: {}", request.context());
        return request;
    }

    private void observeAfter(ChatClientResponse advisedResponse) {
        ChatResponse response = advisedResponse.chatResponse();
        if (null == response) {
            log.info("AI Response is null");
            return;
        }
        ChatResponseMetadata responseMetadata = response.getMetadata();
        // 输出使用的tokens数
        Usage usage = responseMetadata.getUsage();
        log.info("已使用的总tokens数：{}", usage.getTotalTokens());
        log.info("输入的tokens数：{}", usage.getPromptTokens());
        log.info("输出的tokens数：{}", usage.getCompletionTokens());
        AssistantMessage assistantMessage = response.getResult().getOutput();
        List<AssistantMessage.ToolCall> toolCallList = assistantMessage.getToolCalls();
        // 输出提示信息
        // 抓取不到第一次调用AI所用的工具？
        log.info("选择了 [{}] 个工具来使用", toolCallList.size());
        String toolCallInfo = toolCallList.stream()
                .map(toolCall -> String.format("工具名称：%s，参数：%s", toolCall.name(), toolCall.arguments()))
                .collect(Collectors.joining("\n"));
        log.info(toolCallInfo);
        log.info("AI Response: {}", assistantMessage.getText());
    }

    @NotNull
    @Override
    public ChatClientResponse adviseCall(ChatClientRequest advisedRequest, CallAdvisorChain chain) {
        advisedRequest = this.before(advisedRequest);
        ChatClientResponse advisedResponse = chain.nextCall(advisedRequest);
        this.observeAfter(advisedResponse);
        return advisedResponse;
    }

    @NotNull
    @Override
    public Flux<ChatClientResponse> adviseStream(ChatClientRequest advisedRequest, StreamAdvisorChain chain) {
        advisedRequest = this.before(advisedRequest);
        Flux<ChatClientResponse> advisedResponses = chain.nextStream(advisedRequest);
        return (new ChatClientMessageAggregator()).aggregateChatClientResponse(advisedResponses, this::observeAfter);
    }
}

[checkHup]

I am similar to your example, but I cannot obtain token consumption or call tool names every time

[huidongyin]

你遇到的现象不是Spring AI的bug，而是by design的设计。

1. Advisor的作用范围

从代码分析可以看出，CustomizeLoggerAdvisor（以及所有其他Advisor）的作用范围是ChatClient层面，而不是ChatModel层面。具体来说：
Advisor只拦截ChatClient的调用：你的CustomizeLoggerAdvisor只会在ChatClient的call()方法执行时被触发
Tool调用发生在ChatModel内部：工具调用是在ChatModel的internalCall()或internalStream()方法中进行的，这些调用不会经过Advisor链

2. 工具调用的执行流程

从代码中可以看到，工具调用的流程是这样的：

// 在ChatModel的internalCall方法中
if (this.toolExecutionEligibilityPredicate.isToolExecutionRequired(prompt.getOptions(), response)) {
    var toolExecutionResult = this.toolCallingManager.executeToolCalls(prompt, response);
    if (toolExecutionResult.returnDirect()) {
        // 直接返回工具执行结果
        return ChatResponse.builder()
            .from(response)
            .generations(ToolExecutionResult.buildGenerations(toolExecutionResult))
            .build();
    }
    else {
        // 将工具执行结果发送回模型进行第二次调用
        return this.internalCall(new Prompt(toolExecutionResult.conversationHistory(), prompt.getOptions()),
                response);
    }
}

3. 为什么你的Advisor只看到最终结果

在你的测试中：
第一次调用：AI模型决定使用工具，这个决定被发送到ChatModel内部
工具执行：DefaultToolCallingManager.executeToolCalls()在ChatModel内部执行，不经过Advisor
第二次调用：工具执行结果被发送回AI模型，再次在ChatModel内部处理，不经过Advisor
最终结果：只有最终的ChatResponse才会通过Advisor链返回给客户端

4. 这是设计上的考虑

这种设计是合理的，因为：
性能考虑：工具调用通常是同步的，不需要经过复杂的Advisor链处理
职责分离：Advisor主要用于处理客户端层面的逻辑（如日志、内存管理等），而工具调用是模型层面的功能
简化架构：避免在工具调用过程中引入额外的复杂性

5. 如何监控工具调用

如果你需要监控工具调用过程，可以考虑以下方法：
使用Micrometer观察：Spring AI已经集成了Micrometer，可以通过观察工具调用的指标
在ToolCallback中添加日志：直接在工具实现中添加日志
使用Spring AI的观察机制：通过ToolCallingObservationDocumentation来观察工具调用

[huidongyin]

My Debug Code :

@Configuration
public class AiModelConfig {

    @Bean
    public ChatClient deepseekChatClient(ChatModel deepSeekChatModel) {

        return ChatClient.builder(deepSeekChatModel)
                .defaultAdvisors(
                        new SimpleLoggerAdvisor(),
                        new CustomizeLoggerAdvisor()
                )
                //.defaultToolNames(WeatherTools.CURRENT_WEATHER_TOOL)
                .build();
    }



}

My Test Code :

    @Test
    public void test009() {
        String content = deepseekChatClient
                .prompt("请帮我订一个十分钟后的闹钟。")
                .toolCallbacks(ToolCallbacks.from(new DateTimeTools()))
                .call()
                .content();
        log.info("content: {}", content);
    }

[checkHup]

@shuaidaia Have you solved this problem，I cannot obtain token consumption or call tool names every time