Skip to content

Rework Geo::BaseSchedulerWorker to be clearer and log per-loop information

What does this MR do?

Reworks Geo::BaseSchedulerWorker. This affects Geo::RepositorySyncWorker and other children, improving the logging output and so increasing visibility into scheduling actions.

Are there points in the code the reviewer needs to double check?

Why was this MR needed?

It's hard to work out what the workers are doing at the moment.

Screenshots (if relevant)

The geo.log output now looks like:

{"severity":"INFO","time":"2017-09-20T12:34:02.839Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:02.851Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":0,"pending":0,"scheduled":0}
{"severity":"INFO","time":"2017-09-20T12:34:02.852Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.0130841,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:03.312Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:03.324Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":0,"pending":0,"scheduled":0}
{"severity":"INFO","time":"2017-09-20T12:34:03.325Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.012965368,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:03.863Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:03.872Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":0,"pending":0,"scheduled":0}
{"severity":"INFO","time":"2017-09-20T12:34:03.872Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.010279015,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:05.325Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:05.327Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":0,"duration":0.001805815,"reason":"disabled"}
{"severity":"INFO","time":"2017-09-20T12:34:05.675Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:05.692Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":0,"pending":0,"scheduled":0}
{"severity":"INFO","time":"2017-09-20T12:34:05.692Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.017483968,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:06.185Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:06.204Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":0,"pending":0,"scheduled":0}
{"severity":"INFO","time":"2017-09-20T12:34:06.204Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.020185192,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:07.083Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:07.122Z","class":"Geo::RepositorySyncWorker","message":"Loop 0","enqueued":2,"pending":0,"scheduled":2}
{"severity":"INFO","time":"2017-09-20T12:34:07.122Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":1,"duration":0.038848867,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:07.125Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:07.148Z","class":"Geo::RepositorySyncWorker","message":"Loop 1","enqueued":2,"pending":0,"scheduled":2}
{"severity":"INFO","time":"2017-09-20T12:34:07.148Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":2,"duration":0.023313049,"reason":"last_batch"}
{"severity":"INFO","time":"2017-09-20T12:34:07.151Z","class":"Geo::RepositorySyncWorker","message":"Started scheduler"}
{"severity":"INFO","time":"2017-09-20T12:34:07.174Z","class":"Geo::RepositorySyncWorker","message":"Loop 2","enqueued":2,"pending":0,"scheduled":2}
{"severity":"INFO","time":"2017-09-20T12:34:07.174Z","class":"Geo::RepositorySyncWorker","message":"Finished scheduler","total_loops":3,"duration":0.023309843,"reason":"last_batch"}

Does this MR meet the acceptance criteria?

What are the relevant issue numbers?

Related to #3453 (closed)

Edited by Nick Thomas

Merge request reports