Skip to content

APP-1547 Added sqlalchemy mapper to loquacious logger list#14292

Merged
tofarr merged 2 commits into
mainfrom
quieten-sql-alchemy
May 4, 2026
Merged

APP-1547 Added sqlalchemy mapper to loquacious logger list#14292
tofarr merged 2 commits into
mainfrom
quieten-sql-alchemy

Conversation

@tofarr

@tofarr tofarr commented May 4, 2026

Copy link
Copy Markdown
Collaborator
  • A human has tested these changes.

Why

When starting up, sqlalchemy dumps a large quantity of data to the logs at info level. This is useful for debugging, but users do not need this under normal operation, so we increase the level from this logger to WARNING.

Issue Number

How to Test

Run the server and look at the logs. On main you'll see a large amount of data like this, which is conspicuously absent when the fix is applied:

05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) _configure_property(id, Column)                        mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) _configure_property(conversation_id, Column)           mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) _configure_property(role, Column)                      mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) _configure_property(content, Column)                   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) _configure_property(created_at, Column)                mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) Identified primary key columns:                        mapper.py:2480
                             OrderedSet([Column('id', String(), table=<pending_messages>, primary_key=True,                               
                             nullable=False)])                                                                                            
[05/04/26 09:21:46] INFO     (StoredPendingMessage|pending_messages) constructed                                            mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(conversation_id,        mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(selected_repository,    mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(selected_branch,        mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(git_provider, Column)   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(title, Column)          mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(last_updated_at,        mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(created_at, Column)     mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(trigger, Column)        mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(pr_number, Column)      mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(accumulated_cost,       mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(prompt_tokens, Column)  mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(completion_tokens,      mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(total_tokens, Column)   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(max_budget_per_task,    mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(cache_read_tokens,      mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(cache_write_tokens,     mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(reasoning_tokens,       mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(context_window, Column) mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(per_turn_token, Column) mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(llm_model, Column)      mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(agent_kind, Column)     mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(conversation_version,   mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(sandbox_id, Column)     mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(parent_conversation_id, mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(public, Column)         mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) _configure_property(tags, Column)           mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) Identified primary key columns:             mapper.py:2480
                             OrderedSet([Column('conversation_id', String(), table=<conversation_metadata>,                               
                             primary_key=True, nullable=False, default=CallableColumnDefault(<function                                    
                             StoredConversationMetadata.<lambda> at 0x11bce0400>))])                                                      
[05/04/26 09:21:46] INFO     (StoredConversationMetadata|conversation_metadata) constructed                                 mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(id, Column)   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task)                                   mapper.py:2480
                             _configure_property(created_by_user_id, Column)                                                              
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(status,       mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(detail,       mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task)                                   mapper.py:2480
                             _configure_property(app_conversation_id, Column)                                                             
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(sandbox_id,   mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task)                                   mapper.py:2480
                             _configure_property(agent_server_url, Column)                                                                
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(request,      mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(created_at,   mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) _configure_property(updated_at,   mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) Identified primary key columns:   mapper.py:2480
                             OrderedSet([Column('id', Uuid(), table=<app_conversation_start_task>, primary_key=True,                      
                             nullable=False)])                                                                                            
[05/04/26 09:21:46] INFO     (StoredAppConversationStartTask|app_conversation_start_task) constructed                       mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(id, Column)                           mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(conversation_id, Column)              mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(status, Column)                       mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(processor, Column)                    mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(event_kind, Column)                   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(created_at, Column)                   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) _configure_property(updated_at, Column)                   mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) Identified primary key columns: OrderedSet([Column('id',  mapper.py:2480
                             Uuid(), table=<event_callback>, primary_key=True, nullable=False)])                                          
[05/04/26 09:21:46] INFO     (StoredEventCallback|event_callback) constructed                                               mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(id, Column)              mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(status, Column)          mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(event_callback_id,       mapper.py:2480
                             Column)                                                                                                      
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(event_id, Column)        mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(conversation_id, Column) mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(detail, Column)          mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) _configure_property(created_at, Column)      mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) Identified primary key columns:              mapper.py:2480
                             OrderedSet([Column('id', Uuid(), table=<event_callback_result>, primary_key=True,                            
                             nullable=False, default=CallableColumnDefault(<function uuid4 at 0x11c0d85e0>))])                            
[05/04/26 09:21:46] INFO     (StoredEventCallbackResult|event_callback_result) constructed                                  mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) _configure_property(id, Column)                        mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) _configure_property(created_by_user_id, Column)        mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) _configure_property(sandbox_spec_id, Column)           mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) _configure_property(session_api_key_hash, Column)      mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) _configure_property(created_at, Column)                mapper.py:2480
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) Identified primary key columns:                        mapper.py:2480
                             OrderedSet([Column('id', String(), table=<v1_remote_sandbox>, primary_key=True,                              
                             nullable=False)])                                                                                            
[05/04/26 09:21:46] INFO     (StoredRemoteSandbox|v1_remote_sandbox) constructed 

Video/Screenshots

image

Type

  • Bug fix
  • Feature
  • Refactor
  • Breaking change
  • Docs / chore

Notes


To run this PR locally, use the following command:

GUI with Docker:

docker run -it --rm   -p 3000:3000   -v /var/run/docker.sock:/var/run/docker.sock   --add-host host.docker.internal:host-gateway   --name openhands-app-60a0bb0   docker.openhands.dev/openhands/openhands:60a0bb0

When starting up, sqlalchemy dumps a large quantity of data to the logs at info level. This is useful for debugging, but users do not need this under normal operation, so we increase the level from this logger to `WARNING`.
@tofarr tofarr changed the title Added sqlalchemy mapper to loquacious logger list APP-1547 Added sqlalchemy mapper to loquacious logger list May 4, 2026
@github-actions

github-actions Bot commented May 4, 2026

Copy link
Copy Markdown
Contributor

Coverage report

Click to see where and how coverage changed

FileStatementsMissingCoverageCoverage
(new stmts)
Lines missing
  openhands/app_server/utils
  logger.py
Project Total  

This report was generated by python-coverage-comment-action

@tofarr tofarr marked this pull request as ready for review May 4, 2026 15:26

@hieptl hieptl left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you! 🙏

@all-hands-bot all-hands-bot left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Good taste - Simple, targeted configuration change that eliminates noisy startup logs

[RISK ASSESSMENT]

  • [Overall PR] ⚠️ Risk Assessment: 🟢 LOW

This change only modifies logging verbosity for a single SQLAlchemy logger during startup. The scope is minimal, there are no breaking changes, no security implications, and the fix has been tested with clear before/after evidence. If any issues arise, this is easily reversible by removing one line.

VERDICT:
Worth merging - Pragmatic solution to a real operational issue with strong evidence of effectiveness

KEY INSIGHT:
Proper log level management improves operator experience without changing any functional behavior.

@tofarr tofarr merged commit b407ad7 into main May 4, 2026
23 checks passed
@tofarr tofarr deleted the quieten-sql-alchemy branch May 4, 2026 15:35
@mamoodi mamoodi added the release:cloud-1.29.0 PRs included in cloud-1.29.0 release label May 11, 2026 — with OpenHands AI
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

release:cloud-1.29.0 PRs included in cloud-1.29.0 release

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants