Parse Docker Machine JSON output and add phase timings to machine creation metrics

What does this MR do?

The creation and failed-creation histograms get the same target_* labels (zone, region, project, machine type) the action counter already has.

The creation histogram's buckets can be set with creation_time_buckets in the global [machine] section. The default does not change. Because the provider exists before the config is loaded, Init on managed executor providers now receives the global config, like Shutdown does, and runs before collectors are registered.

A new histogram, gitlab_runner_autoscaling_machine_creation_phase_duration_seconds, labelled by phase, result and the same target labels. It is behind FF_DOCKER_MACHINE_JSON_OUTPUT, off by default. With the flag on, the runner passes --log-format=json to docker-machine create and parses the output. docker-machine puts a phase field on the first line of each create phase, and the runner diffs the timestamps of consecutive phase lines. A phase still running when the process exits or is killed on timeout is closed with the runner's clock, so an SSH wait that hit the one hour timeout is recorded under that phase. docker-machine's fields are logged nested under docker_machine instead of as one string, and the phase durations are logged as a phases field on the Machine created line.

A line that does not parse is logged as a warning with the raw line and then logged as text as before. With the flag off the runner passes no flag, does no parsing, and the phase histogram has no samples.

Why was this MR needed?

During INC-13960 machine creation on saas-linux-small-amd64 got two to three times slower. The creation histogram showed p50 going from about 33s to 80 to 105s, but not where the time went or which machines were affected. Reconstructing that from docker-machine log timestamps in Elasticsearch took about two hours. The SSH wait had gone from 1 to 3s to a p90 of 55 to 80s in us-east1-d only, while the GCE insert and provisioning stayed flat. With a zone label on the histogram and a per-phase breakdown, that is a dashboard panel.

The 30s bucket floor also puts a healthy 33 to 35s create entirely in the first two buckets, so p50 is interpolation and a regression from 33s to 40s does not show.

What's the best way to test this MR?

Run a docker+machine runner with FF_DOCKER_MACHINE_JSON_OUTPUT enabled and a docker-machine build with the companion change, create a machine, and check /metrics for the phase histogram and the phases field on the Machine created log line. With the flag off, the output and metrics must be as before and the phase histogram must have no samples.

What are the relevant issue numbers?

#39802 (closed)

docker-machine side: gitlab-org/ci-cd/docker-machine!193 (merged)

Edited by Igor

Merge request reports

Loading
Loading