feat(acp): Add --debug flag for protocol message logging#541
feat(acp): Add --debug flag for protocol message logging#541jpshackelford wants to merge 15 commits intomainfrom
Conversation
Add a --debug flag to the 'openhands acp' command that enables logging of all ACP protocol messages (JSON-RPC) to a JSONL file for debugging. Implementation details: - New DebugLogger class that implements StreamObserver from the agent-client-protocol library - Logs all incoming (>>>) and outgoing (<<<) messages with timestamps - Log files stored in ~/.openhands/acp-debug/ with format: YYYYMMDD_HHMMSS_acp.jsonl Usage: openhands acp --debug Then view logs: cat ~/.openhands/acp-debug/*_acp.jsonl | jq . Closes #540 Co-authored-by: openhands <openhands@all-hands.dev>
Coverage Report •
|
||||||||||||||||||||||||||||||||||||||||||||||||||
Co-authored-by: openhands <openhands@all-hands.dev>
Co-authored-by: openhands <openhands@all-hands.dev>
…estamps - Use asyncio.to_thread() to avoid blocking on synchronous file I/O - Keep file handle open for the logger lifetime instead of open/close per message - Add close() method for explicit cleanup - Use UTC consistently for both filename and log entry timestamps Co-authored-by: openhands <openhands@all-hands.dev>
- Move DebugLogger import to module top-level for clarity - Simplify observers/kwargs indirection into a cleaner pattern Co-authored-by: openhands <openhands@all-hands.dev>
- Update tests to call close() after async writes - Update timestamp format tests for UTC with Z suffix - Fix test_uses_default_persistence_dir to mock get_persistence_dir instead of creating files in the real ~/.openhands directory - Add tests for new close() method behavior - Update launcher test to check for observers=None Co-authored-by: openhands <openhands@all-hands.dev>
all-hands-bot
left a comment
There was a problem hiding this comment.
Taste Rating: 🟡 Acceptable
Core design is sound - using StreamObserver is the right pattern and keeps this non-invasive. Simple implementation that solves a real problem. Main issues are resource management and lack of error handling.
Handle OSError when creating the ACP debug log directory. If mkdir fails (permissions, disk full, etc.), gracefully disable logging with a warning instead of crashing the ACP server. A debug feature should never crash the main application. Co-authored-by: openhands <openhands@all-hands.dev>
Wrap file write operations in try/except to silently ignore OSError exceptions. Debug logging failures should be silent, not fatal, when disk fills up or permissions change mid-session. Co-authored-by: openhands <openhands@all-hands.dev>
Simplify the conditional list creation for observers. Remove redundant log message since DebugLogger already logs on init. Only include debug_logger in observers if it's enabled. Co-authored-by: openhands <openhands@all-hands.dev>
Add atexit.register() to ensure the debug logger's file handle is properly closed when the process exits. This prevents resource leaks for long-running ACP servers. Co-authored-by: openhands <openhands@all-hands.dev>
Add tests that verify DebugLogger gracefully degrades when: - Log directory cannot be created (permission denied, disk full) - Writes fail mid-session (disk full) - File cannot be opened (permission denied) These tests ensure the debug feature never crashes the main agent. Co-authored-by: openhands <openhands@all-hands.dev>
The launcher passes observers=[] (empty list), not observers=None, when debug mode is disabled. Update test assertion to match actual behavior. Co-authored-by: openhands <openhands@all-hands.dev>
Co-authored-by: openhands <openhands@all-hands.dev>
enyst
left a comment
There was a problem hiding this comment.
I think maybe the CLI should have a debug mode for the application. Can we do that, and when set, it will also apply to ACP server, or is there a reason not to?
|
@enyst Thanks for taking a look! Not sure what you mean by debug mode for the application. Are you talking about the CLI or WebUI? In any case, seems like that would be a separate PR, no? |
What I mean is: every repo has or should have a We log at debug level a lot of things. So I wonder, can’t we use that, for ACP debug logging, instead of adding a new ACP-specific flag? |
|
@enyst This flag is different from just using the log level setting in that it also writes logs to a file in a specific format for debugging acp. We could consider adding log files for other elements of the system, but that would be new scope and it isn't clear to me whether it is needed as urgently as acp debug logging where we need output written to file since stdout is used by the acp protocol itself. |
all-hands-bot
left a comment
There was a problem hiding this comment.
Acceptable - Core implementation is solid. Using StreamObserver is the right pattern, error handling is in place, and tests cover the important cases. One minor cleanup suggestion below.
| debug_logger = DebugLogger() if debug else None | ||
| observers = [debug_logger] if (debug_logger and debug_logger.enabled) else [] | ||
|
|
||
| # Register cleanup for debug logger file handle |
There was a problem hiding this comment.
🟡 Suggestion: The atexit registration logic could be tighter. Currently you register cleanup even when the logger failed to initialize (enabled=False). While harmless since close() handles None gracefully, it's cleaner to only register when actually enabled:
| # Register cleanup for debug logger file handle | |
| # Setup debug observer if enabled | |
| observers = [] | |
| if debug: | |
| debug_logger = DebugLogger() | |
| if debug_logger.enabled: | |
| observers.append(debug_logger) | |
| atexit.register(debug_logger.close) |
This makes the lifecycle clearer: only set up cleanup for resources that were successfully initialized.
Summary
Add a
--debugflag to theopenhands acpcommand that enables logging of all ACP protocol messages (JSON-RPC) to a JSONL file for debugging purposes.Closes #540
Implementation
The implementation leverages the existing
StreamObserverpattern from theagent-client-protocollibrary to observe all incoming and outgoing JSON-RPC messages without modifying the core protocol handling.Architecture
Files Changed
openhands_cli/acp_impl/debug_logger.pyopenhands_cli/argparsers/acp_parser.py--debugargumentopenhands_cli/acp_impl/agent/launcher.pyopenhands_cli/entrypoint.pytests/acp/test_debug_logger.pytests/acp/test_launcher.pyLog File Format
Location:
~/.openhands/acp-debug/YYYYMMDD_HHMMSS_acp.jsonlFormat (JSONL - one JSON object per line):
{"ts": "2024-02-25T00:50:00.123456Z", "dir": ">>>", "msg": {"jsonrpc": "2.0", "id": 1, "method": "initialize", "params": {...}}} {"ts": "2024-02-25T00:50:00.234567Z", "dir": "<<<", "msg": {"jsonrpc": "2.0", "id": 1, "result": {...}}}>>>= incoming messages (from IDE to agent)<<<= outgoing messages (from agent to IDE)Usage
Then check logs at:
Testing
All 331 ACP tests pass, including 10 new tests for the debug logging functionality.
🚀 Try this PR