Logging

Moler’s automatic logging system: main moler.log, per-device logs, log rotation, compression, and runtime control.

Moler creates log files automatically as soon as a LOGGER section is present in your configuration. You get two categories of log files without any extra code:

• moler.log — main log showing high-level activity across all devices (commands started/finished, state transitions, events)
• moler.<DeviceName>.log — one file per device showing everything sent to and received from that device, with directional markers

Minimal setup

Add a LOGGER section to your YAML config file:

LOGGER:
  PATH: ./logs
  DATE_FORMAT: "%H:%M:%S"

Then load the config as normal:

from moler.config import load_config

load_config(config='/absolute/path/to/my_devices.yml')

After this, both ./logs/moler.log and per-device log files (e.g., ./logs/moler.MyMachine.log) are created automatically.

LOGGER section fields

Field	Type	Description
PATH	string	Directory where log files are written. Defaults to the current working directory.
DATE_FORMAT	string	strftime-style format for timestamps in log entries. Default: "%d %H:%M:%S".
MODE	string	File open mode: "a" (append, default) or "w" (overwrite on each run).
RAW_LOG	bool	When True, creates additional .raw.log binary files with the exact bytes sent/received.
DEBUG_LEVEL	string	Enable verbose logging: "TRACE" (most verbose), "DEBUG", or "INFO".
ERROR_LOG_STACK	bool	When True, log entries for errors include the full call stack. Default: False.
LOG_ROTATION	mapping	Sub-section configuring log file rotation (see below).
CONSOLE_LOGS	list	Logger names that should also write to stdout.

Log rotation

If your test runs are long, log files can grow large. Moler supports both size-based and time-based rotation through the LOG_ROTATION sub-section.

Size-based rotation

Split log files when they reach a given size. The example below rotates at 5 MB and keeps up to 999 files:

LOGGER:
  PATH: ./logs
  DATE_FORMAT: "%H:%M:%S"
  LOG_ROTATION:
    KIND: size
    INTERVAL: 5242880   # bytes — 5 MB
    BACKUP_COUNT: 999   # default value

Time-based rotation

Split log files at a fixed time interval. The example below rotates every 30 minutes:

LOGGER:
  PATH: ./logs
  DATE_FORMAT: "%H:%M:%S"
  LOG_ROTATION:
    KIND: time
    INTERVAL: 1800      # seconds — 30 minutes
    BACKUP_COUNT: 999   # default value

LOG_ROTATION fields

Field	Type	Description
KIND	string	"size" for size-based rotation, "time" for time-based rotation.
INTERVAL	int	Rotation threshold: bytes when KIND: size, seconds when KIND: time. Default: 102400 (100 KB).
BACKUP_COUNT	int	Maximum number of rotated files to keep. Default: 999.
COMPRESS_AFTER_ROTATION	bool	Compress each rotated file using COMPRESS_COMMAND. Default: False.
COMPRESS_COMMAND	string	Shell command used to compress a rotated file. Uses {compressed} and {log_input} placeholders. Default: "zip -9mq {compressed} {log_input}".
COMPRESSED_FILE_EXTENSION	string	File extension appended to compressed files. Default: ".zip".

Log compression after rotation

To save disk space, enable COMPRESS_AFTER_ROTATION. An external tool (default: zip) is called after each rotation.

Size rotation with compression

LOGGER:
  PATH: ./logs
  DATE_FORMAT: "%H:%M:%S"
  LOG_ROTATION:
    KIND: size
    INTERVAL: 5242880
    BACKUP_COUNT: 999
    COMPRESS_AFTER_ROTATION: True
    COMPRESS_COMMAND: "zip -9mq {compressed} {log_input}"
    COMPRESSED_FILE_EXTENSION: ".zip"

The {log_input} placeholder is replaced with the path to the just-rotated file; {compressed} is replaced with the desired output archive path.

What each log file contains

Main log (moler.log)

The main log gives a high-level view of test progress across all devices. Connection data is not shown — only commands, events, and state transitions.

22:30:19.723 INFO         moler               |More logs in: ./logs
22:30:19.747 INFO         MyMachine           |Connection to: 'MyMachine' has been opened.
22:30:19.748 INFO         MyMachine           |Changed state from 'NOT_CONNECTED' into 'UNIX_LOCAL'
22:30:19.921 INFO         RebexTestMachine    |Command 'moler.cmd.unix.ssh.Ssh':'TERM=xterm-mono ssh -l demo test.rebex.net' started.
22:30:20.909 INFO         RebexTestMachine    |Changed state from 'UNIX_LOCAL' into 'UNIX_REMOTE'
22:30:20.917 INFO         RebexTestMachine    |Command 'moler.cmd.unix.ssh.Ssh' finished.
22:30:20.919 INFO         MyMachine           |Command 'moler.cmd.unix.ping.Ping':'ping www.google.com -w 6' started.
22:30:26.968 INFO         MyMachine           |Command 'moler.cmd.unix.ping.Ping' finished.

Per-device log (moler.<DeviceName>.log)

Each device log shows the raw terminal conversation with directional markers: > for data sent to the device and < for data received from it.

moler.RebexTestMachine.log:

22:30:19.901  |Changed state from 'NOT_CONNECTED' into 'UNIX_LOCAL'
22:30:19.921 >|TERM=xterm-mono ssh -l demo test.rebex.net
22:30:20.762 <|Password:
22:30:20.763 >|*********
22:30:20.908 <|Welcome to Rebex Virtual Shell!
              |For a list of supported commands, type 'help'.
              |demo@ETNA:/$
22:30:20.909  |Changed state from 'UNIX_LOCAL' into 'UNIX_REMOTE'
22:30:20.920  |Command 'moler.cmd.unix.ls.Ls':'ls -l' started.
22:30:20.922 >|ls -l
22:30:20.978 <|drwx------ 2 demo users          0 Jul 26  2017 .
              |drwx------ 2 demo users          0 Jul 26  2017 ..
              |-rw------- 1 demo users        403 Apr 08  2014 readme.txt
22:30:20.985  |Command 'moler.cmd.unix.ls.Ls' finished.

moler.MyMachine.log:

22:30:19.748  |Changed state from 'NOT_CONNECTED' into 'UNIX_LOCAL'
22:30:20.919  |Command 'moler.cmd.unix.ping.Ping':'ping www.google.com -w 6' started.
22:30:20.920 >|ping www.google.com -w 6
22:30:20.959 <|PING www.google.com (216.58.215.68) 56(84) bytes of data.
22:30:21.000 <|64 bytes from waw02s16-in-f4.1e100.net (216.58.215.68): icmp_seq=1 ttl=51 time=40.1 ms
22:30:26.960 <|6 packets transmitted, 6 received, 0% packet loss, time 5007ms
              |rtt min/avg/max/mdev = 29.888/35.251/42.405/4.786 ms
22:30:26.968  |Command 'moler.cmd.unix.ping.Ping' finished.

Multiline output is indented with aligned | separators so every line of a block is clearly associated with its timestamp.

Runtime control

Enable and disable device logging

You can suppress logging for a specific device at runtime. Use this sparingly — missing logs make failure investigation significantly harder.

from moler.device import DeviceFactory

my_unix = DeviceFactory.get_device(name='MyMachine')

my_unix.disable_logging()   # stop writing to moler.MyMachine.log
# ... sensitive operations ...
my_unix.enable_logging()    # resume logging

Change log file suffix

You can add a suffix to log file names to distinguish different test phases or test cases, then remove it or change it again as the test progresses.

from moler.config.loggers import change_logging_suffix
from moler.device import DeviceFactory

# Apply a suffix to all active log files
change_logging_suffix(".tc_001")
# Logs now write to moler.tc_001.log, moler.MyMachine.tc_001.log, etc.

# Remove the suffix (back to default names)
change_logging_suffix(None)

# Apply a suffix to one specific device only
my_unix = DeviceFactory.get_device(name='MyMachine')
my_unix.set_logging_suffix("device_suffix")

# Remove suffix from that device
my_unix.set_logging_suffix(None)

change_logging_suffix has no effect when log rotation is active (KIND is set). Rotating handlers manage their own file naming.

Relocate logs at runtime

from moler.config import reconfigure_logging_path

reconfigure_logging_path('/new/path/to/logs')

All open log file handlers are closed and reopened at the new path. The directory is created if it does not exist.

Debug logging

Set DEBUG_LEVEL in the config or via the MOLER_DEBUG_LEVEL environment variable to write additional detail:

LOGGER:
  PATH: ./logs
  DEBUG_LEVEL: TRACE  # TRACE | DEBUG | INFO

When DEBUG_LEVEL: TRACE or DEBUG_LEVEL: DEBUG, an additional moler.debug.log file is created with per-logger, per-thread, per-file detail:

22:30:20.919 DEBUG        moler.runner.thread-pool       ... ThreadPoolExecutor  runner.py:#42  start() |go background: ...