Seeing inconsistent several hour delay between test creation and running

[domdistilled]

Hi all,

Trying to get a private instance of WPT run and running using the EC2 AMI.

Currently I'm having an issue where:

• I create a test with the API (multiple runs)
• WPT automatically spins up an EC2 instance
• Wait several hours
• The test runs correctly
  

The test machine isn't shut down during this time and while it does happen a lot, it doesn't happen consistently. I'm struggling to debug any further as I can't find any more log entries. How can I debug what's happen on the test machines? (Note I am using the AMI which spins up test machines by itself.)

It's still running, there are just giant delays that make no sense.

Logs result logs

Code:

2018/03/19 14:36:02 - Test Created
2018/03/19 15:58:01 - Starting test (initiated by tester i-034a1e5b4a77e11b9)
2018/03/19 15:58:01 - Run 1 assigned to i-085a1e5b4a22e11b9
2018/03/19 15:58:27 - Test Run Complete. Run: 1, Cached: 0, Done: , Tester: i-034a1e5b4a77e11b9
2018/03/19 15:58:27 - Extracting 295343 byte uploaded file '/tmp/php76Ws8t' to './results/18/03/19/0K/6'
2018/03/19 15:58:27 - Done Processing. Run: 1, Cached: 0, Done: , Tester: i-034a1e5b4a77e11b9
2018/03/19 15:58:48 - Test Run Complete. Run: 1, Cached: 1, Done: 1, Tester: i-034a1e5b4a77e11b9
2018/03/19 15:58:48 - Marked shard 1 as complete: {"1":true}
2018/03/19 15:58:48 - Extracting 190317 byte uploaded file '/tmp/phpStdXQe' to './results/18/03/19/0K/6'
2018/03/19 15:58:48 - Done Processing. Run: 1, Cached: 1, Done: , Tester: i-034a1e5b4a77e11b9
2018/03/19 16:58:49 - Run 2 assigned to i-034a1e5b4a77e11b9
2018/03/19 16:59:16 - Test Run Complete. Run: 2, Cached: 0, Done: , Tester: i-085a1e5b4a22e11b9
2018/03/19 16:59:16 - Extracting 313559 byte uploaded file '/tmp/phpkSzbab' to './results/18/03/19/0K/6'
2018/03/19 16:59:16 - Done Processing. Run: 2, Cached: 0, Done: , Tester: i-085a1e5b4a22e11b9
2018/03/19 16:59:42 - Test Run Complete. Run: 2, Cached: 1, Done: 1, Tester: i-085a1e5b4a22e11b9
2018/03/19 16:59:42 - Marked shard 2 as complete: {"1":true,"2":true}
2018/03/19 16:59:42 - Extracting 345091 byte uploaded file '/tmp/phpY6veml' to './results/18/03/19/0K/6'
2018/03/19 16:59:42 - Done Processing. Run: 2, Cached: 1, Done: , Tester: i-034a1e5b4a77e11b9

testinfo.ini
[test]
startTime=03/19/18 15:58:01
fvonly=0
timeout=0
runs=3
location="US West (N. California) - <b>Chrome</b> - <b>Cable</b>"
loc=us-west-1
id=180319_0K_6
batch=0
batch_locations=0
sensitive=0
connections=0
video=1
owner=id
connectivity=Cable
bwIn=5000
bwOut=1000
latency=28
plr=0


My set-up

• webpagetest-server-2014-11-25 (ami-9978f6ee)
• controller instance on t2.micro - EU Ireland
• test instances haven't touched, so are running on m3.medium that the AMI scales by default
• I have slow_test_time=200 in the settings, but I'm unsure where that logs to.