[11:00:42.172] New invocation is queued and will start shortly
[11:00:42.172] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[11:00:43.249] Starting the invocation (attempt 1)
[11:00:43.299] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[11:00:43.299] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[11:00:43.299] Buildbucket request:
{
"bucket": "luci.infra.cron",
"client_operation_id": "9067050702003440496",
"parameters_json": "{\"builder_name\":\"Build From Tarball\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"buildbucket\":{\"properties\":{\"version\":\"79.0.3920.0\"},\"tags\":[\"parent_buildername:publish_tarball\",\"user_agent:recipe\"]},\"id\":\"4d5bcfb5-21d1-4f00-b696-0bbe8a96e8f8\",\"title\":\"publish_tarball/0\"}]},\"version\":\"79.0.3920.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:9067050702003440496",
"scheduler_job_id:infra/Build From Tarball",
"user_agent:luci-scheduler",
"parent_buildername:publish_tarball",
"user_agent:recipe"
]
}
[11:00:44.050] Buildbucket response:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "PROD",
"created_by": "project:infra",
"created_ts": "1569150043440445",
"id": "8901620640008255920",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3920.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"4d5bcfb5-21d1-4f00-b696-0bbe8a96e8f8\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"79.0.3920.0\"}}",
"project": "infra",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1569150043791693",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9067050702003440496",
"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/8901620640008255920/+/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": "1569150043791869",
"url": "https://ci.chromium.org/b/8901620640008255920",
"utcnow_ts": "1569150044037526"
}
}
[11:00:44.050] Task URL: https://ci.chromium.org/b/8901620640008255920
[11:00:44.050] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:2:0) after 1m0s
[11:01:44.236] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:2:0)
[11:01:44.236] Timer tick, asking Buildbucket for the build status
[11:01:44.380] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:01:44.380] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:3:0) after 1m0s
[11:02:44.608] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:3:0)
[11:02:44.608] Timer tick, asking Buildbucket for the build status
[11:02:44.754] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:02:44.754] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:4:0) after 1m0s
[11:03:44.782] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:4:0)
[11:03:44.782] Timer tick, asking Buildbucket for the build status
[11:03:44.932] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:03:44.932] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:5:0) after 1m0s
[11:04:44.966] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:5:0)
[11:04:44.966] Timer tick, asking Buildbucket for the build status
[11:04:45.136] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:04:45.136] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:6:0) after 1m0s
[11:05:45.563] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:6:0)
[11:05:45.563] Timer tick, asking Buildbucket for the build status
[11:05:45.820] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:05:45.820] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:7:0) after 1m0s
[11:06:45.851] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:7:0)
[11:06:45.851] Timer tick, asking Buildbucket for the build status
[11:06:46.073] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:06:46.073] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:8:0) after 1m0s
[11:07:46.191] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:8:0)
[11:07:46.191] Timer tick, asking Buildbucket for the build status
[11:07:46.776] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:07:46.776] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:9:0) after 1m0s
[11:08:47.037] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:9:0)
[11:08:47.037] Timer tick, asking Buildbucket for the build status
[11:08:47.909] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:08:47.909] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:10:0) after 1m0s
[11:09:47.996] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:10:0)
[11:09:47.996] Timer tick, asking Buildbucket for the build status
[11:09:48.395] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:09:48.395] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:11:0) after 1m0s
[11:10:49.472] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:11:0)
[11:10:49.472] Timer tick, asking Buildbucket for the build status
[11:10:49.741] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:10:49.741] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:12:0) after 1m0s
[11:11:50.621] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:12:0)
[11:11:50.621] Timer tick, asking Buildbucket for the build status
[11:11:51.668] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:11:51.668] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:13:0) after 1m0s
[11:12:52.413] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:13:0)
[11:12:52.413] Timer tick, asking Buildbucket for the build status
[11:12:52.634] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:12:52.634] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:14:0) after 1m0s
[11:13:52.732] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:14:0)
[11:13:52.732] Timer tick, asking Buildbucket for the build status
[11:13:52.918] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:13:52.918] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:15:0) after 1m0s
[11:14:53.274] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:15:0)
[11:14:53.274] Timer tick, asking Buildbucket for the build status
[11:14:53.437] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:14:53.437] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:16:0) after 1m0s
[11:15:53.457] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:16:0)
[11:15:53.457] Timer tick, asking Buildbucket for the build status
[11:15:53.601] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:15:53.601] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:17:0) after 1m0s
[11:16:53.770] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:17:0)
[11:16:53.770] Timer tick, asking Buildbucket for the build status
[11:16:54.121] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:16:54.121] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:18:0) after 1m0s
[11:17:54.148] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:18:0)
[11:17:54.148] Timer tick, asking Buildbucket for the build status
[11:17:54.296] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:17:54.296] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:19:0) after 1m0s
[11:18:54.432] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:19:0)
[11:18:54.432] Timer tick, asking Buildbucket for the build status
[11:18:54.847] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:18:54.847] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:20:0) after 1m0s
[11:19:55.343] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:20:0)
[11:19:55.343] Timer tick, asking Buildbucket for the build status
[11:19:59.428] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:19:59.428] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:21:0) after 1m0s
[11:20:59.680] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:21:0)
[11:20:59.680] Timer tick, asking Buildbucket for the build status
[11:20:59.952] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:20:59.952] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:22:0) after 1m0s
[11:21:59.987] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:22:0)
[11:21:59.987] Timer tick, asking Buildbucket for the build status
[11:22:00.177] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:22:00.177] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:23:0) after 1m0s
[11:23:00.290] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:23:0)
[11:23:00.290] Timer tick, asking Buildbucket for the build status
[11:23:00.624] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:23:00.624] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:24:0) after 1m0s
[11:24:00.893] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:24:0)
[11:24:00.893] Timer tick, asking Buildbucket for the build status
[11:24:01.203] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:24:01.203] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:25:0) after 1m0s
[11:25:01.336] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:25:0)
[11:25:01.336] Timer tick, asking Buildbucket for the build status
[11:25:01.611] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:25:01.611] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:26:0) after 1m0s
[11:26:01.664] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:26:0)
[11:26:01.664] Timer tick, asking Buildbucket for the build status
[11:26:01.854] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:26:01.854] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:27:0) after 1m0s
[11:27:02.327] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:27:0)
[11:27:02.327] Timer tick, asking Buildbucket for the build status
[11:27:02.702] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:27:02.702] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:28:0) after 1m0s
[11:28:25.209] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:28:0)
[11:28:25.209] Timer tick, asking Buildbucket for the build status
[11:28:25.619] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:28:25.619] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:29:0) after 1m0s
[11:29:25.678] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:29:0)
[11:29:25.678] Timer tick, asking Buildbucket for the build status
[11:29:25.967] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:29:25.967] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:30:0) after 1m0s
[11:30:25.991] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:30:0)
[11:30:25.991] Timer tick, asking Buildbucket for the build status
[11:30:26.209] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:30:26.209] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:31:0) after 1m0s
[11:31:26.248] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:31:0)
[11:31:26.248] Timer tick, asking Buildbucket for the build status
[11:31:26.503] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:31:26.503] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:32:0) after 1m0s
[11:32:26.573] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:32:0)
[11:32:26.573] Timer tick, asking Buildbucket for the build status
[11:32:27.078] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:32:27.078] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:33:0) after 1m0s
[11:33:27.124] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:33:0)
[11:33:27.125] Timer tick, asking Buildbucket for the build status
[11:33:27.223] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:33:27.223] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:34:0) after 1m0s
[11:34:27.333] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:34:0)
[11:34:27.333] Timer tick, asking Buildbucket for the build status
[11:34:27.507] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:34:27.507] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:35:0) after 1m0s
[11:35:27.611] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:35:0)
[11:35:27.611] Timer tick, asking Buildbucket for the build status
[11:35:28.986] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:35:28.986] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:36:0) after 1m0s
[11:36:29.026] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:36:0)
[11:36:29.026] Timer tick, asking Buildbucket for the build status
[11:36:29.293] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:36:29.293] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:37:0) after 1m0s
[11:37:29.293] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:37:0)
[11:37:29.293] Timer tick, asking Buildbucket for the build status
[11:37:29.401] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:37:29.401] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:38:0) after 1m0s
[11:38:29.499] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:38:0)
[11:38:29.499] Timer tick, asking Buildbucket for the build status
[11:38:29.673] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:38:29.673] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:39:0) after 1m0s
[11:39:30.741] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:39:0)
[11:39:30.741] Timer tick, asking Buildbucket for the build status
[11:39:33.798] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:39:33.799] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:40:0) after 1m0s
[11:40:34.455] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:40:0)
[11:40:34.455] Timer tick, asking Buildbucket for the build status
[11:40:34.587] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:40:34.587] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:41:0) after 1m0s
[11:41:35.030] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:41:0)
[11:41:35.030] Timer tick, asking Buildbucket for the build status
[11:41:35.182] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:41:35.182] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:42:0) after 1m0s
[11:42:35.357] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:42:0)
[11:42:35.357] Timer tick, asking Buildbucket for the build status
[11:42:35.532] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:42:35.532] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:43:0) after 1m0s
[11:43:35.932] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:43:0)
[11:43:35.932] Timer tick, asking Buildbucket for the build status
[11:43:36.038] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:43:36.038] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:44:0) after 1m0s
[11:44:36.201] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:44:0)
[11:44:36.201] Timer tick, asking Buildbucket for the build status
[11:44:36.505] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:44:36.505] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:45:0) after 1m0s
[11:45:36.652] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:45:0)
[11:45:36.652] Timer tick, asking Buildbucket for the build status
[11:45:36.853] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:45:36.853] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:46:0) after 1m0s
[11:46:36.905] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:46:0)
[11:46:36.905] Timer tick, asking Buildbucket for the build status
[11:46:46.419] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:46:46.419] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:47:0) after 1m0s
[11:47:46.673] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:47:0)
[11:47:46.673] Timer tick, asking Buildbucket for the build status
[11:47:46.907] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:47:46.907] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:48:0) after 1m0s
[11:48:46.930] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:48:0)
[11:48:46.930] Timer tick, asking Buildbucket for the build status
[11:48:47.116] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:48:47.116] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:49:0) after 1m0s
[11:49:47.295] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:49:0)
[11:49:47.295] Timer tick, asking Buildbucket for the build status
[11:49:47.544] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:49:47.545] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:50:0) after 1m0s
[11:50:47.632] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:50:0)
[11:50:47.632] Timer tick, asking Buildbucket for the build status
[11:50:47.816] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:50:47.816] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:51:0) after 1m0s
[11:51:47.967] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:51:0)
[11:51:47.967] Timer tick, asking Buildbucket for the build status
[11:51:48.488] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:51:48.489] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:52:0) after 1m0s
[11:52:48.729] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:52:0)
[11:52:48.729] Timer tick, asking Buildbucket for the build status
[11:52:48.968] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:52:48.968] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:53:0) after 1m0s
[11:53:49.005] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:53:0)
[11:53:49.005] Timer tick, asking Buildbucket for the build status
[11:53:49.325] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:53:49.325] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:54:0) after 1m0s
[11:54:49.409] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:54:0)
[11:54:49.409] Timer tick, asking Buildbucket for the build status
[11:54:49.873] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:54:49.873] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:55:0) after 1m0s
[11:55:49.943] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:55:0)
[11:55:49.943] Timer tick, asking Buildbucket for the build status
[11:55:50.148] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:55:50.148] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:56:0) after 1m0s
[11:56:50.267] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:56:0)
[11:56:50.267] Timer tick, asking Buildbucket for the build status
[11:56:50.476] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:56:50.476] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:57:0) after 1m0s
[11:57:50.642] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:57:0)
[11:57:50.642] Timer tick, asking Buildbucket for the build status
[11:57:51.019] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:57:51.019] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:58:0) after 1m0s
[11:58:51.082] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:58:0)
[11:58:51.082] Timer tick, asking Buildbucket for the build status
[11:58:51.307] Build 8901620640008255920: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:58:51.307] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:59:0) after 1m0s
[11:59:51.351] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:59:0)
[11:59:51.351] Timer tick, asking Buildbucket for the build status
[11:59:51.534] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:59:51.534] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:60:0) after 1m0s
[11:59:51.821] Received PubSub notification, asking Buildbucket for the build status
[11:59:52.314] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:00:51.610] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:60:0)
[12:00:51.610] Timer tick, asking Buildbucket for the build status
[12:00:52.008] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:00:52.008] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:62:0) after 1m0s
[12:01:52.137] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:62:0)
[12:01:52.137] Timer tick, asking Buildbucket for the build status
[12:01:52.329] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:01:52.330] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:63:0) after 1m0s
[12:02:52.433] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:63:0)
[12:02:52.433] Timer tick, asking Buildbucket for the build status
[12:02:52.847] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:02:52.847] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:64:0) after 1m0s
[12:03:53.054] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:64:0)
[12:03:53.054] Timer tick, asking Buildbucket for the build status
[12:03:53.582] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:03:53.582] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:65:0) after 1m0s
[12:04:53.741] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:65:0)
[12:04:53.741] Timer tick, asking Buildbucket for the build status
[12:04:53.898] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:04:53.898] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:66:0) after 1m0s
[12:05:54.019] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:66:0)
[12:05:54.019] Timer tick, asking Buildbucket for the build status
[12:05:54.236] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:05:54.236] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:67:0) after 1m0s
[12:06:54.280] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:67:0)
[12:06:54.280] Timer tick, asking Buildbucket for the build status
[12:06:54.552] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:06:54.552] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:68:0) after 1m0s
[12:07:54.892] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:68:0)
[12:07:54.892] Timer tick, asking Buildbucket for the build status
[12:07:55.250] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:07:55.250] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:69:0) after 1m0s
[12:08:55.466] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:69:0)
[12:08:55.466] Timer tick, asking Buildbucket for the build status
[12:08:55.829] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:08:55.829] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:70:0) after 1m0s
[12:09:55.976] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:70:0)
[12:09:55.976] Timer tick, asking Buildbucket for the build status
[12:09:56.372] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:09:56.372] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:71:0) after 1m0s
[12:10:56.449] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:71:0)
[12:10:56.449] Timer tick, asking Buildbucket for the build status
[12:10:56.985] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:10:56.985] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:72:0) after 1m0s
[12:11:57.034] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:72:0)
[12:11:57.034] Timer tick, asking Buildbucket for the build status
[12:11:57.456] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:11:57.456] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:73:0) after 1m0s
[12:12:57.510] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:73:0)
[12:12:57.510] Timer tick, asking Buildbucket for the build status
[12:12:57.650] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:12:57.650] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:74:0) after 1m0s
[12:13:57.698] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:74:0)
[12:13:57.698] Timer tick, asking Buildbucket for the build status
[12:13:58.341] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:13:58.341] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:75:0) after 1m0s
[12:14:58.423] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:75:0)
[12:14:58.423] Timer tick, asking Buildbucket for the build status
[12:14:58.539] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:14:58.539] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:76:0) after 1m0s
[12:15:58.654] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:76:0)
[12:15:58.654] Timer tick, asking Buildbucket for the build status
[12:15:58.902] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:15:58.903] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:77:0) after 1m0s
[12:16:58.972] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:77:0)
[12:16:58.972] Timer tick, asking Buildbucket for the build status
[12:16:59.229] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:16:59.229] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:78:0) after 1m0s
[12:17:59.257] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:78:0)
[12:17:59.257] Timer tick, asking Buildbucket for the build status
[12:17:59.447] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:17:59.447] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:79:0) after 1m0s
[12:18:59.497] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:79:0)
[12:18:59.497] Timer tick, asking Buildbucket for the build status
[12:18:59.639] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:18:59.639] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:80:0) after 1m0s
[12:19:59.747] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:80:0)
[12:19:59.747] Timer tick, asking Buildbucket for the build status
[12:20:00.098] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:20:00.098] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:81:0) after 1m0s
[12:21:00.242] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:81:0)
[12:21:00.242] Timer tick, asking Buildbucket for the build status
[12:21:00.417] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:21:00.417] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:82:0) after 1m0s
[12:22:00.500] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:82:0)
[12:22:00.501] Timer tick, asking Buildbucket for the build status
[12:22:00.715] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:22:00.715] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:83:0) after 1m0s
[12:23:00.803] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:83:0)
[12:23:00.803] Timer tick, asking Buildbucket for the build status
[12:23:02.552] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:23:02.553] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:84:0) after 1m0s
[12:24:02.575] Handling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:84:0)
[12:24:02.575] Timer tick, asking Buildbucket for the build status
[12:24:02.729] Build 8901620640008255920: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:24:02.729] Scheduling timer "check-buildbucket-build-status" (infra/Build From Tarball:9067050702003440496:85:0) after 1m0s
[12:24:25.980] Received PubSub notification, asking Buildbucket for the build status
[12:24:26.091] Build 8901620640008255920: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[12:24:26.091] Buildbucket build:
{
"build": {
"bucket": "luci.infra.cron",
"canary_preference": "PROD",
"completed_ts": "1569155065191808",
"created_by": "project:infra",
"created_ts": "1569150043440445",
"failure_reason": "BUILD_FAILURE",
"id": "8901620640008255920",
"parameters_json": "{\"builder_name\": \"Build From Tarball\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3920.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"4d5bcfb5-21d1-4f00-b696-0bbe8a96e8f8\", \"title\": \"publish_tarball/0\"}]}, \"version\": \"79.0.3920.0\"}}",
"project": "infra",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('Download nodejs.') (retcode: 1)\"}, \"properties\": {\"$gatekeeper\": {\"group\": \"chromium.infra.cron\"}, \"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"buildbucket\": {\"properties\": {\"version\": \"79.0.3920.0\"}, \"tags\": [\"parent_buildername:publish_tarball\", \"user_agent:recipe\"]}, \"id\": \"4d5bcfb5-21d1-4f00-b696-0bbe8a96e8f8\", \"title\": \"publish_tarball/0\"}]}, \"bot_id\": \"luci-infra-cron-xenial-large-0-aepm\", \"buildername\": \"Build From Tarball\", \"path_config\": \"generic\", \"recipe\": \"build_from_tarball\", \"version\": \"79.0.3920.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-aepm\"], \"image\": [\"chrome-xenial-19090600-ed917d8233f\"], \"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\": [\"4443-3a52fcb\"], \"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": "1569153590794371",
"status": "COMPLETED",
"status_changed_ts": "1569153591253280",
"tags": [
"builder:Build From Tarball",
"parent_buildername:publish_tarball",
"scheduler_invocation_id:9067050702003440496",
"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/8901620640008255920/+/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:47717310b8154710",
"user_agent:luci-scheduler",
"user_agent:recipe"
],
"updated_ts": "1569155065270995",
"url": "https://ci.chromium.org/b/8901620640008255920",
"utcnow_ts": "1569155066064254"
}
}
[12:24:26.091] Invocation finished in 1h23m43.937693578s with status FAILED