Skip to content

CI/CD job section timings

Michael Trainor requested to merge cicd-job-section-timings into main

I thought I saw a discussion on this topic in this project but I could not find it. If this is a duplicate of another script of project, please let me know.

Summary

This aims to parse the CI/CD job log and provide the timings of each section. This allow for easy analysis of how long each section is taking.

Language

It was originally written in Bash because I assumed that text search would be so much faster than in Ruby. I decided to port the Bash script to Ruby to test the performance. In real time Bash is more performant. See section Performance.

We should decide which script we should accept and maintain.

Usage

The intended usage is to provide a job log file for the -n argument to the script:

./gls_cicd_job_section_timings -n <job_log_file.txt>

If the job is on GitLab.com, you can use the API to download the trace and then call the script:

PROJECT_ID=123456
JOB_ID=9876543
FILE="${JOB_ID}-trace.txt"

curl -s --location --header "PRIVATE-TOKEN: <your_access_token>" \
-o $FILE https://gitlab.com/api/v4/projects/$PROJECT_ID/jobs/$JOB_ID/trace

./gls_cicd_job_section_timings -n $FILE

Output is printf table format by default:

SECTION                         START            END         DURATION
resolve_secrets                 1673883670       1673883670  0
prepare_executor                1673883670       1673883670  0
prepare_script                  1673883670       1673883671  1
get_sources                     1673883671       1673883704  33
step_script                     1673883704       1673883711  7
upload_artifacts_on_success     1673883711       1673883730  19
cleanup_file_variables          1673883730       1673883732  2

You can change the output format by using the -f option:

$ ./gls_cicd_job_section_timings -n $FILE -f csv
SECTION,START,END,DURATION
resolve_secrets,1673883670,1673883670,0
prepare_executor,1673883670,1673883670,0
prepare_script,1673883670,1673883671,1
get_sources,1673883671,1673883704,33
step_script,1673883704,1673883711,7
upload_artifacts_on_success,1673883711,1673883730,19
cleanup_file_variables,1673883730,1673883732,2

You can write to a file by piping to tee. I don't see a reason to implement a feature for writing to disk.

$ ./gls_cicd_job_section_timings -n $FILE -f csv | tee /tmp/job_timings.csv

Performance

See below for performance of both the Bash script and Ruby script.

$ time bash scripts/cicd-job-section-timings.sh -n ~/Downloads/zd361779/job1logs15.6.txt

real	0m0.201s
user	0m0.069s
sys	0m0.170s

$ time bash scripts/cicd-job-section-timings.sh -n ~/Downloads/zd361779/job1logs15.6.txt -f csv

real	0m0.218s
user	0m0.076s
sys	0m0.192s

$ time ruby scripts/cicd-job-section-timings.rb -n ~/Downloads/zd361779/job1logs15.6.txt

real	0m0.360s
user	0m0.077s
sys	0m0.049s

$ time ruby scripts/cicd-job-section-timings.rb -n ~/Downloads/zd361779/job1logs15.6.txt -f csv

real	0m0.333s
user	0m0.076s
sys	0m0.046s
Edited by Michael Trainor

Merge request reports