Logging that slows the thing being logged

[Fairman]

Logging that slows the thing being logged

Good practice says to log everything. In a trading program, logging has a price.

Writing to disk takes time. Formatting strings, especially with timestamps and numbers, takes CPU. Under a burst of ticks, a program that writes a line per tick can fall behind, and the delay lands in the middle of the decision loop.

Synchronous logging blocks the program until the write finishes. If the disk is slow or busy, the program waits.

Better design moves logging off the critical path. Messages are placed in a queue and written by a separate thread. The main loop only pays the cost of adding to memory.

Log volume matters too. Recording every tick of every pair generates gigabytes a day. Logging only events of interest, such as signals, orders, fills, and errors, keeps the files manageable.

Log levels allow detail when debugging and brevity in production.

A test is easy: run the program with logging at full verbosity and at minimal, and compare the decision latency distribution.

Many unexplained latency spikes in home-made bots trace back to a log call.

With verbose logging on, how much does order-sending time grow?