Skip to content

Improve logging during model runs with unified logging system #422

Description

@JiaXu1024

Current Situation

We currently have fragmented logging across multiple systems that makes it difficult to track model run progress and debug issues:

Existing Logging Components:

  • EMME Logbook (emme_project/Logbook) - Only accessible through EMME software, not easily reviewable without opening EMME
  • Various log files in logFiles/ directory - Contains event logs from different components but lacks organization
  • ActivitySim logs in output/*/log directories (e.g., output/resident/log, output/airport.SAN/activitysim.log) - These are fine to keep separate
  • Python scripts - Many use print() statements that are lost unless batch scripts redirect output

Problems:

  1. Print statements in Python scripts (like TravelTimeReporter.py, 2zoneSkim.py, EMME tool scripts) are not being captured when batch scripts don't redirect output
  2. No unified chronological log to follow model run progression across all components
  3. EMME logbook requires opening EMME software to review, need a text-based alternative
  4. Difficult to track EMME tool execution times and status
  5. No easy way to identify errors or warnings across all components

Proposed Solution

Implement a comprehensive Python logging system that:

  • Captures all EMME tool execution, Python script output, and non-EMME components
  • Provides both a master chronological log (all components) and component-specific logs (detailed debugging)
  • Creates a text-based alternative to EMME logbook with tool execution times and status
  • Maintains existing ActivitySim logs in their current locations (no changes needed)

Implementation Plan

1. Create centralized Python logging module

  • Create python/logging_config.py with:
    • Function to initialize dual-handler logging (master log + component log)
    • Timestamped formatter with script name, level, and message
    • Master log: logFiles/master_run.log (all components, chronological)
    • Component logs: logFiles/{component_name}.log (e.g., emme_tools.log, travel_time_reporter.log)
    • Log rotation configuration (size-based, keep last 5 files)

2. Create EMME tool execution wrapper

  • Create python/emme/emme_logger.py with:
    • Decorator function to wrap EMME tool calls
    • Captures: tool name, start time, end time, duration, parameters, success/error status
    • Writes to master log and logFiles/emme_tools.log

3. Update master_run.py

  • Import logging modules
  • Add execution tracking for each major tool call (4Ds, network import, transit, assignments, etc.)
  • Wrap tool invocations with logging decorator

4. Update Python scripts to use logging

  • Priority scripts without output redirection:
    • python/TravelTimeReporter.py
    • src/main/python/2zoneSkim.py
    • All scripts in python/emme/ directory
  • Replace print() with logger.info() and logger.error()

5. Update batch scripts

  • Add output redirection as backup for scripts not yet converted:
    • bin/run_travel_time_calculator.cmd
    • bin/runSandagAbm_2zoneSkim.cmd

6. Create log summary utility

  • Create python/generate_log_summary.py to generate logFiles/run_summary.txt with:
    • Model run start/end times
    • EMME tool execution times and status
    • Component completion status
    • Error/warning summary

Expected Benefits

  1. All output captured - No more lost print statements
  2. Easy troubleshooting - Single chronological master log shows entire model run progression
  3. Text-based EMME tracking - View EMME tool execution without opening EMME software
  4. Component-specific debugging - Detailed logs per component for deep dives
  5. Automatic log management - Log rotation prevents disk space issues
  6. Structured logging - Consistent format across all Python components

Acceptance Criteria

  • logFiles/master_run.log contains chronological entries from all Python/EMME components
  • logFiles/emme_tools.log contains EMME tool execution times and status
  • Print statements from Python scripts appear in logs
  • Log rotation works and prevents disk space issues
  • logFiles/run_summary.txt provides readable summary of model run
  • Existing ActivitySim logs remain unchanged
  • No regression in model functionality

Metadata

Metadata

Labels

enhancementpythonPull requests that update Python code

Fields

No fields configured for Feature.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions