[15:23:38.801] New invocation is queued and will start shortly
[15:23:38.801] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[15:23:40.025] Starting the invocation (attempt 1)
[15:23:40.184] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:23:40.184] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:23:40.184] Buildbucket request:
{
"bucket": "luci.infra.cron",
"client_operation_id": "9095209815566837680",
"parameters_json": "{\"builder_name\":\"Build From Tarball\",\"properties\":{\"version\":\"72.0.3611.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:9095209815566837680",
"scheduler_job_id:infra/Build From Tarball",
"user_agent:luci-scheduler",
"parent_buildername:publish_tarball",
"user_agent:recipe"
]
}
[15:23:41.543] Buildbucket response:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1542295420304469",
"id": "8929779753317384752",
"lease_expiration_ts": "1542414221430790",
"lease_key": "197265268",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"version\": \"72.0.3611.0\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1542295421431530",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9095209815566837680",
"scheduler_job_id:infra/Build From Tarball",
"swarming_dimension:builder:Build From Tarball",
"swarming_dimension:caches:builder_a26b12d8a59ca9041fe7666278599d55714efad5956e4752511581aec53352b0_v2",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Ubuntu-14.04",
"swarming_dimension:pool:luci.infra.cron",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:buildbucket_bucket:infra/cron",
"swarming_tag:buildbucket_build_id:8929779753317384752",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:1fc149ed7cdb2549b1387665915ec044aea4e328",
"swarming_tag:builder:Build From Tarball",
"swarming_tag:caches:builder_a26b12d8a59ca9041fe7666278599d55714efad5956e4752511581aec53352b0_v2",
"swarming_tag:cpu:x86-64",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8929779753317384752/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Ubuntu-14.04",
"swarming_tag:parent_buildername:publish_tarball",
"swarming_tag:pool:luci.infra.cron",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:build_from_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9095209815566837680",
"swarming_tag:scheduler_job_id:infra/Build From Tarball",
"swarming_tag:service_account:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:c00943b407e76550df4b2e19c30f4a883d9c39b2",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:user_agent:recipe",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:4130ca0818ec6a10",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1542295421431591",
"url": "https://ci.chromium.org/b/8929779753317384752",
"utcnow_ts": "1542295421533493"
}
}
[15:23:41.543] Task URL: https://ci.chromium.org/b/8929779753317384752
[15:23:41.543] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:2:0) after 1m0s
[15:24:01.477] Received PubSub notification, asking Buildbucket for the build status
[15:24:01.610] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:24:41.560] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:2:0)
[15:24:41.560] Timer tick, asking Buildbucket for the build status
[15:24:41.621] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:24:41.622] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:4:0) after 1m0s
[15:25:41.703] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:4:0)
[15:25:41.703] Timer tick, asking Buildbucket for the build status
[15:25:41.760] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:25:41.760] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:5:0) after 1m0s
[15:26:41.783] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:5:0)
[15:26:41.783] Timer tick, asking Buildbucket for the build status
[15:26:41.856] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:26:41.856] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:6:0) after 1m0s
[15:27:41.879] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:6:0)
[15:27:41.879] Timer tick, asking Buildbucket for the build status
[15:27:41.947] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:27:41.947] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:7:0) after 1m0s
[15:28:42.015] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:7:0)
[15:28:42.015] Timer tick, asking Buildbucket for the build status
[15:28:42.119] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:28:42.119] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:8:0) after 1m0s
[15:29:42.347] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:8:0)
[15:29:42.347] Timer tick, asking Buildbucket for the build status
[15:29:42.536] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:29:42.536] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:9:0) after 1m0s
[15:30:42.569] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:9:0)
[15:30:42.569] Timer tick, asking Buildbucket for the build status
[15:30:42.641] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:30:42.641] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:10:0) after 1m0s
[15:31:42.659] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:10:0)
[15:31:42.659] Timer tick, asking Buildbucket for the build status
[15:31:43.315] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:31:43.315] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:11:0) after 1m0s
[15:32:43.334] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:11:0)
[15:32:43.334] Timer tick, asking Buildbucket for the build status
[15:32:43.404] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:32:43.404] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:12:0) after 1m0s
[15:33:43.418] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:12:0)
[15:33:43.418] Timer tick, asking Buildbucket for the build status
[15:33:43.549] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:33:43.549] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:13:0) after 1m0s
[15:34:43.570] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:13:0)
[15:34:43.570] Timer tick, asking Buildbucket for the build status
[15:34:43.643] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:34:43.643] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:14:0) after 1m0s
[15:35:43.663] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:14:0)
[15:35:43.663] Timer tick, asking Buildbucket for the build status
[15:35:43.799] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:35:43.799] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:15:0) after 1m0s
[15:36:43.815] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:15:0)
[15:36:43.815] Timer tick, asking Buildbucket for the build status
[15:36:44.018] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:36:44.018] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:16:0) after 1m0s
[15:37:44.037] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:16:0)
[15:37:44.037] Timer tick, asking Buildbucket for the build status
[15:37:44.177] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:37:44.177] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:17:0) after 1m0s
[15:38:44.196] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:17:0)
[15:38:44.196] Timer tick, asking Buildbucket for the build status
[15:38:44.253] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:38:44.253] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:18:0) after 1m0s
[15:39:44.294] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:18:0)
[15:39:44.294] Timer tick, asking Buildbucket for the build status
[15:39:44.392] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:39:44.392] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:19:0) after 1m0s
[15:40:44.421] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:19:0)
[15:40:44.421] Timer tick, asking Buildbucket for the build status
[15:40:44.475] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:40:44.475] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:20:0) after 1m0s
[15:41:44.492] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:20:0)
[15:41:44.492] Timer tick, asking Buildbucket for the build status
[15:41:44.560] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:41:44.560] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:21:0) after 1m0s
[15:42:44.577] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:21:0)
[15:42:44.577] Timer tick, asking Buildbucket for the build status
[15:42:44.670] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:42:44.670] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:22:0) after 1m0s
[15:43:44.690] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:22:0)
[15:43:44.690] Timer tick, asking Buildbucket for the build status
[15:43:44.811] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:43:44.811] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:23:0) after 1m0s
[15:44:44.832] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:23:0)
[15:44:44.832] Timer tick, asking Buildbucket for the build status
[15:44:44.995] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:44:44.995] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:24:0) after 1m0s
[15:45:45.017] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:24:0)
[15:45:45.017] Timer tick, asking Buildbucket for the build status
[15:45:45.403] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:45:45.403] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:25:0) after 1m0s
[15:46:45.423] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:25:0)
[15:46:45.423] Timer tick, asking Buildbucket for the build status
[15:46:45.617] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:46:45.618] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:26:0) after 1m0s
[15:47:45.640] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:26:0)
[15:47:45.640] Timer tick, asking Buildbucket for the build status
[15:47:45.720] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:47:45.720] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:27:0) after 1m0s
[15:48:45.740] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:27:0)
[15:48:45.740] Timer tick, asking Buildbucket for the build status
[15:48:45.822] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:48:45.822] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:28:0) after 1m0s
[15:49:45.840] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:28:0)
[15:49:45.840] Timer tick, asking Buildbucket for the build status
[15:49:46.493] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:49:46.493] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:29:0) after 1m0s
[15:50:46.510] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:29:0)
[15:50:46.510] Timer tick, asking Buildbucket for the build status
[15:50:46.592] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:50:46.592] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:30:0) after 1m0s
[15:51:46.623] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:30:0)
[15:51:46.623] Timer tick, asking Buildbucket for the build status
[15:51:46.690] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:51:46.690] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:31:0) after 1m0s
[15:52:46.711] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:31:0)
[15:52:46.711] Timer tick, asking Buildbucket for the build status
[15:52:46.779] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:52:46.779] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:32:0) after 1m0s
[15:53:46.799] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:32:0)
[15:53:46.799] Timer tick, asking Buildbucket for the build status
[15:53:47.015] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:53:47.015] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:33:0) after 1m0s
[15:54:47.035] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:33:0)
[15:54:47.035] Timer tick, asking Buildbucket for the build status
[15:54:47.081] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:54:47.081] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:34:0) after 1m0s
[15:55:47.172] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:34:0)
[15:55:47.172] Timer tick, asking Buildbucket for the build status
[15:55:47.236] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:55:47.236] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:35:0) after 1m0s
[15:56:47.257] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:35:0)
[15:56:47.257] Timer tick, asking Buildbucket for the build status
[15:56:47.454] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:56:47.454] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:36:0) after 1m0s
[15:57:47.506] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:36:0)
[15:57:47.506] Timer tick, asking Buildbucket for the build status
[15:57:47.812] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:57:47.812] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:37:0) after 1m0s
[15:58:47.838] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:37:0)
[15:58:47.838] Timer tick, asking Buildbucket for the build status
[15:58:47.886] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:58:47.886] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:38:0) after 1m0s
[15:59:47.912] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:38:0)
[15:59:47.912] Timer tick, asking Buildbucket for the build status
[15:59:47.967] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:59:47.967] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:39:0) after 1m0s
[16:00:47.987] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:39:0)
[16:00:47.987] Timer tick, asking Buildbucket for the build status
[16:00:48.156] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:00:48.156] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:40:0) after 1m0s
[16:01:48.173] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:40:0)
[16:01:48.173] Timer tick, asking Buildbucket for the build status
[16:01:48.232] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:01:48.232] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:41:0) after 1m0s
[16:02:48.279] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:41:0)
[16:02:48.279] Timer tick, asking Buildbucket for the build status
[16:02:48.343] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:02:48.343] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:42:0) after 1m0s
[16:03:48.366] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:42:0)
[16:03:48.366] Timer tick, asking Buildbucket for the build status
[16:03:48.420] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:03:48.420] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:43:0) after 1m0s
[16:04:48.437] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:43:0)
[16:04:48.437] Timer tick, asking Buildbucket for the build status
[16:04:48.482] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:04:48.482] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:44:0) after 1m0s
[16:05:48.501] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:44:0)
[16:05:48.501] Timer tick, asking Buildbucket for the build status
[16:05:48.567] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:05:48.567] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:45:0) after 1m0s
[16:06:48.588] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:45:0)
[16:06:48.588] Timer tick, asking Buildbucket for the build status
[16:06:48.654] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:06:48.654] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:46:0) after 1m0s
[16:07:48.669] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:46:0)
[16:07:48.669] Timer tick, asking Buildbucket for the build status
[16:07:48.730] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:07:48.730] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:47:0) after 1m0s
[16:08:48.752] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:47:0)
[16:08:48.752] Timer tick, asking Buildbucket for the build status
[16:08:48.814] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:08:48.814] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:48:0) after 1m0s
[16:09:48.839] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:48:0)
[16:09:48.839] Timer tick, asking Buildbucket for the build status
[16:09:48.934] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:09:48.934] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:49:0) after 1m0s
[16:10:48.952] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:49:0)
[16:10:48.952] Timer tick, asking Buildbucket for the build status
[16:10:49.216] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:10:49.216] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:50:0) after 1m0s
[16:11:49.383] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:50:0)
[16:11:49.383] Timer tick, asking Buildbucket for the build status
[16:11:49.470] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:11:49.470] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:51:0) after 1m0s
[16:12:49.487] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:51:0)
[16:12:49.487] Timer tick, asking Buildbucket for the build status
[16:12:49.564] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:12:49.564] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:52:0) after 1m0s
[16:13:49.585] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:52:0)
[16:13:49.585] Timer tick, asking Buildbucket for the build status
[16:13:49.700] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:13:49.700] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:53:0) after 1m0s
[16:14:49.721] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:53:0)
[16:14:49.721] Timer tick, asking Buildbucket for the build status
[16:14:49.788] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:14:49.789] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:54:0) after 1m0s
[16:15:49.824] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:54:0)
[16:15:49.824] Timer tick, asking Buildbucket for the build status
[16:15:50.111] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:15:50.111] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:55:0) after 1m0s
[16:16:50.131] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:55:0)
[16:16:50.131] Timer tick, asking Buildbucket for the build status
[16:16:50.255] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:16:50.255] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:56:0) after 1m0s
[16:17:50.275] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:56:0)
[16:17:50.275] Timer tick, asking Buildbucket for the build status
[16:17:50.431] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:17:50.431] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:57:0) after 1m0s
[16:18:50.447] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:57:0)
[16:18:50.447] Timer tick, asking Buildbucket for the build status
[16:18:50.493] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:18:50.493] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:58:0) after 1m0s
[16:19:50.514] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:58:0)
[16:19:50.514] Timer tick, asking Buildbucket for the build status
[16:19:50.568] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:19:50.568] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:59:0) after 1m0s
[16:20:50.602] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:59:0)
[16:20:50.602] Timer tick, asking Buildbucket for the build status
[16:20:50.736] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:20:50.736] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:60:0) after 1m0s
[16:21:50.755] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:60:0)
[16:21:50.755] Timer tick, asking Buildbucket for the build status
[16:21:50.819] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:21:50.819] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:61:0) after 1m0s
[16:22:50.838] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:61:0)
[16:22:50.838] Timer tick, asking Buildbucket for the build status
[16:22:51.048] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:22:51.048] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:62:0) after 1m0s
[16:23:51.069] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:62:0)
[16:23:51.069] Timer tick, asking Buildbucket for the build status
[16:23:51.162] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:23:51.162] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:63:0) after 1m0s
[16:24:51.180] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:63:0)
[16:24:51.180] Timer tick, asking Buildbucket for the build status
[16:24:51.230] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:24:51.230] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:64:0) after 1m0s
[16:25:51.254] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:64:0)
[16:25:51.254] Timer tick, asking Buildbucket for the build status
[16:25:51.326] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:25:51.326] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:65:0) after 1m0s
[16:26:51.350] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:65:0)
[16:26:51.350] Timer tick, asking Buildbucket for the build status
[16:26:51.428] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:26:51.428] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:66:0) after 1m0s
[16:27:51.448] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:66:0)
[16:27:51.448] Timer tick, asking Buildbucket for the build status
[16:27:51.572] Build 8929779753317384752: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:27:51.572] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9095209815566837680:67:0) after 1m0s
[16:28:09.979] Received PubSub notification, asking Buildbucket for the build status
[16:28:10.017] Build 8929779753317384752: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[16:28:10.018] Buildbucket build:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "AUTO",
"completed_ts": "1542299288779655",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1542295420304469",
"failure_reason": "BUILD_FAILURE",
"id": "8929779753317384752",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"version\": \"72.0.3611.0\"}}",
"project": "infra",
"result": "FAILURE",
"result_details_json": "{\"ui\": {\"info\": \"Failure Bootstrap gn.\"}, \"swarming\": {\"bot_dimensions\": {\"machine_type\": [\"n1-standard-8\"], \"inside_docker\": [\"0\"], \"python\": [\"2.7.6\"], \"builder\": [\"Build From Tarball\"], \"kvm\": [\"1\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"server_version\": [\"3844-124e68f\"], \"image\": [\"chrome-trusty-18091700-38cc06ee3ee\"], \"gpu\": [\"none\"], \"cores\": [\"8\"], \"zone\": [\"us\", \"us-central\", \"us-central1\", \"us-central1-c\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-14.04\"], \"id\": [\"gce-trusty-canary-e973df7c-us-central1-c-rwnq\"], \"pool\": [\"luci.infra.cron\"], \"caches\": [\"vpython\"]}}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"buildername\": \"Build From Tarball\", \"recipe\": \"build_from_tarball\", \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"buildbucket\": {\"hostname\": \"cr-buildbucket.appspot.com\", \"build\": {\"created_ts\": 1542295420304469, \"tags\": [\"builder:Build From Tarball\", \"parent_buildername:publish_tarball\", \"scheduler_invocation_id:9095209815566837680\", \"scheduler_job_id:infra/Build From Tarball\", \"user_agent:luci-scheduler\", \"user_agent:recipe\"], \"bucket\": \"luci.infra.cron\", \"created_by\": \"user:luci-scheduler@appspot.gserviceaccount.com\", \"project\": \"infra\", \"id\": \"8929779753317384752\"}}, \"version\": \"72.0.3611.0\", \"path_config\": \"generic\", \"bot_id\": \"gce-trusty-canary-e973df7c-us-central1-c-rwnq\"}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1542295440399582",
"status": "COMPLETED",
"status_changed_ts": "1542299289482382",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9095209815566837680",
"scheduler_job_id:infra/Build From Tarball",
"swarming_dimension:builder:Build From Tarball",
"swarming_dimension:caches:builder_a26b12d8a59ca9041fe7666278599d55714efad5956e4752511581aec53352b0_v2",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Ubuntu-14.04",
"swarming_dimension:pool:luci.infra.cron",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:buildbucket_bucket:infra/cron",
"swarming_tag:buildbucket_build_id:8929779753317384752",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:1fc149ed7cdb2549b1387665915ec044aea4e328",
"swarming_tag:builder:Build From Tarball",
"swarming_tag:caches:builder_a26b12d8a59ca9041fe7666278599d55714efad5956e4752511581aec53352b0_v2",
"swarming_tag:cpu:x86-64",
"swarming_tag:log_location:logdog://logs.chromium.org/infra/buildbucket/cr-buildbucket.appspot.com/8929779753317384752/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Ubuntu-14.04",
"swarming_tag:parent_buildername:publish_tarball",
"swarming_tag:pool:luci.infra.cron",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:build_from_tarball",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9095209815566837680",
"swarming_tag:scheduler_job_id:infra/Build From Tarball",
"swarming_tag:service_account:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:c00943b407e76550df4b2e19c30f4a883d9c39b2",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:user_agent:recipe",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:4130ca0818ec6a10",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1542299289500018",
"url": "https://ci.chromium.org/b/8929779753317384752",
"utcnow_ts": "1542299290008940"
}
}
[16:28:10.018] Invocation finished in 1h4m31.242843332s with status FAILED