[15:53:44.183] New invocation is queued and will start shortly
[15:53:44.183] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[15:53:45.321] Starting the invocation (attempt 1)
[15:53:45.377] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:53:45.377] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:53:45.378] Buildbucket request:
{
"bucket": "luci.infra.cron",
"client_operation_id": "9064948535702403536",
"parameters_json": "{\"builder_name\":\"Build From Tarball\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"buildbucket\":{\"properties\":{\"version\":\"79.0.3942.0\"},\"tags\":[\"parent_buildername:publish_tarball\",\"user_agent:recipe\"]},\"id\":\"58d33af1-7272-473f-a24d-98a7d69fcb84\",\"title\":\"publish_tarball/0\"}]},\"version\":\"79.0.3942.0\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Build From Tarball",
"scheduler_invocation_id:9064948535702403536",
"scheduler_job_id:infra/Build From Tarball",
"user_agent:luci-scheduler",
"parent_buildername:publish_tarball",
"user_agent:recipe"
]
}
[15:53:51.245] Buildbucket response:
{
"build": {
"bucket": "luci.infra.cron",
"canary": true,
"canary_preference": "CANARY",
"created_by": "project:infra",
"created_ts": "1571154826332325",
"id": "8899518472781966448",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3942.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"58d33af1-7272-473f-a24d-98a7d69fcb84\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"79.0.3942.0\"}}",
"project": "infra",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1571154828787855",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9064948535702403536",
"scheduler_job_id:infra/Build From Tarball",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8899518472781966448/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:recipe_name:build_from_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_task_id:",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1571154828787985",
"url": "https://ci.chromium.org/b/8899518472781966448",
"utcnow_ts": "1571154831058633"
}
}
[15:53:51.245] Task URL: https://ci.chromium.org/b/8899518472781966448
[15:53:51.245] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:2:0) after 1m0s
[15:54:51.283] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:2:0)
[15:54:51.283] Timer tick, asking Buildbucket for the build status
[15:54:51.465] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:54:51.465] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:3:0) after 1m0s
[15:55:51.481] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:3:0)
[15:55:51.481] Timer tick, asking Buildbucket for the build status
[15:55:51.670] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:55:51.670] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:4:0) after 1m0s
[15:56:51.662] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:4:0)
[15:56:51.662] Timer tick, asking Buildbucket for the build status
[15:56:53.210] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:56:53.210] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:5:0) after 1m0s
[15:57:53.245] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:5:0)
[15:57:53.245] Timer tick, asking Buildbucket for the build status
[15:57:53.464] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:57:53.464] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:6:0) after 1m0s
[15:58:53.500] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:6:0)
[15:58:53.500] Timer tick, asking Buildbucket for the build status
[15:58:53.806] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:58:53.806] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:7:0) after 1m0s
[15:59:53.858] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:7:0)
[15:59:53.858] Timer tick, asking Buildbucket for the build status
[15:59:54.209] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[15:59:54.209] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:8:0) after 1m0s
[16:00:54.246] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:8:0)
[16:00:54.246] Timer tick, asking Buildbucket for the build status
[16:00:54.410] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:00:54.410] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:9:0) after 1m0s
[16:01:54.520] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:9:0)
[16:01:54.520] Timer tick, asking Buildbucket for the build status
[16:01:54.679] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:01:54.679] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:10:0) after 1m0s
[16:02:54.805] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:10:0)
[16:02:54.805] Timer tick, asking Buildbucket for the build status
[16:02:55.359] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:02:55.359] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:11:0) after 1m0s
[16:03:55.447] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:11:0)
[16:03:55.447] Timer tick, asking Buildbucket for the build status
[16:03:55.611] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:03:55.611] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:12:0) after 1m0s
[16:04:55.661] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:12:0)
[16:04:55.661] Timer tick, asking Buildbucket for the build status
[16:04:56.512] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:04:56.512] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:13:0) after 1m0s
[16:05:56.553] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:13:0)
[16:05:56.553] Timer tick, asking Buildbucket for the build status
[16:05:56.991] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:05:56.991] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:14:0) after 1m0s
[16:06:57.012] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:14:0)
[16:06:57.012] Timer tick, asking Buildbucket for the build status
[16:06:57.930] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:06:57.930] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:15:0) after 1m0s
[16:07:57.998] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:15:0)
[16:07:57.998] Timer tick, asking Buildbucket for the build status
[16:07:58.596] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:07:58.596] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:16:0) after 1m0s
[16:08:58.659] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:16:0)
[16:08:58.659] Timer tick, asking Buildbucket for the build status
[16:08:59.122] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:08:59.122] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:17:0) after 1m0s
[16:09:59.146] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:17:0)
[16:09:59.146] Timer tick, asking Buildbucket for the build status
[16:09:59.930] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:09:59.930] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:18:0) after 1m0s
[16:11:00.041] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:18:0)
[16:11:00.041] Timer tick, asking Buildbucket for the build status
[16:11:00.355] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:11:00.355] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:19:0) after 1m0s
[16:12:00.458] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:19:0)
[16:12:00.458] Timer tick, asking Buildbucket for the build status
[16:12:00.690] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:12:00.690] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:20:0) after 1m0s
[16:13:00.726] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:20:0)
[16:13:00.726] Timer tick, asking Buildbucket for the build status
[16:13:00.918] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:13:00.918] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:21:0) after 1m0s
[16:14:00.939] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:21:0)
[16:14:00.939] Timer tick, asking Buildbucket for the build status
[16:14:01.092] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:14:01.092] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:22:0) after 1m0s
[16:15:01.204] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:22:0)
[16:15:01.204] Timer tick, asking Buildbucket for the build status
[16:15:01.462] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:15:01.462] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:23:0) after 1m0s
[16:16:01.555] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:23:0)
[16:16:01.555] Timer tick, asking Buildbucket for the build status
[16:16:02.145] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:16:02.146] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:24:0) after 1m0s
[16:17:02.194] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:24:0)
[16:17:02.194] Timer tick, asking Buildbucket for the build status
[16:17:02.323] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:17:02.323] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:25:0) after 1m0s
[16:18:02.349] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:25:0)
[16:18:02.349] Timer tick, asking Buildbucket for the build status
[16:18:02.729] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:18:02.729] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:26:0) after 1m0s
[16:19:02.773] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:26:0)
[16:19:02.773] Timer tick, asking Buildbucket for the build status
[16:19:03.006] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:19:03.006] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:27:0) after 1m0s
[16:20:03.101] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:27:0)
[16:20:03.101] Timer tick, asking Buildbucket for the build status
[16:20:03.333] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:20:03.333] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:28:0) after 1m0s
[16:21:03.363] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:28:0)
[16:21:03.363] Timer tick, asking Buildbucket for the build status
[16:21:03.482] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:21:03.482] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:29:0) after 1m0s
[16:22:03.466] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:29:0)
[16:22:03.466] Timer tick, asking Buildbucket for the build status
[16:22:03.917] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:22:03.917] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:30:0) after 1m0s
[16:23:03.935] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:30:0)
[16:23:03.935] Timer tick, asking Buildbucket for the build status
[16:23:04.113] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:23:04.113] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:31:0) after 1m0s
[16:24:04.219] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:31:0)
[16:24:04.219] Timer tick, asking Buildbucket for the build status
[16:24:04.462] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:24:04.462] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:32:0) after 1m0s
[16:25:04.487] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:32:0)
[16:25:04.487] Timer tick, asking Buildbucket for the build status
[16:25:04.731] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:25:04.731] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:33:0) after 1m0s
[16:26:04.775] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:33:0)
[16:26:04.775] Timer tick, asking Buildbucket for the build status
[16:26:06.709] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:26:06.709] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:34:0) after 1m0s
[16:27:06.733] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:34:0)
[16:27:06.733] Timer tick, asking Buildbucket for the build status
[16:27:06.966] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:27:06.966] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:35:0) after 1m0s
[16:28:07.045] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:35:0)
[16:28:07.045] Timer tick, asking Buildbucket for the build status
[16:28:08.290] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:28:08.290] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:36:0) after 1m0s
[16:29:08.410] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:36:0)
[16:29:08.410] Timer tick, asking Buildbucket for the build status
[16:29:08.557] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:29:08.557] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:37:0) after 1m0s
[16:30:08.696] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:37:0)
[16:30:08.696] Timer tick, asking Buildbucket for the build status
[16:30:08.903] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:30:08.903] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:38:0) after 1m0s
[16:31:09.023] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:38:0)
[16:31:09.023] Timer tick, asking Buildbucket for the build status
[16:31:09.443] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:31:09.443] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:39:0) after 1m0s
[16:32:09.686] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:39:0)
[16:32:09.686] Timer tick, asking Buildbucket for the build status
[16:32:09.923] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:32:09.923] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:40:0) after 1m0s
[16:33:10.135] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:40:0)
[16:33:10.135] Timer tick, asking Buildbucket for the build status
[16:33:12.794] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:33:12.794] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:41:0) after 1m0s
[16:34:12.891] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:41:0)
[16:34:12.891] Timer tick, asking Buildbucket for the build status
[16:34:13.118] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:34:13.118] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:42:0) after 1m0s
[16:35:13.266] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:42:0)
[16:35:13.266] Timer tick, asking Buildbucket for the build status
[16:35:14.262] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:35:14.262] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:43:0) after 1m0s
[16:36:14.367] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:43:0)
[16:36:14.367] Timer tick, asking Buildbucket for the build status
[16:36:15.201] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:36:15.201] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:44:0) after 1m0s
[16:37:15.175] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:44:0)
[16:37:15.175] Timer tick, asking Buildbucket for the build status
[16:37:15.787] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:37:15.787] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:45:0) after 1m0s
[16:38:15.922] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:45:0)
[16:38:15.922] Timer tick, asking Buildbucket for the build status
[16:38:16.217] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:38:16.217] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:46:0) after 1m0s
[16:39:16.301] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:46:0)
[16:39:16.301] Timer tick, asking Buildbucket for the build status
[16:39:16.430] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:39:16.430] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:47:0) after 1m0s
[16:40:16.497] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:47:0)
[16:40:16.497] Timer tick, asking Buildbucket for the build status
[16:40:16.805] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:40:16.805] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:48:0) after 1m0s
[16:41:16.842] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:48:0)
[16:41:16.842] Timer tick, asking Buildbucket for the build status
[16:41:17.211] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:41:17.211] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:49:0) after 1m0s
[16:42:17.258] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:49:0)
[16:42:17.258] Timer tick, asking Buildbucket for the build status
[16:42:18.183] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:42:18.183] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:50:0) after 1m0s
[16:43:18.193] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:50:0)
[16:43:18.193] Timer tick, asking Buildbucket for the build status
[16:43:18.596] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:43:18.596] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:51:0) after 1m0s
[16:44:18.670] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:51:0)
[16:44:18.670] Timer tick, asking Buildbucket for the build status
[16:44:18.866] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:44:18.866] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:52:0) after 1m0s
[16:45:18.944] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:52:0)
[16:45:18.945] Timer tick, asking Buildbucket for the build status
[16:45:19.146] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:45:19.146] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:53:0) after 1m0s
[16:46:19.262] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:53:0)
[16:46:19.262] Timer tick, asking Buildbucket for the build status
[16:46:19.494] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:46:19.494] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:54:0) after 1m0s
[16:47:19.534] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:54:0)
[16:47:19.534] Timer tick, asking Buildbucket for the build status
[16:47:20.188] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:47:20.188] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:55:0) after 1m0s
[16:48:20.250] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:55:0)
[16:48:20.250] Timer tick, asking Buildbucket for the build status
[16:48:20.964] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:48:20.965] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:56:0) after 1m0s
[16:49:21.028] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:56:0)
[16:49:21.028] Timer tick, asking Buildbucket for the build status
[16:49:22.144] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:49:22.144] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:57:0) after 1m0s
[16:50:22.213] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:57:0)
[16:50:22.213] Timer tick, asking Buildbucket for the build status
[16:50:22.626] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:50:22.626] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:58:0) after 1m0s
[16:51:22.664] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:58:0)
[16:51:22.664] Timer tick, asking Buildbucket for the build status
[16:51:22.827] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:51:22.827] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:59:0) after 1m0s
[16:52:23.012] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:59:0)
[16:52:23.012] Timer tick, asking Buildbucket for the build status
[16:52:23.186] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:52:23.186] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:60:0) after 1m0s
[16:53:23.179] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:60:0)
[16:53:23.179] Timer tick, asking Buildbucket for the build status
[16:53:23.350] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:53:23.350] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:61:0) after 1m0s
[16:54:23.349] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:61:0)
[16:54:23.349] Timer tick, asking Buildbucket for the build status
[16:54:23.589] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:54:23.589] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:62:0) after 1m0s
[16:55:23.690] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:62:0)
[16:55:23.690] Timer tick, asking Buildbucket for the build status
[16:55:23.968] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:55:23.968] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:63:0) after 1m0s
[16:56:24.018] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:63:0)
[16:56:24.018] Timer tick, asking Buildbucket for the build status
[16:56:24.340] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:56:24.340] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:64:0) after 1m0s
[16:57:24.408] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:64:0)
[16:57:24.408] Timer tick, asking Buildbucket for the build status
[16:57:26.317] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:57:26.317] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:65:0) after 1m0s
[16:58:26.389] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:65:0)
[16:58:26.389] Timer tick, asking Buildbucket for the build status
[16:58:26.617] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:58:26.617] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:66:0) after 1m0s
[16:59:26.650] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:66:0)
[16:59:26.650] Timer tick, asking Buildbucket for the build status
[16:59:27.756] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:59:27.756] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:67:0) after 1m0s
[17:00:27.819] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:67:0)
[17:00:27.819] Timer tick, asking Buildbucket for the build status
[17:00:28.652] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:00:28.652] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:68:0) after 1m0s
[17:01:28.768] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:68:0)
[17:01:28.768] Timer tick, asking Buildbucket for the build status
[17:01:29.262] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:01:29.262] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:69:0) after 1m0s
[17:02:29.339] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:69:0)
[17:02:29.339] Timer tick, asking Buildbucket for the build status
[17:02:29.553] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:02:29.553] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:70:0) after 1m0s
[17:03:29.683] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:70:0)
[17:03:29.683] Timer tick, asking Buildbucket for the build status
[17:03:29.848] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:03:29.848] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:71:0) after 1m0s
[17:04:29.878] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:71:0)
[17:04:29.878] Timer tick, asking Buildbucket for the build status
[17:04:30.012] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:04:30.012] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:72:0) after 1m0s
[17:05:30.201] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:72:0)
[17:05:30.201] Timer tick, asking Buildbucket for the build status
[17:05:30.568] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:05:30.568] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:73:0) after 1m0s
[17:06:30.551] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:73:0)
[17:06:30.551] Timer tick, asking Buildbucket for the build status
[17:06:31.032] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:06:31.032] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:74:0) after 1m0s
[17:07:31.064] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:74:0)
[17:07:31.064] Timer tick, asking Buildbucket for the build status
[17:07:32.078] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:07:32.078] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:75:0) after 1m0s
[17:08:32.143] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:75:0)
[17:08:32.143] Timer tick, asking Buildbucket for the build status
[17:08:32.337] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:08:32.337] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:76:0) after 1m0s
[17:09:32.367] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:76:0)
[17:09:32.367] Timer tick, asking Buildbucket for the build status
[17:09:32.575] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:09:32.575] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:77:0) after 1m0s
[17:10:32.621] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:77:0)
[17:10:32.621] Timer tick, asking Buildbucket for the build status
[17:10:32.816] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:10:32.816] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:78:0) after 1m0s
[17:11:33.041] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:78:0)
[17:11:33.041] Timer tick, asking Buildbucket for the build status
[17:11:33.240] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:11:33.240] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:79:0) after 1m0s
[17:12:33.266] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:79:0)
[17:12:33.266] Timer tick, asking Buildbucket for the build status
[17:12:33.377] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:12:33.377] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:80:0) after 1m0s
[17:13:33.445] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:80:0)
[17:13:33.445] Timer tick, asking Buildbucket for the build status
[17:13:33.702] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:13:33.702] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:81:0) after 1m0s
[17:14:33.971] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:81:0)
[17:14:33.971] Timer tick, asking Buildbucket for the build status
[17:14:34.147] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:14:34.147] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:82:0) after 1m0s
[17:15:34.228] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:82:0)
[17:15:34.228] Timer tick, asking Buildbucket for the build status
[17:15:35.416] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:15:35.416] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:83:0) after 1m0s
[17:16:35.511] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:83:0)
[17:16:35.511] Timer tick, asking Buildbucket for the build status
[17:16:35.745] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:16:35.745] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:84:0) after 1m0s
[17:17:35.844] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:84:0)
[17:17:35.844] Timer tick, asking Buildbucket for the build status
[17:17:47.286] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:17:47.286] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:85:0) after 1m0s
[17:18:47.367] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:85:0)
[17:18:47.367] Timer tick, asking Buildbucket for the build status
[17:18:47.695] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:18:47.695] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:86:0) after 1m0s
[17:19:47.880] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:86:0)
[17:19:47.880] Timer tick, asking Buildbucket for the build status
[17:19:48.600] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:19:48.600] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:87:0) after 1m0s
[17:20:48.650] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:87:0)
[17:20:48.650] Timer tick, asking Buildbucket for the build status
[17:20:48.815] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:20:48.815] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:88:0) after 1m0s
[17:21:48.905] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:88:0)
[17:21:48.905] Timer tick, asking Buildbucket for the build status
[17:21:51.207] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:21:51.207] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:89:0) after 1m0s
[17:22:51.253] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:89:0)
[17:22:51.253] Timer tick, asking Buildbucket for the build status
[17:22:51.380] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:22:51.380] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:90:0) after 1m0s
[17:23:51.505] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:90:0)
[17:23:51.506] Timer tick, asking Buildbucket for the build status
[17:23:51.666] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:23:51.666] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:91:0) after 1m0s
[17:24:51.889] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:91:0)
[17:24:51.889] Timer tick, asking Buildbucket for the build status
[17:24:53.148] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:24:53.149] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:92:0) after 1m0s
[17:25:53.177] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:92:0)
[17:25:53.177] Timer tick, asking Buildbucket for the build status
[17:25:54.764] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:25:54.765] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:93:0) after 1m0s
[17:26:54.761] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:93:0)
[17:26:54.761] Timer tick, asking Buildbucket for the build status
[17:26:54.893] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:26:54.893] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:94:0) after 1m0s
[17:27:54.974] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:94:0)
[17:27:54.974] Timer tick, asking Buildbucket for the build status
[17:27:56.082] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:27:56.082] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:95:0) after 1m0s
[17:28:56.140] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:95:0)
[17:28:56.140] Timer tick, asking Buildbucket for the build status
[17:28:56.253] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:28:56.253] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:96:0) after 1m0s
[17:29:56.266] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:96:0)
[17:29:56.266] Timer tick, asking Buildbucket for the build status
[17:29:56.450] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:29:56.450] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:97:0) after 1m0s
[17:30:56.503] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:97:0)
[17:30:56.503] Timer tick, asking Buildbucket for the build status
[17:30:56.632] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:30:56.632] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:98:0) after 1m0s
[17:31:56.809] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:98:0)
[17:31:56.809] Timer tick, asking Buildbucket for the build status
[17:31:58.312] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:31:58.312] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:99:0) after 1m0s
[17:32:58.368] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:99:0)
[17:32:58.368] Timer tick, asking Buildbucket for the build status
[17:33:00.517] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:33:00.517] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:100:0) after 1m0s
[17:34:00.598] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:100:0)
[17:34:00.598] Timer tick, asking Buildbucket for the build status
[17:34:01.937] Build 8899518472781966448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:34:01.937] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:101:0) after 1m0s
[17:34:43.818] Received PubSub notification, asking Buildbucket for the build status
[17:34:43.903] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:35:02.002] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:101:0)
[17:35:02.002] Timer tick, asking Buildbucket for the build status
[17:35:02.340] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:35:02.340] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:103:0) after 1m0s
[17:36:02.439] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:103:0)
[17:36:02.439] Timer tick, asking Buildbucket for the build status
[17:36:02.630] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:36:02.630] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:104:0) after 1m0s
[17:37:02.733] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:104:0)
[17:37:02.733] Timer tick, asking Buildbucket for the build status
[17:37:03.444] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:37:03.444] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:105:0) after 1m0s
[17:38:03.468] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:105:0)
[17:38:03.468] Timer tick, asking Buildbucket for the build status
[17:38:03.642] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:38:03.642] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:106:0) after 1m0s
[17:39:03.659] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:106:0)
[17:39:03.659] Timer tick, asking Buildbucket for the build status
[17:39:04.172] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:39:04.172] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:107:0) after 1m0s
[17:40:04.433] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:107:0)
[17:40:04.433] Timer tick, asking Buildbucket for the build status
[17:40:05.249] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:40:05.249] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:108:0) after 1m0s
[17:41:05.605] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:108:0)
[17:41:05.605] Timer tick, asking Buildbucket for the build status
[17:41:05.726] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:41:05.726] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:109:0) after 1m0s
[17:42:06.118] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:109:0)
[17:42:06.118] Timer tick, asking Buildbucket for the build status
[17:42:07.072] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:42:07.072] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:110:0) after 1m0s
[17:43:07.105] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:110:0)
[17:43:07.105] Timer tick, asking Buildbucket for the build status
[17:43:07.253] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:43:07.253] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:111:0) after 1m0s
[17:44:07.452] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:111:0)
[17:44:07.452] Timer tick, asking Buildbucket for the build status
[17:44:07.692] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:44:07.692] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:112:0) after 1m0s
[17:45:07.750] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:112:0)
[17:45:07.751] Timer tick, asking Buildbucket for the build status
[17:45:07.872] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:45:07.872] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:113:0) after 1m0s
[17:46:07.900] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:113:0)
[17:46:07.900] Timer tick, asking Buildbucket for the build status
[17:46:07.986] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:46:07.986] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:114:0) after 1m0s
[17:47:08.056] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:114:0)
[17:47:08.056] Timer tick, asking Buildbucket for the build status
[17:47:08.176] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:47:08.176] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:115:0) after 1m0s
[17:48:08.195] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:115:0)
[17:48:08.195] Timer tick, asking Buildbucket for the build status
[17:48:08.320] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:48:08.320] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:116:0) after 1m0s
[17:49:08.350] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:116:0)
[17:49:08.350] Timer tick, asking Buildbucket for the build status
[17:49:08.510] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:49:08.510] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:117:0) after 1m0s
[17:50:08.555] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:117:0)
[17:50:08.556] Timer tick, asking Buildbucket for the build status
[17:50:11.000] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:50:11.000] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:118:0) after 1m0s
[17:51:11.049] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:118:0)
[17:51:11.049] Timer tick, asking Buildbucket for the build status
[17:51:11.759] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:51:11.759] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:119:0) after 1m0s
[17:52:12.015] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:119:0)
[17:52:12.015] Timer tick, asking Buildbucket for the build status
[17:52:12.316] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:52:12.316] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:120:0) after 1m0s
[17:53:12.513] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:120:0)
[17:53:12.513] Timer tick, asking Buildbucket for the build status
[17:53:14.727] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:53:14.728] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:121:0) after 1m0s
[17:54:14.881] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:121:0)
[17:54:14.881] Timer tick, asking Buildbucket for the build status
[17:54:15.953] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:54:15.953] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:122:0) after 1m0s
[17:55:16.001] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:122:0)
[17:55:16.001] Timer tick, asking Buildbucket for the build status
[17:55:16.193] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:55:16.193] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:123:0) after 1m0s
[17:56:16.272] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:123:0)
[17:56:16.272] Timer tick, asking Buildbucket for the build status
[17:56:16.629] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:56:16.629] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:124:0) after 1m0s
[17:57:16.918] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:124:0)
[17:57:16.918] Timer tick, asking Buildbucket for the build status
[17:57:17.504] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:57:17.504] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:125:0) after 1m0s
[17:58:17.671] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:125:0)
[17:58:17.671] Timer tick, asking Buildbucket for the build status
[17:58:17.855] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:58:17.855] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:126:0) after 1m0s
[17:59:17.879] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:126:0)
[17:59:17.879] Timer tick, asking Buildbucket for the build status
[17:59:18.131] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:59:18.131] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:127:0) after 1m0s
[18:00:18.199] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:127:0)
[18:00:18.199] Timer tick, asking Buildbucket for the build status
[18:00:18.366] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:00:18.366] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:128:0) after 1m0s
[18:01:18.491] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:128:0)
[18:01:18.491] Timer tick, asking Buildbucket for the build status
[18:01:18.864] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:01:18.864] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:129:0) after 1m0s
[18:02:18.919] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:129:0)
[18:02:18.919] Timer tick, asking Buildbucket for the build status
[18:02:19.104] Build 8899518472781966448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:02:19.104] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9064948535702403536:130:0) after 1m0s
[18:02:26.213] Received PubSub notification, asking Buildbucket for the build status
[18:02:26.566] Build 8899518472781966448: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[18:02:26.566] Buildbucket build:
{
"build": {
"bucket": "luci.infra.cron",
"canary": true,
"canary_preference": "CANARY",
"completed_ts": "1571162545602253",
"created_by": "project:infra",
"created_ts": "1571154826332325",
"failure_reason": "BUILD_FAILURE",
"id": "8899518472781966448",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3942.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"58d33af1-7272-473f-a24d-98a7d69fcb84\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"79.0.3942.0\"}}",
"project": "infra",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('Download nodejs.') (retcode: 1)\"}, \"properties\": {\"$gatekeeper\": {\"group\": \"chromium.infra.cron\"}, \"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3942.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"58d33af1-7272-473f-a24d-98a7d69fcb84\", \"title\": \"publish_tarball/0\"}]}, \"bot_id\": \"luci-infra-cron-xenial-large-0-iv9g\", \"buildername\": \"Build From Tarball\", \"path_config\": \"generic\", \"recipe\": \"build_from_tarball\", \"version\": \"79.0.3942.0\"}, \"swarming\": {\"bot_dimensions\": {\"builderless\": [\"1\"], \"caches\": [\"git\", \"vpython\"], \"cores\": [\"32\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"luci-infra-cron-xenial-large-0-iv9g\"], \"image\": [\"chrome-xenial-19100400-6cc5b08ab04\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-32\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"pool\": [\"luci.infra.cron\"], \"python\": [\"2.7.12\"], \"server_version\": [\"4501-487d554\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}, \"ui\": {\"info\": \"Step('Download nodejs.') (retcode: 1)\"}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1571160881102847",
"status": "COMPLETED",
"status_changed_ts": "1571160882821574",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9064948535702403536",
"scheduler_job_id:infra/Build From Tarball",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8899518472781966448/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Linux",
"swarming_tag:recipe_name:build_from_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_task_id:47e8f273f1866110",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1571162545674083",
"url": "https://ci.chromium.org/b/8899518472781966448",
"utcnow_ts": "1571162546509910"
}
}
[18:02:26.568] Invocation finished in 2h8m42.404387018s with status FAILED