[10:50:05.082] New invocation is queued and will start shortly
[10:50:05.082] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[10:50:06.184] Starting the invocation (attempt 1)
[10:50:06.236] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:50:06.236] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:50:06.236] Buildbucket request:
{
"bucket": "luci.infra.cron",
"client_operation_id": "9062249730827132880",
"parameters_json": "{\"builder_name\":\"Build From Tarball\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"buildbucket\":{\"properties\":{\"version\":\"80.0.3967.0\"},\"tags\":[\"parent_buildername:publish_tarball\",\"user_agent:recipe\"]},\"id\":\"1a7ff3e9-98d4-417d-b474-4091479ccd7b\",\"title\":\"publish_tarball/0\"}]},\"version\":\"80.0.3967.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:9062249730827132880",
"scheduler_job_id:infra/Build From Tarball",
"user_agent:luci-scheduler",
"parent_buildername:publish_tarball",
"user_agent:recipe"
]
}
[10:50:07.039] Buildbucket response:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "PROD",
"created_by": "project:infra",
"created_ts": "1573728606419566",
"id": "8896819668753733808",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"80.0.3967.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"1a7ff3e9-98d4-417d-b474-4091479ccd7b\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"80.0.3967.0\"}}",
"project": "infra",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1573728606805372",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9062249730827132880",
"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/8896819668753733808/+/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": "1573728606805515",
"url": "https://ci.chromium.org/b/8896819668753733808",
"utcnow_ts": "1573728607019598"
}
}
[10:50:07.039] Task URL: https://ci.chromium.org/b/8896819668753733808
[10:50:07.039] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:2:0) after 1m0s
[10:51:07.103] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:2:0)
[10:51:07.103] Timer tick, asking Buildbucket for the build status
[10:51:07.258] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:51:07.258] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:3:0) after 1m0s
[10:52:07.324] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:3:0)
[10:52:07.324] Timer tick, asking Buildbucket for the build status
[10:52:07.481] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:52:07.481] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:4:0) after 1m0s
[10:53:07.576] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:4:0)
[10:53:07.576] Timer tick, asking Buildbucket for the build status
[10:53:07.723] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:53:07.723] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:5:0) after 1m0s
[10:54:07.745] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:5:0)
[10:54:07.745] Timer tick, asking Buildbucket for the build status
[10:54:07.876] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:54:07.876] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:6:0) after 1m0s
[10:55:07.950] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:6:0)
[10:55:07.950] Timer tick, asking Buildbucket for the build status
[10:55:08.044] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:55:08.044] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:7:0) after 1m0s
[10:56:08.129] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:7:0)
[10:56:08.129] Timer tick, asking Buildbucket for the build status
[10:56:08.293] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:56:08.293] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:8:0) after 1m0s
[10:57:08.537] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:8:0)
[10:57:08.537] Timer tick, asking Buildbucket for the build status
[10:57:09.080] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:57:09.081] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:9:0) after 1m0s
[10:58:09.163] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:9:0)
[10:58:09.163] Timer tick, asking Buildbucket for the build status
[10:58:09.481] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:58:09.481] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:10:0) after 1m0s
[10:59:09.639] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:10:0)
[10:59:09.639] Timer tick, asking Buildbucket for the build status
[10:59:09.873] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:59:09.873] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:11:0) after 1m0s
[11:00:09.919] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:11:0)
[11:00:09.919] Timer tick, asking Buildbucket for the build status
[11:00:10.564] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:00:10.564] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:12:0) after 1m0s
[11:01:10.717] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:12:0)
[11:01:10.717] Timer tick, asking Buildbucket for the build status
[11:01:11.068] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:01:11.068] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:13:0) after 1m0s
[11:02:11.125] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:13:0)
[11:02:11.125] Timer tick, asking Buildbucket for the build status
[11:02:11.317] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:02:11.317] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:14:0) after 1m0s
[11:03:11.346] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:14:0)
[11:03:11.346] Timer tick, asking Buildbucket for the build status
[11:03:11.588] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:03:11.588] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:15:0) after 1m0s
[11:04:11.653] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:15:0)
[11:04:11.653] Timer tick, asking Buildbucket for the build status
[11:04:13.274] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:04:13.274] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:16:0) after 1m0s
[11:05:13.445] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:16:0)
[11:05:13.445] Timer tick, asking Buildbucket for the build status
[11:05:13.544] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:05:13.544] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:17:0) after 1m0s
[11:06:13.570] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:17:0)
[11:06:13.570] Timer tick, asking Buildbucket for the build status
[11:06:14.462] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:06:14.462] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:18:0) after 1m0s
[11:07:14.512] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:18:0)
[11:07:14.512] Timer tick, asking Buildbucket for the build status
[11:07:14.639] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:07:14.640] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:19:0) after 1m0s
[11:08:14.709] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:19:0)
[11:08:14.709] Timer tick, asking Buildbucket for the build status
[11:08:14.857] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:08:14.857] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:20:0) after 1m0s
[11:09:14.885] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:20:0)
[11:09:14.885] Timer tick, asking Buildbucket for the build status
[11:09:15.131] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:09:15.131] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:21:0) after 1m0s
[11:10:15.212] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:21:0)
[11:10:15.212] Timer tick, asking Buildbucket for the build status
[11:10:17.702] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:10:17.702] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:22:0) after 1m0s
[11:11:17.728] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:22:0)
[11:11:17.728] Timer tick, asking Buildbucket for the build status
[11:11:18.015] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:11:18.015] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:23:0) after 1m0s
[11:12:18.007] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:23:0)
[11:12:18.007] Timer tick, asking Buildbucket for the build status
[11:12:18.985] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:12:18.985] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:24:0) after 1m0s
[11:13:19.057] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:24:0)
[11:13:19.057] Timer tick, asking Buildbucket for the build status
[11:13:19.711] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:13:19.711] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:25:0) after 1m0s
[11:14:19.778] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:25:0)
[11:14:19.778] Timer tick, asking Buildbucket for the build status
[11:14:21.007] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:14:21.007] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:26:0) after 1m0s
[11:15:21.059] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:26:0)
[11:15:21.059] Timer tick, asking Buildbucket for the build status
[11:15:21.246] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:15:21.246] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:27:0) after 1m0s
[11:16:21.294] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:27:0)
[11:16:21.294] Timer tick, asking Buildbucket for the build status
[11:16:21.547] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:16:21.547] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:28:0) after 1m0s
[11:17:21.626] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:28:0)
[11:17:21.626] Timer tick, asking Buildbucket for the build status
[11:17:22.370] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:17:22.370] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:29:0) after 1m0s
[11:18:22.470] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:29:0)
[11:18:22.470] Timer tick, asking Buildbucket for the build status
[11:18:22.674] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:18:22.674] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:30:0) after 1m0s
[11:19:22.774] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:30:0)
[11:19:22.774] Timer tick, asking Buildbucket for the build status
[11:19:23.085] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:19:23.085] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:31:0) after 1m0s
[11:20:23.174] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:31:0)
[11:20:23.174] Timer tick, asking Buildbucket for the build status
[11:20:23.329] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:20:23.329] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:32:0) after 1m0s
[11:21:23.449] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:32:0)
[11:21:23.449] Timer tick, asking Buildbucket for the build status
[11:21:23.557] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:21:23.557] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:33:0) after 1m0s
[11:22:23.773] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:33:0)
[11:22:23.773] Timer tick, asking Buildbucket for the build status
[11:22:24.069] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:22:24.069] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:34:0) after 1m0s
[11:23:24.336] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:34:0)
[11:23:24.336] Timer tick, asking Buildbucket for the build status
[11:23:24.626] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:23:24.626] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:35:0) after 1m0s
[11:24:24.761] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:35:0)
[11:24:24.761] Timer tick, asking Buildbucket for the build status
[11:24:24.987] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:24:24.987] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:36:0) after 1m0s
[11:25:25.063] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:36:0)
[11:25:25.063] Timer tick, asking Buildbucket for the build status
[11:25:25.600] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:25:25.600] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:37:0) after 1m0s
[11:26:25.676] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:37:0)
[11:26:25.676] Timer tick, asking Buildbucket for the build status
[11:26:25.811] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:26:25.811] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:38:0) after 1m0s
[11:27:25.878] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:38:0)
[11:27:25.878] Timer tick, asking Buildbucket for the build status
[11:27:26.074] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:27:26.074] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:39:0) after 1m0s
[11:28:26.118] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:39:0)
[11:28:26.118] Timer tick, asking Buildbucket for the build status
[11:28:26.328] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:28:26.328] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:40:0) after 1m0s
[11:29:26.443] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:40:0)
[11:29:26.443] Timer tick, asking Buildbucket for the build status
[11:29:26.600] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:29:26.600] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:41:0) after 1m0s
[11:30:26.741] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:41:0)
[11:30:26.741] Timer tick, asking Buildbucket for the build status
[11:30:27.124] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:30:27.124] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:42:0) after 1m0s
[11:31:27.307] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:42:0)
[11:31:27.307] Timer tick, asking Buildbucket for the build status
[11:31:27.615] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:31:27.615] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:43:0) after 1m0s
[11:32:27.753] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:43:0)
[11:32:27.753] Timer tick, asking Buildbucket for the build status
[11:32:27.916] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:32:27.916] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:44:0) after 1m0s
[11:33:28.124] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:44:0)
[11:33:28.124] Timer tick, asking Buildbucket for the build status
[11:33:28.287] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:33:28.287] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:45:0) after 1m0s
[11:34:28.554] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:45:0)
[11:34:28.554] Timer tick, asking Buildbucket for the build status
[11:34:28.747] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:34:28.747] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:46:0) after 1m0s
[11:35:28.907] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:46:0)
[11:35:28.907] Timer tick, asking Buildbucket for the build status
[11:35:29.112] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:35:29.112] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:47:0) after 1m0s
[11:36:29.225] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:47:0)
[11:36:29.225] Timer tick, asking Buildbucket for the build status
[11:36:29.564] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:36:29.564] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:48:0) after 1m0s
[11:37:29.635] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:48:0)
[11:37:29.635] Timer tick, asking Buildbucket for the build status
[11:37:29.927] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:37:29.927] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:49:0) after 1m0s
[11:38:30.129] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:49:0)
[11:38:30.129] Timer tick, asking Buildbucket for the build status
[11:38:30.341] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:38:30.341] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:50:0) after 1m0s
[11:39:30.459] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:50:0)
[11:39:30.459] Timer tick, asking Buildbucket for the build status
[11:39:30.797] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:39:30.797] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:51:0) after 1m0s
[11:40:30.862] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:51:0)
[11:40:30.862] Timer tick, asking Buildbucket for the build status
[11:40:31.029] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:40:31.029] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:52:0) after 1m0s
[11:41:31.134] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:52:0)
[11:41:31.134] Timer tick, asking Buildbucket for the build status
[11:41:31.305] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:41:31.305] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:53:0) after 1m0s
[11:42:31.429] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:53:0)
[11:42:31.429] Timer tick, asking Buildbucket for the build status
[11:42:31.826] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:42:31.826] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:54:0) after 1m0s
[11:43:31.870] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:54:0)
[11:43:31.870] Timer tick, asking Buildbucket for the build status
[11:43:32.500] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:43:32.500] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:55:0) after 1m0s
[11:44:32.632] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:55:0)
[11:44:32.632] Timer tick, asking Buildbucket for the build status
[11:44:32.987] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:44:32.987] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:56:0) after 1m0s
[11:45:33.039] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:56:0)
[11:45:33.039] Timer tick, asking Buildbucket for the build status
[11:45:33.512] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:45:33.512] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:57:0) after 1m0s
[11:46:33.561] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:57:0)
[11:46:33.561] Timer tick, asking Buildbucket for the build status
[11:46:34.024] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:46:34.024] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:58:0) after 1m0s
[11:47:34.209] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:58:0)
[11:47:34.209] Timer tick, asking Buildbucket for the build status
[11:47:34.541] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:47:34.541] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:59:0) after 1m0s
[11:48:34.619] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:59:0)
[11:48:34.619] Timer tick, asking Buildbucket for the build status
[11:48:34.745] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:48:34.745] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:60:0) after 1m0s
[11:49:34.931] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:60:0)
[11:49:34.931] Timer tick, asking Buildbucket for the build status
[11:49:35.105] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:49:35.105] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:61:0) after 1m0s
[11:50:35.158] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:61:0)
[11:50:35.158] Timer tick, asking Buildbucket for the build status
[11:50:35.294] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:50:35.294] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:62:0) after 1m0s
[11:51:35.493] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:62:0)
[11:51:35.493] Timer tick, asking Buildbucket for the build status
[11:51:35.693] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:51:35.693] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:63:0) after 1m0s
[11:52:35.778] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:63:0)
[11:52:35.778] Timer tick, asking Buildbucket for the build status
[11:52:35.964] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:52:35.964] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:64:0) after 1m0s
[11:53:35.995] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:64:0)
[11:53:35.995] Timer tick, asking Buildbucket for the build status
[11:53:36.167] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:53:36.167] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:65:0) after 1m0s
[11:54:36.233] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:65:0)
[11:54:36.233] Timer tick, asking Buildbucket for the build status
[11:54:36.709] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:54:36.709] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:66:0) after 1m0s
[11:55:36.790] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:66:0)
[11:55:36.790] Timer tick, asking Buildbucket for the build status
[11:55:36.865] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:55:36.865] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:67:0) after 1m0s
[11:56:36.936] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:67:0)
[11:56:36.936] Timer tick, asking Buildbucket for the build status
[11:56:37.233] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:56:37.233] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:68:0) after 1m0s
[11:57:37.340] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:68:0)
[11:57:37.340] Timer tick, asking Buildbucket for the build status
[11:57:37.744] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:57:37.744] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:69:0) after 1m0s
[11:58:37.764] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:69:0)
[11:58:37.764] Timer tick, asking Buildbucket for the build status
[11:58:38.131] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:58:38.131] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:70:0) after 1m0s
[11:59:38.176] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:70:0)
[11:59:38.176] Timer tick, asking Buildbucket for the build status
[11:59:38.431] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:59:38.431] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:71:0) after 1m0s
[12:00:38.459] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:71:0)
[12:00:38.459] Timer tick, asking Buildbucket for the build status
[12:00:38.597] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:00:38.597] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:72:0) after 1m0s
[12:01:38.629] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:72:0)
[12:01:38.629] Timer tick, asking Buildbucket for the build status
[12:01:38.859] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:01:38.859] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:73:0) after 1m0s
[12:02:38.897] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:73:0)
[12:02:38.897] Timer tick, asking Buildbucket for the build status
[12:02:39.237] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:02:39.237] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:74:0) after 1m0s
[12:03:39.306] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:74:0)
[12:03:39.306] Timer tick, asking Buildbucket for the build status
[12:03:39.485] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:03:39.485] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:75:0) after 1m0s
[12:04:39.523] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:75:0)
[12:04:39.523] Timer tick, asking Buildbucket for the build status
[12:04:39.640] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:04:39.640] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:76:0) after 1m0s
[12:05:39.747] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:76:0)
[12:05:39.747] Timer tick, asking Buildbucket for the build status
[12:05:40.775] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:05:40.775] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:77:0) after 1m0s
[12:06:40.799] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:77:0)
[12:06:40.799] Timer tick, asking Buildbucket for the build status
[12:06:40.952] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:06:40.952] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:78:0) after 1m0s
[12:07:41.209] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:78:0)
[12:07:41.209] Timer tick, asking Buildbucket for the build status
[12:07:41.406] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:07:41.406] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:79:0) after 1m0s
[12:08:41.653] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:79:0)
[12:08:41.653] Timer tick, asking Buildbucket for the build status
[12:08:41.938] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:08:41.938] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:80:0) after 1m0s
[12:09:41.956] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:80:0)
[12:09:41.956] Timer tick, asking Buildbucket for the build status
[12:09:42.075] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:09:42.075] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:81:0) after 1m0s
[12:10:42.194] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:81:0)
[12:10:42.194] Timer tick, asking Buildbucket for the build status
[12:10:42.828] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:10:42.828] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:82:0) after 1m0s
[12:11:42.817] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:82:0)
[12:11:42.817] Timer tick, asking Buildbucket for the build status
[12:11:43.874] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:11:43.874] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:83:0) after 1m0s
[12:12:43.929] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:83:0)
[12:12:43.929] Timer tick, asking Buildbucket for the build status
[12:12:44.072] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:12:44.072] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:84:0) after 1m0s
[12:13:44.164] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:84:0)
[12:13:44.164] Timer tick, asking Buildbucket for the build status
[12:13:44.389] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:13:44.389] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:85:0) after 1m0s
[12:14:44.493] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:85:0)
[12:14:44.493] Timer tick, asking Buildbucket for the build status
[12:14:44.580] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:14:44.580] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:86:0) after 1m0s
[12:15:44.646] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:86:0)
[12:15:44.646] Timer tick, asking Buildbucket for the build status
[12:15:45.878] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:15:45.878] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:87:0) after 1m0s
[12:16:45.914] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:87:0)
[12:16:45.914] Timer tick, asking Buildbucket for the build status
[12:16:46.276] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:16:46.276] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:88:0) after 1m0s
[12:17:46.272] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:88:0)
[12:17:46.272] Timer tick, asking Buildbucket for the build status
[12:17:46.427] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:17:46.427] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:89:0) after 1m0s
[12:18:46.467] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:89:0)
[12:18:46.467] Timer tick, asking Buildbucket for the build status
[12:18:46.793] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:18:46.793] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:90:0) after 1m0s
[12:19:46.848] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:90:0)
[12:19:46.848] Timer tick, asking Buildbucket for the build status
[12:19:47.233] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:19:47.233] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:91:0) after 1m0s
[12:20:47.357] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:91:0)
[12:20:47.357] Timer tick, asking Buildbucket for the build status
[12:20:47.514] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:20:47.514] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:92:0) after 1m0s
[12:21:47.577] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:92:0)
[12:21:47.577] Timer tick, asking Buildbucket for the build status
[12:21:47.821] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:21:47.821] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:93:0) after 1m0s
[12:22:47.910] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:93:0)
[12:22:47.910] Timer tick, asking Buildbucket for the build status
[12:22:49.949] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:22:49.949] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:94:0) after 1m0s
[12:23:49.999] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:94:0)
[12:23:49.999] Timer tick, asking Buildbucket for the build status
[12:23:50.311] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:23:50.312] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:95:0) after 1m0s
[12:24:50.367] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:95:0)
[12:24:50.367] Timer tick, asking Buildbucket for the build status
[12:24:50.504] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:24:50.504] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:96:0) after 1m0s
[12:25:50.549] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:96:0)
[12:25:50.549] Timer tick, asking Buildbucket for the build status
[12:25:50.808] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:25:50.808] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:97:0) after 1m0s
[12:26:50.833] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:97:0)
[12:26:50.833] Timer tick, asking Buildbucket for the build status
[12:26:50.989] Build 8896819668753733808: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:26:50.989] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:98:0) after 1m0s
[12:27:30.241] Received PubSub notification, asking Buildbucket for the build status
[12:27:30.354] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:27:51.534] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:98:0)
[12:27:51.534] Timer tick, asking Buildbucket for the build status
[12:27:51.651] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:27:51.651] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:100:0) after 1m0s
[12:28:51.844] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:100:0)
[12:28:51.844] Timer tick, asking Buildbucket for the build status
[12:28:52.115] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:28:52.115] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:101:0) after 1m0s
[12:29:55.639] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:101:0)
[12:29:55.639] Timer tick, asking Buildbucket for the build status
[12:29:56.059] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:29:56.059] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:102:0) after 1m0s
[12:30:56.062] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:102:0)
[12:30:56.062] Timer tick, asking Buildbucket for the build status
[12:30:56.504] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:30:56.504] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:103:0) after 1m0s
[12:31:56.532] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:103:0)
[12:31:56.532] Timer tick, asking Buildbucket for the build status
[12:31:56.679] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:31:56.679] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:104:0) after 1m0s
[12:32:56.899] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:104:0)
[12:32:56.900] Timer tick, asking Buildbucket for the build status
[12:32:57.155] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:32:57.155] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:105:0) after 1m0s
[12:33:57.246] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:105:0)
[12:33:57.246] Timer tick, asking Buildbucket for the build status
[12:33:57.726] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:33:57.726] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:106:0) after 1m0s
[12:34:57.773] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:106:0)
[12:34:57.773] Timer tick, asking Buildbucket for the build status
[12:34:57.986] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:34:57.986] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:107:0) after 1m0s
[12:35:58.048] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:107:0)
[12:35:58.048] Timer tick, asking Buildbucket for the build status
[12:35:58.538] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:35:58.538] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:108:0) after 1m0s
[12:36:58.553] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:108:0)
[12:36:58.554] Timer tick, asking Buildbucket for the build status
[12:36:58.687] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:36:58.687] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:109:0) after 1m0s
[12:37:58.777] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:109:0)
[12:37:58.777] Timer tick, asking Buildbucket for the build status
[12:37:58.963] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:37:58.963] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:110:0) after 1m0s
[12:38:59.029] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:110:0)
[12:38:59.029] Timer tick, asking Buildbucket for the build status
[12:38:59.157] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:38:59.157] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:111:0) after 1m0s
[12:39:59.213] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:111:0)
[12:39:59.213] Timer tick, asking Buildbucket for the build status
[12:39:59.616] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:39:59.616] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:112:0) after 1m0s
[12:40:59.681] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:112:0)
[12:40:59.681] Timer tick, asking Buildbucket for the build status
[12:40:59.829] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:40:59.829] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:113:0) after 1m0s
[12:41:59.941] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:113:0)
[12:41:59.941] Timer tick, asking Buildbucket for the build status
[12:42:00.554] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:42:00.554] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:114:0) after 1m0s
[12:43:00.609] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:114:0)
[12:43:00.609] Timer tick, asking Buildbucket for the build status
[12:43:01.000] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:43:01.000] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:115:0) after 1m0s
[12:44:01.059] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:115:0)
[12:44:01.059] Timer tick, asking Buildbucket for the build status
[12:44:01.206] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:44:01.206] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:116:0) after 1m0s
[12:45:01.282] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:116:0)
[12:45:01.282] Timer tick, asking Buildbucket for the build status
[12:45:01.628] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:45:01.628] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:117:0) after 1m0s
[12:46:01.646] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:117:0)
[12:46:01.647] Timer tick, asking Buildbucket for the build status
[12:46:01.885] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:46:01.885] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:118:0) after 1m0s
[12:47:01.941] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:118:0)
[12:47:01.941] Timer tick, asking Buildbucket for the build status
[12:47:02.512] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:47:02.512] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:119:0) after 1m0s
[12:48:02.602] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:119:0)
[12:48:02.602] Timer tick, asking Buildbucket for the build status
[12:48:02.738] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:48:02.738] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:120:0) after 1m0s
[12:49:02.808] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:120:0)
[12:49:02.808] Timer tick, asking Buildbucket for the build status
[12:49:03.426] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:49:03.426] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:121:0) after 1m0s
[12:50:03.527] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:121:0)
[12:50:03.527] Timer tick, asking Buildbucket for the build status
[12:50:04.090] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:50:04.090] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:122:0) after 1m0s
[12:51:04.223] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:122:0)
[12:51:04.223] Timer tick, asking Buildbucket for the build status
[12:51:04.371] Build 8896819668753733808: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:51:04.371] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9062249730827132880:123:0) after 1m0s
[12:51:49.312] Received PubSub notification, asking Buildbucket for the build status
[12:51:49.498] Build 8896819668753733808: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[12:51:49.498] Buildbucket build:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "PROD",
"completed_ts": "1573735908834747",
"created_by": "project:infra",
"created_ts": "1573728606419566",
"failure_reason": "BUILD_FAILURE",
"id": "8896819668753733808",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"80.0.3967.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"1a7ff3e9-98d4-417d-b474-4091479ccd7b\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"80.0.3967.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\": \"80.0.3967.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"1a7ff3e9-98d4-417d-b474-4091479ccd7b\", \"title\": \"publish_tarball/0\"}]}, \"bot_id\": \"luci-infra-cron-xenial-large-0-lmua\", \"buildername\": \"Build From Tarball\", \"path_config\": \"generic\", \"recipe\": \"build_from_tarball\", \"version\": \"80.0.3967.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-lmua\"], \"image\": [\"chrome-xenial-19111101-9a63619e779\"], \"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\": [\"4628-14f2294\"], \"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": "1573734449105351",
"status": "COMPLETED",
"status_changed_ts": "1573734449558901",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9062249730827132880",
"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/8896819668753733808/+/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:48825a9804036910",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1573735908937903",
"url": "https://ci.chromium.org/b/8896819668753733808",
"utcnow_ts": "1573735909460227"
}
}
[12:51:49.498] Invocation finished in 2h1m44.43996093s with status FAILED