cashapp / spirit

Online Schema Change Tool for MySQL 8.0+
Apache License 2.0
114 stars 20 forks source link

Consolidate common log lines #329

Open morgo opened 4 months ago

morgo commented 4 months ago

When spirit runs, there are 3 common log lines that keep being printed:

2024-07-08T23:51:17.639 info finished periodic flush of binary log: total-duration=2.854617ms batch-size=5583
2024-07-08T23:51:47.636 info migration status: state=copyRows copy-progress=273732111/3306757995 8.28% binlog-deltas=0 total-time=10h57m32s copier-time=10h57m30s copier-remaining-time=125h32m28s (-18h6m from 10h56m ago) copier-is-throttled=false conns-in-use=2
2024-07-08T23:51:47.636 info checkpoint: low-watermark={"Key":["id"],"ChunkSize":6452,"LowerBound":{"Value": ["2876218631"],"Inclusive":true},"UpperBound":{"Value": ["2876225083"],"Inclusive":false}} log-file=mysql-bin-changelog.210394 log-pos=1852984531 rows-copied=273688043 rows-copied-logical=273732111

To give these tasks names, they are roughly:

These all run on different intervals, which is why they currently print separately.

What I suggest is saving the last replClient update and last checkpoint update to the migration runner state, and then printing the output in the same log line as the main task status.

The main task can then say:

I think conns-in-use can also be removed.

We might change the output interval from every 30s to every 1 minute too.