From 43d81002ec4a8ca272574cc8d8a4b573507bb280 Mon Sep 17 00:00:00 2001 From: Twirre Meulenbelt <43213592+TwirreM@users.noreply.github.com> Date: Tue, 27 Jan 2026 16:52:18 +0100 Subject: [PATCH] feat: add useful experiment logs ref: N25B-401 --- .../agents/actuation/robot_gesture_agent.py | 4 +++ .../agents/bdi/bdi_core_agent.py | 12 +++++++ .../agents/bdi/bdi_program_manager.py | 17 +++++++++ src/control_backend/agents/llm/llm_agent.py | 15 +++++--- .../transcription_agent.py | 36 ++++++++++++------- .../agents/perception/vad_agent.py | 16 +++++++++ .../user_interrupt/user_interrupt_agent.py | 4 +++ 7 files changed, 87 insertions(+), 17 deletions(-) diff --git a/src/control_backend/agents/actuation/robot_gesture_agent.py b/src/control_backend/agents/actuation/robot_gesture_agent.py index 997b684..9567940 100644 --- a/src/control_backend/agents/actuation/robot_gesture_agent.py +++ b/src/control_backend/agents/actuation/robot_gesture_agent.py @@ -1,4 +1,5 @@ import json +import logging import zmq import zmq.asyncio as azmq @@ -8,6 +9,8 @@ from control_backend.core.agent_system import InternalMessage from control_backend.core.config import settings from control_backend.schemas.ri_message import GestureCommand, RIEndpoint +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class RobotGestureAgent(BaseAgent): """ @@ -111,6 +114,7 @@ class RobotGestureAgent(BaseAgent): gesture_command.data, ) return + experiment_logger.action("Gesture: %s", gesture_command.data) await self.pubsocket.send_json(gesture_command.model_dump()) except Exception: self.logger.exception("Error processing internal message.") diff --git a/src/control_backend/agents/bdi/bdi_core_agent.py b/src/control_backend/agents/bdi/bdi_core_agent.py index 628bb53..ad7d71f 100644 --- a/src/control_backend/agents/bdi/bdi_core_agent.py +++ b/src/control_backend/agents/bdi/bdi_core_agent.py @@ -1,6 +1,7 @@ import asyncio import copy import json +import logging import time from collections.abc import Iterable @@ -19,6 +20,9 @@ from control_backend.schemas.ri_message import GestureCommand, RIEndpoint, Speec DELIMITER = ";\n" # TODO: temporary until we support lists in AgentSpeak +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + + class BDICoreAgent(BaseAgent): """ BDI Core Agent. @@ -207,6 +211,9 @@ class BDICoreAgent(BaseAgent): else: term = agentspeak.Literal(name) + if name != "user_said": + experiment_logger.observation(f"Formed new belief: {name}{f'={args}' if args else ''}") + self.bdi_agent.call( agentspeak.Trigger.addition, agentspeak.GoalType.belief, @@ -244,6 +251,9 @@ class BDICoreAgent(BaseAgent): new_args = (agentspeak.Literal(arg) for arg in args) term = agentspeak.Literal(name, new_args) + if name != "user_said": + experiment_logger.observation(f"Removed belief: {name}{f'={args}' if args else ''}") + result = self.bdi_agent.call( agentspeak.Trigger.removal, agentspeak.GoalType.belief, @@ -386,6 +396,8 @@ class BDICoreAgent(BaseAgent): body=str(message_text), ) + experiment_logger.chat(str(message_text), extra={"role": "assistant"}) + self.add_behavior(self.send(chat_history_message)) yield diff --git a/src/control_backend/agents/bdi/bdi_program_manager.py b/src/control_backend/agents/bdi/bdi_program_manager.py index 6e8a594..3ea6a62 100644 --- a/src/control_backend/agents/bdi/bdi_program_manager.py +++ b/src/control_backend/agents/bdi/bdi_program_manager.py @@ -1,10 +1,12 @@ import asyncio import json +import logging import zmq from pydantic import ValidationError from zmq.asyncio import Context +import control_backend from control_backend.agents import BaseAgent from control_backend.agents.bdi.agentspeak_generator import AgentSpeakGenerator from control_backend.core.config import settings @@ -19,6 +21,8 @@ from control_backend.schemas.program import ( Program, ) +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class BDIProgramManager(BaseAgent): """ @@ -277,6 +281,18 @@ class BDIProgramManager(BaseAgent): await self.send(extractor_msg) self.logger.debug("Sent message to extractor agent to clear history.") + @staticmethod + def _rollover_experiment_logs(): + """ + A new experiment program started; make a new experiment log file. + """ + handlers = logging.getLogger(settings.logging_settings.experiment_logger_name).handlers + for handler in handlers: + if isinstance(handler, control_backend.logging.DatedFileHandler): + experiment_logger.action("Doing rollover...") + handler.do_rollover() + experiment_logger.debug("Finished rollover.") + async def _receive_programs(self): """ Continuous loop that receives program updates from the HTTP endpoint. @@ -297,6 +313,7 @@ class BDIProgramManager(BaseAgent): self._initialize_internal_state(program) await self._send_program_to_user_interrupt(program) await self._send_clear_llm_history() + self._rollover_experiment_logs() await asyncio.gather( self._create_agentspeak_and_send_to_bdi(program), diff --git a/src/control_backend/agents/llm/llm_agent.py b/src/control_backend/agents/llm/llm_agent.py index 1c72dfc..b2324a4 100644 --- a/src/control_backend/agents/llm/llm_agent.py +++ b/src/control_backend/agents/llm/llm_agent.py @@ -1,4 +1,5 @@ import json +import logging import re import uuid from collections.abc import AsyncGenerator @@ -13,6 +14,8 @@ from control_backend.core.config import settings from ...schemas.llm_prompt_message import LLMPromptMessage from .llm_instructions import LLMInstructions +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class LLMAgent(BaseAgent): """ @@ -132,7 +135,7 @@ class LLMAgent(BaseAgent): *self.history, ] - message_id = str(uuid.uuid4()) # noqa + message_id = str(uuid.uuid4()) try: full_message = "" @@ -141,10 +144,9 @@ class LLMAgent(BaseAgent): full_message += token current_chunk += token - self.logger.llm( - "Received token: %s", + experiment_logger.chat( full_message, - extra={"reference": message_id}, # Used in the UI to update old logs + extra={"role": "assistant", "reference": message_id, "partial": True}, ) # Stream the message in chunks separated by punctuation. @@ -160,6 +162,11 @@ class LLMAgent(BaseAgent): if current_chunk: yield current_chunk + experiment_logger.chat( + full_message, + extra={"role": "assistant", "reference": message_id, "partial": False}, + ) + self.history.append( { "role": "assistant", diff --git a/src/control_backend/agents/perception/transcription_agent/transcription_agent.py b/src/control_backend/agents/perception/transcription_agent/transcription_agent.py index 795623d..e69fea6 100644 --- a/src/control_backend/agents/perception/transcription_agent/transcription_agent.py +++ b/src/control_backend/agents/perception/transcription_agent/transcription_agent.py @@ -1,4 +1,5 @@ import asyncio +import logging import numpy as np import zmq @@ -10,6 +11,8 @@ from control_backend.core.config import settings from .speech_recognizer import SpeechRecognizer +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class TranscriptionAgent(BaseAgent): """ @@ -25,6 +28,8 @@ class TranscriptionAgent(BaseAgent): :ivar audio_in_socket: The ZMQ SUB socket instance. :ivar speech_recognizer: The speech recognition engine instance. :ivar _concurrency: Semaphore to limit concurrent transcriptions. + :ivar _current_speech_reference: The reference of the current user utterance, for synchronising + experiment logs. """ def __init__(self, audio_in_address: str): @@ -39,6 +44,7 @@ class TranscriptionAgent(BaseAgent): self.audio_in_socket: azmq.Socket | None = None self.speech_recognizer = None self._concurrency = None + self._current_speech_reference: str | None = None async def setup(self): """ @@ -63,6 +69,10 @@ class TranscriptionAgent(BaseAgent): self.logger.info("Finished setting up %s", self.name) + async def handle_message(self, msg: InternalMessage): + if msg.thread == "voice_activity": + self._current_speech_reference = msg.body + async def stop(self): """ Stop the agent and close sockets. @@ -96,24 +106,25 @@ class TranscriptionAgent(BaseAgent): async def _share_transcription(self, transcription: str): """ - Share a transcription to the other agents that depend on it. + Share a transcription to the other agents that depend on it, and to experiment logs. Currently sends to: - :attr:`settings.agent_settings.text_belief_extractor_name` + - The UI via the experiment logger :param transcription: The transcribed text. """ - receiver_names = [ - settings.agent_settings.text_belief_extractor_name, - ] + experiment_logger.chat( + transcription, + extra={"role": "user", "reference": self._current_speech_reference, "partial": False}, + ) - for receiver_name in receiver_names: - message = InternalMessage( - to=receiver_name, - sender=self.name, - body=transcription, - ) - await self.send(message) + message = InternalMessage( + to=settings.agent_settings.text_belief_extractor_name, + sender=self.name, + body=transcription, + ) + await self.send(message) async def _transcribing_loop(self) -> None: """ @@ -129,10 +140,9 @@ class TranscriptionAgent(BaseAgent): audio = np.frombuffer(audio_data, dtype=np.float32) speech = await self._transcribe(audio) if not speech: - self.logger.info("Nothing transcribed.") + self.logger.debug("Nothing transcribed.") continue - self.logger.info("Transcribed speech: %s", speech) await self._share_transcription(speech) except Exception as e: self.logger.error(f"Error in transcription loop: {e}") diff --git a/src/control_backend/agents/perception/vad_agent.py b/src/control_backend/agents/perception/vad_agent.py index 2b333f5..920c3ab 100644 --- a/src/control_backend/agents/perception/vad_agent.py +++ b/src/control_backend/agents/perception/vad_agent.py @@ -1,4 +1,6 @@ import asyncio +import logging +import uuid import numpy as np import torch @@ -12,6 +14,8 @@ from control_backend.schemas.internal_message import InternalMessage from ...schemas.program_status import PROGRAM_STATUS, ProgramStatus from .transcription_agent.transcription_agent import TranscriptionAgent +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class SocketPoller[T]: """ @@ -252,6 +256,18 @@ class VADAgent(BaseAgent): if prob > prob_threshold: if self.i_since_speech > non_speech_patience + begin_silence_length: self.logger.debug("Speech started.") + reference = str(uuid.uuid4()) + experiment_logger.chat( + "...", + extra={"role": "user", "reference": reference, "partial": True}, + ) + await self.send( + InternalMessage( + to=settings.agent_settings.transcription_name, + body=reference, + thread="voice_activity", + ) + ) self.audio_buffer = np.append(self.audio_buffer, chunk) self.i_since_speech = 0 continue diff --git a/src/control_backend/agents/user_interrupt/user_interrupt_agent.py b/src/control_backend/agents/user_interrupt/user_interrupt_agent.py index 117f83c..f8186b7 100644 --- a/src/control_backend/agents/user_interrupt/user_interrupt_agent.py +++ b/src/control_backend/agents/user_interrupt/user_interrupt_agent.py @@ -1,4 +1,5 @@ import json +import logging import zmq from zmq.asyncio import Context @@ -16,6 +17,8 @@ from control_backend.schemas.ri_message import ( SpeechCommand, ) +experiment_logger = logging.getLogger(settings.logging_settings.experiment_logger_name) + class UserInterruptAgent(BaseAgent): """ @@ -296,6 +299,7 @@ class UserInterruptAgent(BaseAgent): :param text_to_say: The string that the robot has to say. """ + experiment_logger.chat(text_to_say, extra={"role": "assistant"}) cmd = SpeechCommand(data=text_to_say, is_priority=True) out_msg = InternalMessage( to=settings.agent_settings.robot_speech_name,