Elapsed time measurement


#1

I stumbled upon this PR in steps-wait-for-android-emulator and noticed that non-monotonic clock is used to measure elapsed time.

In general, it is an error when wall clock is used to measure time periods because it may go backward or forward when e.g. when a clock is adjusted by the user or synchronized with the time server. E.g. here is one of the most noticeable examples from Cloudflare. It uses the same go function as linked step.
However, in ephemeral bitrise containers there are no malicious users and wall clock is rather kept in sync.

I’ve checked what exactly happens when wall clock in a container is changed and I noticed that bitrise CLI is also affected by this “bug”:

Failed to format time, error: time (82374.439693 hour) greater then max allowed (999 hour)
| x | wait-for-android-emulator (exit code: 1)                      | 999+ hour|
+---+---------------------------------------------------------------+----------+
| Issue tracker: ...com/bitrise-steplib/steps-wait-for-android-emulator/issues |
| Source: https://github.com/bitrise-steplib/steps-wait-for-android-emulator   |
+---+---------------------------------------------------------------+----------+
Failed to format time, error: time (82374.465508 hour) greater then max allowed (999 hour)
| Total runtime: 999+ hour                                                     |
+------------------------------------------------------------------------------+

INFO[18:00:02]                                              
INFO[18:00:02] Submitting anonymized usage information...   
INFO[18:00:02] For more information visit:                  
INFO[18:00:02] https://github.com/bitrise-core/bitrise-plugins-analytics/blob/master/README.md 
FATA[18:00:02] Failed to send analytics, error: failed to perform request with usage data ({"steps":[{"step":"","version":"","duration":58.304983562,"error":false,"ci":true},{"step":"","version":"","duration":0.9830175670000001,"error":false,"ci":true},{"step":"","version":"","duration":33.644818656,"error":false,"ci":true},{"step":"","version":"","duration":2.9654798289487594e+08,"error":true,"ci":true}]}), error: Post https://bitrise-stats.herokuapp.com/save: x509: certificate has expired or is not yet valid 
WARN[18:00:02] Failed to trigger WorkflowRunDidFinish, error: exit status 1 

What do others think? It is an error to use wall clock in time measurement on bitrise, or it is acceptable?


#2

You’re totally right @koral, and from a technical point of view switching would definitely be a good idea. But the sad reality is that if you change the time, that will mess up your build one way or another, almost guaranteed. E.g. Downloading from and uploading to Amazon S3 won’t work if the time diff is more than 15 mins (I believe).

This of course is no excuse to not to do the right thing, so feel free to create a bug report on the CLI’s github (or send a fix PR if you have the time), all this means is that this is a “lower priority” bug, not a “show stopper” :slight_smile:


#3

Relevant Go issue has been resolved and will be shipped with Go 1.9. So it seems that calculations using Time API like this in bitrise CLI or in mentioned PR will be fixed out of the box when Go in bitrise docker images will be updated to 1.9. More info.


#4

Good catch! I did see this PR/discussion (on HackerNews), but didn’t realise that it’ll fix the issue without any code change.

Awesome, and thanks for the links @koral! :wink: