This is somewhat of a rehash of Add option to print timestamps in klippy.log - #10
Specifically, timestamps are valuable when troubleshooting startup issues (to allow for correlation with other logs), as it stands now, timing data is only available in the form of stats reports, and the realtime and monotonic times printed in the “printer started” message.
Alternately, logging supports a configuration file syntax for all kinds of uses, being able to specify this on the command line, or in the environment would allow for quite a bit of flexibility, however, this would require the user to reimplement the bglogger’s queue if the targets are blocking. This would also be //really// useful when providing -v or -X importtime to the python runtime, as it would allow sorting these messages out. As it stands now, I abuse the site module to customize logging as needed.
For my own setup, I run klippy w/o a logfile, and stdout/err->journal, which gets me quite a bit of useful information, including the monotonic timestamp if needed (useful when NTP syncs after klippy starts). (example follows)
> journalctl -o short-monotonic --boot -u klippy -g 'MCU|Start'
[ 17.602002] voron systemd[1]: Started Klipper host daemon.
[ 18.621195] voron klipper-klippy[686]: INFO:root:Starting Klippy...
[ 19.576465] voron klipper-klippy[686]: INFO:root:Start printer at Tue Jul 16 12:00:17 2024 (1721131217.8 19.6)
[ 36.595113] voron klipper-klippy[686]: INFO:root:mcu 'mcu': Starting CAN connect
[ 37.704362] voron klipper-klippy[686]: INFO:root:Loaded MCU 'mcu' 126 commands (a9b4ce8 / gcc: (SUSE Linux) 12.3.0 binutils: (GNU Binutils; openSUSE Tumbleweed) 2.40.0.20230412-5)
[ 37.704362] voron klipper-klippy[686]: MCU 'mcu' config: ADC_MAX=4095 BUS_PINS_i2c1=PB6,PB7 BUS_PINS_i2c1a=PB8,PB9 BUS_PINS_i2c2=PB10,PB11 BUS_PINS_i2c3=PA8,PC9 BUS_PINS_sdio=PC12,PD2,PC8,PC9,PC10,PC11 BUS_PINS_spi1=PA6,PA7,PA5 BUS_PINS_spi1a=PB4,PB5,P>
[ 37.706860] voron klipper-klippy[686]: INFO:root:mcu 'klipper_beacon.beacon': Starting serial connect
[ 38.346907] voron klipper-klippy[686]: INFO:root:Loaded MCU 'klipper_beacon.beacon' 40 commands (Beacon 2.0.1 / )
[ 38.346907] voron klipper-klippy[686]: MCU 'klipper_beacon.beacon' config: ADC_MAX=4095 BEACON_ADC_SMOOTH_COUNT=16 BEACON_REV=D CLOCK_FREQ=32000000 MCU=beacon STATS_SUMSQ_BASE=256
[ 38.366227] voron klipper-klippy[686]: INFO:root:Sending MCU 'mcu' printer configuration...
[ 38.393407] voron klipper-klippy[686]: INFO:root:Configured MCU 'mcu' (1024 moves)
[ 38.487185] voron klipper-klippy[686]: INFO:root:Sending MCU 'klipper_beacon.beacon' printer configuration...
[ 38.487185] voron klipper-klippy[686]: INFO:root:Configured MCU 'klipper_beacon.beacon' (0 moves)
[ 38.602996] voron klipper-klippy[686]: INFO:root:Starting heater checks for heater_bed
[ 39.331434] voron klipper-klippy[686]: INFO:root:Starting heater checks for extruder
However, as tools already exist that parse klipper logs, it would probably be prudent to introduce this as disabled by default, and flip it on a major release.