Skip to content

Consolidate common log lines #329

@morgo

Description

@morgo

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:

  • The replClient status
  • The copier or main task status
  • The checkpoint status

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:

  • lastCheckpoint: 10s ago (we don't need the additional info)
  • lastChangelogFlush: 10s ago; took 2.5s; 5512 batch size
  • the chunkSize should also be written to the copier's status, since currently it's part of the checkpoint output.

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

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    enhancementNew feature or request

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions