enriquegh
commented
4 years ago Okay looked through our logging system and our times are correct.
For 9e702876120945b5b1391e62ef7fc2d4 some timestamps: Start time (UI) 2020-01-17 15:56:28
Sauce processes request 2020-01-17 15:56:27
Session command gets to VM 01/17/2020 15:56:34
Start time of POST session command (log.json)
2020-01-17 15:56:34
Selenium server sending response back: 01/17/2020 15:56:42
VM gets DELETE session command:
01/17/2020 15:56:56
Start time of DELETE session command (log.json):
01/17/2020 15:56:56
Job ends in VM: 01/17/2020 15:56:59
Job end processed: 01/17/202015:57:00
End time (UI): 2020-01-17 15:57:00
This timestamps together with the start_time of the POST session command and DELETE session command (1579305394 and 1579305416) respectively tell us:
log.json takes into account the time between:
Session command gets to VM
and
VM gets DELETE session command
It does not taken into account:
- time it takes to process request and have chef running (about 7 secs in test)
- time it takes to shutdown VM (about 3 seconds)
- time it takes to process screenshots and video (1 second)
There’s a lot of decimal point accuracy that I am forgoing but that adds to about the 10 second difference we see. Based on my findings these 10 seconds (assuming we’re not talking about say an iOS Simulator or Android Emulator) should be pretty static across our cloud.
Maybe the processing time can vary if it’s a long test but time to get a VM ready, time to shutdown a VM should be static at least across a particular cloud
As an AC to close this issue, I will add a blurb to our README that some discrepancy is expected between this analysis and time we report the test took.
Data source: https://docs.google.com/spreadsheets/d/1hin8kpuo-gIzWvbuxcfZL1iS9F1lhro3iCGR4OXsBQs/edit?usp=sharing
If you pick a job on this list, say 9e702876120945b5b1391e62ef7fc2d4, and look at the UI of the job the duration is 32 seconds.
sauce-log-parser says this same job took a total of 22.31 seconds.
Duration total: 12.2.
Between Commands: 10.11