Add timestamps to the CI logs for each line in the log
Status update (2024-06-10)
- As part of our Product Development Flow, we released this feature behind a GitLab Runner feature flag in 17.0.
- Enable this feature by:
- Updating your runners to at least version 17.0 to get the most recent UI updates of this feature.
- Enabling
FF_TIMESTAMPS
by following these instructions for your whole pipeline or specific jobs. (Note: If you're using gitlab.com, some hosted runners may not support timestamps yet and need to be updated on GitLab's side).-
Self-managed users
👉 One extra step! Enable theparse_ci_job_timestamps
feature flag for your instance.
-
Self-managed users
-
💜 We are looking forward to hearing your feedback on this feature: Feedback issue: CI log timestamps (#463391). The goal is to gather feedback through the 17.2 iteration and enable the feature flag by default.
Problem to solve
When a CI job takes too long, I want to know which part of the script section in the job started taking longer. I want to be able to do this without adding dedicated timing code to the CI yaml.
One of the most valuable plugins available to Jenkins is the Timestamper, which prepends the timestamp to every line, much like looking at Linux system logs.
This functionality is mission critical to anyone attempting to do performance analysis, debugging, or improvements on a job.
Current solution
In 16.11, support for timestamps can be enabled with the runner feature flag FF_TIMESTAMPS
. This can be set as a job variable.
This is a first iteration, and when timestamps are present, can interfere with color formatting of the logs. In 17.0, we hope to enable timestamps support by default and also enable correct rendering within the UI.
For older runners, a previous workaround created by the wider community (and not a GitLab supported solution) was this bash script
Intended users
Further details / use cases
One use-case would be trying to optimize the time of a CI job. I want to be able to look at the job, see which command in the script is taking the longest, and try and optimize that.
User Experience
The user should be able to look at a job's execution logs in and determine which subsection of this job is the largest bottleneck.
Real world examples:
- When someone complains that a particular stage in Jenkins (job in GitLab) takes too long, how do we debug that? How do I analyze how much of the execution was spent downloading dependencies, vs how much time was spent compiling the code? If the lines had timestamps, I could determine exactly where the bottleneck lies.
- When running tests, sometimes there is a single test which takes far longer than others. Users complain about testing taking too long and now we need to debug this. In order to determine which test is hanging or taking the largest amount of time, if I could go through the execution logs and see timestamps, I could find the test cmd where things take longer than expected and then debug that.
- This is a small scale example, but real world: In my (terratest:eks)[https://gitlab.com/sandlin/aws/terraform_eks/-/jobs/563074542] stage, I can see
go test ...
takes6:13
, but what part is taking so long? Is it the tests? Is it the dependency download? etc.
Proposal
Add timestamps and other metadata to each log line.
Open Tasks
-
Enable the GitLab Rails feature flag parse_ci_job_timestamps
so that it is on by default.- Note: users will still need to set the
FF_TIMESTAMPS
feature flag in the CI jobs as this enables the feature on the runner that will execute the CI job.
- Note: users will still need to set the
-
Create release post entry