[12:37:02.160] New invocation is queued and will start shortly
[12:37:03.243] Starting the invocation (attempt 1)
[12:37:03.279] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[12:37:03.279] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[12:37:03.279] Buildbucket request:
{
"bucket": "luci.infra.cron",
"client_operation_id": "9081540155868478384",
"parameters_json": "{\"builder_name\":\"publish_tarball_dispatcher\",\"properties\":{}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:publish_tarball_dispatcher",
"scheduler_invocation_id:9081540155868478384",
"scheduler_job_id:infra/publish_tarball_dispatcher",
"user_agent:luci-scheduler"
]
}
[12:37:03.629] Buildbucket response:
{
"build": {
"bucket": "luci.infra.cron",
"canary": true,
"canary_preference": "AUTO",
"created_by": "project:infra",
"created_ts": "1555331823402725",
"id": "8916110093902235344",
"parameters_json": "{\"builder_name\": \"publish_tarball_dispatcher\", \"properties\": {}}",
"project": "infra",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1555331823532773",
"tags": [
"builder:publish_tarball_dispatcher",
"scheduler_invocation_id:9081540155868478384",
"scheduler_job_id:infra/publish_tarball_dispatcher",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8916110093902235344/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:recipe_name:publish_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_task_id:",
"user_agent:luci-scheduler"
],
"updated_ts": "1555331823532937",
"url": "https://ci.chromium.org/b/8916110093902235344",
"utcnow_ts": "1555331823620038"
}
}
[12:37:03.629] Task URL: https://ci.chromium.org/b/8916110093902235344
[12:37:03.629] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:2:0) after 1m0s
[12:38:03.646] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:2:0)
[12:38:03.646] Timer tick, asking Buildbucket for the build status
[12:38:03.771] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:38:03.771] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:3:0) after 1m0s
[12:39:03.782] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:3:0)
[12:39:03.782] Timer tick, asking Buildbucket for the build status
[12:39:03.977] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:39:03.977] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:4:0) after 1m0s
[12:40:03.993] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:4:0)
[12:40:03.993] Timer tick, asking Buildbucket for the build status
[12:40:04.075] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:40:04.075] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:5:0) after 1m0s
[12:41:04.096] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:5:0)
[12:41:04.096] Timer tick, asking Buildbucket for the build status
[12:41:04.190] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:41:04.190] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:6:0) after 1m0s
[12:42:04.227] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:6:0)
[12:42:04.227] Timer tick, asking Buildbucket for the build status
[12:42:04.392] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:42:04.392] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:7:0) after 1m0s
[12:43:04.417] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:7:0)
[12:43:04.417] Timer tick, asking Buildbucket for the build status
[12:43:04.481] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:43:04.481] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:8:0) after 1m0s
[12:44:04.522] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:8:0)
[12:44:04.522] Timer tick, asking Buildbucket for the build status
[12:44:04.591] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:44:04.591] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:9:0) after 1m0s
[12:45:04.608] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:9:0)
[12:45:04.608] Timer tick, asking Buildbucket for the build status
[12:45:04.665] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:45:04.665] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:10:0) after 1m0s
[12:46:04.692] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:10:0)
[12:46:04.692] Timer tick, asking Buildbucket for the build status
[12:46:04.790] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:46:04.790] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:11:0) after 1m0s
[12:47:04.792] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:11:0)
[12:47:04.792] Timer tick, asking Buildbucket for the build status
[12:47:04.866] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:47:04.866] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:12:0) after 1m0s
[12:48:04.907] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:12:0)
[12:48:04.907] Timer tick, asking Buildbucket for the build status
[12:48:05.001] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:48:05.002] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:13:0) after 1m0s
[12:49:05.019] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:13:0)
[12:49:05.019] Timer tick, asking Buildbucket for the build status
[12:49:05.097] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:49:05.098] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:14:0) after 1m0s
[12:50:05.125] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:14:0)
[12:50:05.125] Timer tick, asking Buildbucket for the build status
[12:50:05.359] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:50:05.359] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:15:0) after 1m0s
[12:51:05.391] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:15:0)
[12:51:05.391] Timer tick, asking Buildbucket for the build status
[12:51:05.711] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:51:05.711] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:16:0) after 1m0s
[12:52:05.738] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:16:0)
[12:52:05.738] Timer tick, asking Buildbucket for the build status
[12:52:06.064] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:52:06.064] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:17:0) after 1m0s
[12:53:06.073] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:17:0)
[12:53:06.073] Timer tick, asking Buildbucket for the build status
[12:53:06.158] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:53:06.158] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:18:0) after 1m0s
[12:54:06.193] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:18:0)
[12:54:06.194] Timer tick, asking Buildbucket for the build status
[12:54:06.277] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:54:06.277] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:19:0) after 1m0s
[12:55:06.428] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:19:0)
[12:55:06.428] Timer tick, asking Buildbucket for the build status
[12:55:06.503] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:55:06.503] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:20:0) after 1m0s
[12:56:06.532] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:20:0)
[12:56:06.532] Timer tick, asking Buildbucket for the build status
[12:56:06.678] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:56:06.678] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:21:0) after 1m0s
[12:57:06.696] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:21:0)
[12:57:06.696] Timer tick, asking Buildbucket for the build status
[12:57:06.885] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:57:06.885] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:22:0) after 1m0s
[12:58:06.909] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:22:0)
[12:58:06.909] Timer tick, asking Buildbucket for the build status
[12:58:07.009] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:58:07.009] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:23:0) after 1m0s
[12:59:07.007] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:23:0)
[12:59:07.007] Timer tick, asking Buildbucket for the build status
[12:59:07.085] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:59:07.085] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:24:0) after 1m0s
[13:00:07.126] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:24:0)
[13:00:07.126] Timer tick, asking Buildbucket for the build status
[13:00:07.292] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:00:07.292] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:25:0) after 1m0s
[13:01:07.351] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:25:0)
[13:01:07.352] Timer tick, asking Buildbucket for the build status
[13:01:08.379] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:01:08.379] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:26:0) after 1m0s
[13:02:08.399] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:26:0)
[13:02:08.399] Timer tick, asking Buildbucket for the build status
[13:02:08.599] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:02:08.599] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:27:0) after 1m0s
[13:03:08.574] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:27:0)
[13:03:08.574] Timer tick, asking Buildbucket for the build status
[13:03:08.639] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:03:08.639] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:28:0) after 1m0s
[13:04:08.659] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:28:0)
[13:04:08.659] Timer tick, asking Buildbucket for the build status
[13:04:08.922] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:04:08.922] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:29:0) after 1m0s
[13:05:08.933] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:29:0)
[13:05:08.933] Timer tick, asking Buildbucket for the build status
[13:05:09.001] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:05:09.001] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:30:0) after 1m0s
[13:06:09.038] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:30:0)
[13:06:09.038] Timer tick, asking Buildbucket for the build status
[13:06:09.205] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:06:09.205] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:31:0) after 1m0s
[13:07:09.214] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:31:0)
[13:07:09.214] Timer tick, asking Buildbucket for the build status
[13:07:09.285] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:07:09.285] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:32:0) after 1m0s
[13:08:09.303] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:32:0)
[13:08:09.303] Timer tick, asking Buildbucket for the build status
[13:08:09.356] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:08:09.356] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:33:0) after 1m0s
[13:09:09.379] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:33:0)
[13:09:09.379] Timer tick, asking Buildbucket for the build status
[13:09:09.449] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:09:09.449] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:34:0) after 1m0s
[13:10:09.469] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:34:0)
[13:10:09.469] Timer tick, asking Buildbucket for the build status
[13:10:09.637] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:10:09.637] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:35:0) after 1m0s
[13:11:09.672] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:35:0)
[13:11:09.672] Timer tick, asking Buildbucket for the build status
[13:11:09.758] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:11:09.758] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:36:0) after 1m0s
[13:12:09.810] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:36:0)
[13:12:09.810] Timer tick, asking Buildbucket for the build status
[13:12:09.901] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:12:09.901] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:37:0) after 1m0s
[13:13:09.949] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:37:0)
[13:13:09.949] Timer tick, asking Buildbucket for the build status
[13:13:10.032] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:13:10.032] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:38:0) after 1m0s
[13:14:10.056] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:38:0)
[13:14:10.056] Timer tick, asking Buildbucket for the build status
[13:14:10.195] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:14:10.195] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:39:0) after 1m0s
[13:15:10.222] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:39:0)
[13:15:10.222] Timer tick, asking Buildbucket for the build status
[13:15:10.459] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:15:10.459] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:40:0) after 1m0s
[13:16:10.479] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:40:0)
[13:16:10.479] Timer tick, asking Buildbucket for the build status
[13:16:10.734] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:16:10.734] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:41:0) after 1m0s
[13:17:10.786] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:41:0)
[13:17:10.786] Timer tick, asking Buildbucket for the build status
[13:17:10.902] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:17:10.902] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:42:0) after 1m0s
[13:18:10.926] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:42:0)
[13:18:10.926] Timer tick, asking Buildbucket for the build status
[13:18:11.052] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:18:11.052] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:43:0) after 1m0s
[13:19:11.072] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:43:0)
[13:19:11.072] Timer tick, asking Buildbucket for the build status
[13:19:11.175] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:19:11.175] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:44:0) after 1m0s
[13:20:11.170] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:44:0)
[13:20:11.170] Timer tick, asking Buildbucket for the build status
[13:20:11.351] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:20:11.351] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:45:0) after 1m0s
[13:21:11.374] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:45:0)
[13:21:11.374] Timer tick, asking Buildbucket for the build status
[13:21:11.474] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:21:11.474] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:46:0) after 1m0s
[13:22:11.492] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:46:0)
[13:22:11.492] Timer tick, asking Buildbucket for the build status
[13:22:11.688] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:22:11.688] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:47:0) after 1m0s
[13:23:11.711] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:47:0)
[13:23:11.711] Timer tick, asking Buildbucket for the build status
[13:23:11.763] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:23:11.763] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:48:0) after 1m0s
[13:24:11.768] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:48:0)
[13:24:11.768] Timer tick, asking Buildbucket for the build status
[13:24:11.933] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:24:11.933] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:49:0) after 1m0s
[13:25:11.958] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:49:0)
[13:25:11.958] Timer tick, asking Buildbucket for the build status
[13:25:12.024] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:25:12.024] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:50:0) after 1m0s
[13:26:12.045] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:50:0)
[13:26:12.045] Timer tick, asking Buildbucket for the build status
[13:26:12.243] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:26:12.243] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:51:0) after 1m0s
[13:27:12.266] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:51:0)
[13:27:12.266] Timer tick, asking Buildbucket for the build status
[13:27:12.397] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:27:12.398] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:52:0) after 1m0s
[13:28:12.420] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:52:0)
[13:28:12.420] Timer tick, asking Buildbucket for the build status
[13:28:12.497] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:28:12.497] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:53:0) after 1m0s
[13:29:12.497] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:53:0)
[13:29:12.497] Timer tick, asking Buildbucket for the build status
[13:29:12.604] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:29:12.604] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:54:0) after 1m0s
[13:30:12.632] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:54:0)
[13:30:12.632] Timer tick, asking Buildbucket for the build status
[13:30:12.919] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:30:12.919] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:55:0) after 1m0s
[13:31:12.913] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:55:0)
[13:31:12.913] Timer tick, asking Buildbucket for the build status
[13:31:13.022] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:31:13.022] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:56:0) after 1m0s
[13:32:13.039] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:56:0)
[13:32:13.039] Timer tick, asking Buildbucket for the build status
[13:32:13.172] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:32:13.172] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:57:0) after 1m0s
[13:33:13.200] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:57:0)
[13:33:13.200] Timer tick, asking Buildbucket for the build status
[13:33:13.283] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:33:13.283] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:58:0) after 1m0s
[13:34:13.291] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:58:0)
[13:34:13.291] Timer tick, asking Buildbucket for the build status
[13:34:13.364] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:34:13.364] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:59:0) after 1m0s
[13:35:13.381] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:59:0)
[13:35:13.381] Timer tick, asking Buildbucket for the build status
[13:35:13.510] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:35:13.510] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:60:0) after 1m0s
[13:36:13.534] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:60:0)
[13:36:13.534] Timer tick, asking Buildbucket for the build status
[13:36:13.683] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:36:13.683] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:61:0) after 1m0s
[13:37:13.700] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:61:0)
[13:37:13.700] Timer tick, asking Buildbucket for the build status
[13:37:13.806] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:37:13.806] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:62:0) after 1m0s
[13:38:13.829] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:62:0)
[13:38:13.829] Timer tick, asking Buildbucket for the build status
[13:38:13.911] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:38:13.911] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:63:0) after 1m0s
[13:39:13.932] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:63:0)
[13:39:13.932] Timer tick, asking Buildbucket for the build status
[13:39:14.168] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:39:14.168] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:64:0) after 1m0s
[13:40:14.175] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:64:0)
[13:40:14.175] Timer tick, asking Buildbucket for the build status
[13:40:14.385] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:40:14.386] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:65:0) after 1m0s
[13:41:14.390] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:65:0)
[13:41:14.390] Timer tick, asking Buildbucket for the build status
[13:41:14.499] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:41:14.499] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:66:0) after 1m0s
[13:42:14.482] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:66:0)
[13:42:14.482] Timer tick, asking Buildbucket for the build status
[13:42:14.611] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:42:14.611] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:67:0) after 1m0s
[13:43:14.635] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:67:0)
[13:43:14.635] Timer tick, asking Buildbucket for the build status
[13:43:14.836] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:43:14.837] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:68:0) after 1m0s
[13:44:14.857] Handling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:68:0)
[13:44:14.857] Timer tick, asking Buildbucket for the build status
[13:44:15.010] Build 8916110093902235344: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[13:44:15.010] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball_dispatcher:9081540155868478384:69:0) after 1m0s
[13:44:31.056] Received PubSub notification, asking Buildbucket for the build status
[13:44:31.206] Build 8916110093902235344: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:45:02.568] Received PubSub notification, asking Buildbucket for the build status
[13:45:02.680] Build 8916110093902235344: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[13:45:02.680] Buildbucket build:
{
"build": {
"bucket": "luci.infra.cron",
"canary": true,
"canary_preference": "AUTO",
"completed_ts": "1555335901892392",
"created_by": "project:infra",
"created_ts": "1555331823402725",
"id": "8916110093902235344",
"parameters_json": "{\"builder_name\": \"publish_tarball_dispatcher\", \"properties\": {}}",
"project": "infra",
"result": "SUCCESS",
"result_details_json": "{\"properties\": {\"$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}, \"bot_id\": \"publish-tarball-0-jsz3\", \"buildername\": \"publish_tarball_dispatcher\", \"path_config\": \"generic\", \"recipe\": \"publish_tarball\"}, \"swarming\": {\"bot_dimensions\": {\"builder\": [\"publish_tarball\"], \"caches\": [\"git\", \"vpython\"], \"cores\": [\"8\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"publish-tarball-0-jsz3\"], \"image\": [\"chrome-trusty-18091700-38cc06ee3ee\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"machine_type\": [\"n1-standard-8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-14.04\"], \"pool\": [\"luci.infra.cron\"], \"python\": [\"2.7.6\"], \"server_version\": [\"4253-3d44409\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1555335870428393",
"status": "COMPLETED",
"status_changed_ts": "1555335902205963",
"tags": [
"builder:publish_tarball_dispatcher",
"scheduler_invocation_id:9081540155868478384",
"scheduler_job_id:infra/publish_tarball_dispatcher",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8916110093902235344/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Linux",
"swarming_tag:recipe_name:publish_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_task_id:4439d1c0f7fa3f10",
"user_agent:luci-scheduler"
],
"updated_ts": "1555335902209712",
"url": "https://ci.chromium.org/b/8916110093902235344",
"utcnow_ts": "1555335902670097"
}
}
[13:45:02.680] Invocation finished in 1h8m0.535830105s with status SUCCEEDED