[20:59:13.018] New invocation is queued and will start shortly
[20:59:14.363] Starting the invocation (attempt 1)
[20:59:14.430] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:59:14.430] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:59:14.430] Buildbucket request:
{
"bucket": "luci.nacl.ci",
"client_operation_id": "9092561391275315664",
"parameters_json": "{\"builder_name\":\"linux_64-newlib-x86_64-pnacl-spec\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"af5947d13e6794eac489365ff58fd45c0dd4ca2a\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux_64-newlib-x86_64-pnacl-spec",
"scheduler_invocation_id:9092561391275315664",
"scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec",
"user_agent:luci-scheduler",
"buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"gitiles_ref:refs/heads/master"
]
}
[20:59:16.083] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1544821154526586",
"id": "8927131329029589488",
"lease_expiration_ts": "1544939955458724",
"lease_key": "2051952285",
"parameters_json": "{\"builder_name\": \"linux_64-newlib-x86_64-pnacl-spec\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"af5947d13e6794eac489365ff58fd45c0dd4ca2a\"}}",
"project": "nacl",
"result_details_json": "null",
"service_account": "nacl-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1544821155858055",
"tags": [
"build_address:luci.nacl.ci/linux_64-newlib-x86_64-pnacl-spec/93",
"builder:linux_64-newlib-x86_64-pnacl-spec",
"buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9092561391275315664",
"scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec",
"swarming_dimension:caches:builder_72f7de4266b10a3c57219ed8f7bf22c2a5e6b20d479961516158ed6c989314d0_v2",
"swarming_dimension:cores:8",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Ubuntu-14.04",
"swarming_dimension:pool:luci.flex.ci",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:build_address:luci.nacl.ci/linux_64-newlib-x86_64-pnacl-spec/93",
"swarming_tag:buildbucket_bucket:nacl/ci",
"swarming_tag:buildbucket_build_id:8927131329029589488",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:daaff082e95b94bec84fa6e440a8b97677d6f76d",
"swarming_tag:builder:linux_64-newlib-x86_64-pnacl-spec",
"swarming_tag:buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"swarming_tag:caches:builder_72f7de4266b10a3c57219ed8f7bf22c2a5e6b20d479961516158ed6c989314d0_v2",
"swarming_tag:cores:8",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8927131329029589488/+/annotations",
"swarming_tag:luci_project:nacl",
"swarming_tag:os:Ubuntu-14.04",
"swarming_tag:pool:luci.flex.ci",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:nacl",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_tag:scheduler_invocation_id:9092561391275315664",
"swarming_tag:scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec",
"swarming_tag:service_account:nacl-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:ee62e96c73f38e03db7f2d5dd18fea50e0f44727",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:41c755ad6218d110",
"user_agent:luci-scheduler"
],
"updated_ts": "1544821155858158",
"url": "https://ci.chromium.org/b/8927131329029589488",
"utcnow_ts": "1544821156071359"
}
}
[20:59:16.083] Task URL: https://ci.chromium.org/b/8927131329029589488
[20:59:16.083] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:2:0) after 1m0s
[21:00:16.107] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:2:0)
[21:00:16.107] Timer tick, asking Buildbucket for the build status
[21:00:16.212] Build 8927131329029589488: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:00:16.212] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:3:0) after 1m0s
[21:01:16.228] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:3:0)
[21:01:16.228] Timer tick, asking Buildbucket for the build status
[21:01:16.312] Build 8927131329029589488: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:01:16.312] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:4:0) after 1m0s
[21:02:16.333] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:4:0)
[21:02:16.333] Timer tick, asking Buildbucket for the build status
[21:02:16.455] Build 8927131329029589488: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:02:16.455] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:5:0) after 1m0s
[21:03:16.483] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:5:0)
[21:03:16.483] Timer tick, asking Buildbucket for the build status
[21:03:16.592] Build 8927131329029589488: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:03:16.592] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:6:0) after 1m0s
[21:03:54.779] Received PubSub notification, asking Buildbucket for the build status
[21:03:54.873] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:04:16.614] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:6:0)
[21:04:16.614] Timer tick, asking Buildbucket for the build status
[21:04:16.819] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:04:16.819] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:8:0) after 1m0s
[21:05:16.863] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:8:0)
[21:05:16.863] Timer tick, asking Buildbucket for the build status
[21:05:16.919] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:05:16.919] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:9:0) after 1m0s
[21:06:16.938] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:9:0)
[21:06:16.938] Timer tick, asking Buildbucket for the build status
[21:06:16.997] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:06:16.997] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:10:0) after 1m0s
[21:07:17.016] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:10:0)
[21:07:17.016] Timer tick, asking Buildbucket for the build status
[21:07:17.163] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:07:17.163] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:11:0) after 1m0s
[21:08:17.184] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:11:0)
[21:08:17.184] Timer tick, asking Buildbucket for the build status
[21:08:17.282] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:08:17.282] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:12:0) after 1m0s
[21:09:17.298] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:12:0)
[21:09:17.298] Timer tick, asking Buildbucket for the build status
[21:09:17.339] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:09:17.339] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:13:0) after 1m0s
[21:10:17.357] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:13:0)
[21:10:17.357] Timer tick, asking Buildbucket for the build status
[21:10:17.443] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:10:17.443] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:14:0) after 1m0s
[21:11:17.460] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:14:0)
[21:11:17.460] Timer tick, asking Buildbucket for the build status
[21:11:17.818] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:11:17.818] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:15:0) after 1m0s
[21:12:17.833] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:15:0)
[21:12:17.833] Timer tick, asking Buildbucket for the build status
[21:12:17.874] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:12:17.874] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:16:0) after 1m0s
[21:13:17.899] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:16:0)
[21:13:17.899] Timer tick, asking Buildbucket for the build status
[21:13:18.035] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:13:18.035] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:17:0) after 1m0s
[21:14:18.053] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:17:0)
[21:14:18.053] Timer tick, asking Buildbucket for the build status
[21:14:18.092] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:14:18.092] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:18:0) after 1m0s
[21:15:18.117] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:18:0)
[21:15:18.117] Timer tick, asking Buildbucket for the build status
[21:15:18.257] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:15:18.257] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:19:0) after 1m0s
[21:16:18.283] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:19:0)
[21:16:18.283] Timer tick, asking Buildbucket for the build status
[21:16:18.386] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:16:18.386] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:20:0) after 1m0s
[21:17:18.403] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:20:0)
[21:17:18.403] Timer tick, asking Buildbucket for the build status
[21:17:18.464] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:17:18.464] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:21:0) after 1m0s
[21:18:18.481] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:21:0)
[21:18:18.481] Timer tick, asking Buildbucket for the build status
[21:18:18.547] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:18:18.547] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:22:0) after 1m0s
[21:19:18.563] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:22:0)
[21:19:18.563] Timer tick, asking Buildbucket for the build status
[21:19:18.595] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:19:18.595] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:23:0) after 1m0s
[21:20:18.652] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:23:0)
[21:20:18.652] Timer tick, asking Buildbucket for the build status
[21:20:18.721] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:20:18.721] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:24:0) after 1m0s
[21:21:18.781] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:24:0)
[21:21:18.781] Timer tick, asking Buildbucket for the build status
[21:21:18.840] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:21:18.840] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:25:0) after 1m0s
[21:22:18.862] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:25:0)
[21:22:18.862] Timer tick, asking Buildbucket for the build status
[21:22:18.962] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:22:18.962] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:26:0) after 1m0s
[21:23:18.980] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:26:0)
[21:23:18.980] Timer tick, asking Buildbucket for the build status
[21:23:19.063] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:23:19.063] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:27:0) after 1m0s
[21:24:19.091] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:27:0)
[21:24:19.091] Timer tick, asking Buildbucket for the build status
[21:24:19.148] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:24:19.148] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:28:0) after 1m0s
[21:25:19.168] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:28:0)
[21:25:19.168] Timer tick, asking Buildbucket for the build status
[21:25:19.212] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:25:19.212] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:29:0) after 1m0s
[21:26:19.244] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:29:0)
[21:26:19.244] Timer tick, asking Buildbucket for the build status
[21:26:19.297] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:26:19.297] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:30:0) after 1m0s
[21:27:19.317] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:30:0)
[21:27:19.317] Timer tick, asking Buildbucket for the build status
[21:27:19.444] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:27:19.444] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:31:0) after 1m0s
[21:28:19.461] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:31:0)
[21:28:19.461] Timer tick, asking Buildbucket for the build status
[21:28:20.028] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:28:20.028] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:32:0) after 1m0s
[21:29:20.058] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:32:0)
[21:29:20.058] Timer tick, asking Buildbucket for the build status
[21:29:20.103] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:29:20.103] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:33:0) after 1m0s
[21:30:20.120] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:33:0)
[21:30:20.120] Timer tick, asking Buildbucket for the build status
[21:30:20.576] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:30:20.576] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:34:0) after 1m0s
[21:31:20.610] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:34:0)
[21:31:20.610] Timer tick, asking Buildbucket for the build status
[21:31:20.716] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:31:20.716] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:35:0) after 1m0s
[21:32:20.732] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:35:0)
[21:32:20.732] Timer tick, asking Buildbucket for the build status
[21:32:20.797] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:32:20.797] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:36:0) after 1m0s
[21:33:20.844] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:36:0)
[21:33:20.844] Timer tick, asking Buildbucket for the build status
[21:33:20.887] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:33:20.887] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:37:0) after 1m0s
[21:34:21.015] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:37:0)
[21:34:21.015] Timer tick, asking Buildbucket for the build status
[21:34:21.075] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:34:21.075] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:38:0) after 1m0s
[21:35:21.113] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:38:0)
[21:35:21.113] Timer tick, asking Buildbucket for the build status
[21:35:21.150] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:35:21.150] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:39:0) after 1m0s
[21:36:21.176] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:39:0)
[21:36:21.176] Timer tick, asking Buildbucket for the build status
[21:36:21.224] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:36:21.224] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:40:0) after 1m0s
[21:37:21.317] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:40:0)
[21:37:21.317] Timer tick, asking Buildbucket for the build status
[21:37:21.375] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:37:21.375] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:41:0) after 1m0s
[21:38:21.392] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:41:0)
[21:38:21.392] Timer tick, asking Buildbucket for the build status
[21:38:21.424] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:38:21.424] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:42:0) after 1m0s
[21:39:21.441] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:42:0)
[21:39:21.441] Timer tick, asking Buildbucket for the build status
[21:39:21.631] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:39:21.631] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:43:0) after 1m0s
[21:40:21.651] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:43:0)
[21:40:21.651] Timer tick, asking Buildbucket for the build status
[21:40:21.707] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:40:21.707] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:44:0) after 1m0s
[21:41:21.809] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:44:0)
[21:41:21.809] Timer tick, asking Buildbucket for the build status
[21:41:21.901] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:41:21.901] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:45:0) after 1m0s
[21:42:21.921] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:45:0)
[21:42:21.921] Timer tick, asking Buildbucket for the build status
[21:42:22.005] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:42:22.005] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:46:0) after 1m0s
[21:43:22.042] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:46:0)
[21:43:22.042] Timer tick, asking Buildbucket for the build status
[21:43:22.098] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:43:22.098] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:47:0) after 1m0s
[21:44:22.116] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:47:0)
[21:44:22.116] Timer tick, asking Buildbucket for the build status
[21:44:22.170] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:44:22.170] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:48:0) after 1m0s
[21:45:22.189] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:48:0)
[21:45:22.189] Timer tick, asking Buildbucket for the build status
[21:45:22.323] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:45:22.323] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:49:0) after 1m0s
[21:46:22.346] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:49:0)
[21:46:22.346] Timer tick, asking Buildbucket for the build status
[21:46:22.417] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:46:22.417] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:50:0) after 1m0s
[21:47:22.445] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:50:0)
[21:47:22.445] Timer tick, asking Buildbucket for the build status
[21:47:22.503] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:47:22.503] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:51:0) after 1m0s
[21:48:22.521] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:51:0)
[21:48:22.521] Timer tick, asking Buildbucket for the build status
[21:48:22.556] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:48:22.556] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:52:0) after 1m0s
[21:49:22.574] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:52:0)
[21:49:22.574] Timer tick, asking Buildbucket for the build status
[21:49:22.711] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:49:22.711] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:53:0) after 1m0s
[21:50:22.766] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:53:0)
[21:50:22.766] Timer tick, asking Buildbucket for the build status
[21:50:22.910] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:50:22.910] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:54:0) after 1m0s
[21:51:22.972] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:54:0)
[21:51:22.972] Timer tick, asking Buildbucket for the build status
[21:51:23.059] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:51:23.059] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:55:0) after 1m0s
[21:52:23.080] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:55:0)
[21:52:23.080] Timer tick, asking Buildbucket for the build status
[21:52:23.255] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:52:23.255] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:56:0) after 1m0s
[21:53:23.275] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:56:0)
[21:53:23.275] Timer tick, asking Buildbucket for the build status
[21:53:23.323] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:53:23.323] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:57:0) after 1m0s
[21:54:23.344] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:57:0)
[21:54:23.344] Timer tick, asking Buildbucket for the build status
[21:54:23.389] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:54:23.389] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:58:0) after 1m0s
[21:55:23.407] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:58:0)
[21:55:23.407] Timer tick, asking Buildbucket for the build status
[21:55:23.483] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:55:23.483] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:59:0) after 1m0s
[21:56:23.500] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:59:0)
[21:56:23.500] Timer tick, asking Buildbucket for the build status
[21:56:23.806] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:56:23.806] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:60:0) after 1m0s
[21:57:23.825] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:60:0)
[21:57:23.825] Timer tick, asking Buildbucket for the build status
[21:57:24.008] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:57:24.008] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:61:0) after 1m0s
[21:58:24.027] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:61:0)
[21:58:24.027] Timer tick, asking Buildbucket for the build status
[21:58:24.073] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:58:24.073] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:62:0) after 1m0s
[21:59:24.099] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:62:0)
[21:59:24.099] Timer tick, asking Buildbucket for the build status
[21:59:24.206] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:59:24.206] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:63:0) after 1m0s
[22:00:24.240] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:63:0)
[22:00:24.240] Timer tick, asking Buildbucket for the build status
[22:00:24.284] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:00:24.284] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:64:0) after 1m0s
[22:01:24.302] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:64:0)
[22:01:24.302] Timer tick, asking Buildbucket for the build status
[22:01:24.344] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:01:24.344] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:65:0) after 1m0s
[22:02:24.371] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:65:0)
[22:02:24.371] Timer tick, asking Buildbucket for the build status
[22:02:24.519] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:02:24.519] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:66:0) after 1m0s
[22:03:24.543] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:66:0)
[22:03:24.543] Timer tick, asking Buildbucket for the build status
[22:03:24.654] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:03:24.654] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:67:0) after 1m0s
[22:04:24.679] Handling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:67:0)
[22:04:24.679] Timer tick, asking Buildbucket for the build status
[22:04:24.751] Build 8927131329029589488: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:04:24.751] Scheduling timer "check-buildbucket-build-status" (nacl/linux_64-newlib-x86_64-pnacl-spec:9092561391275315664:68:0) after 1m0s
[22:05:11.046] Received PubSub notification, asking Buildbucket for the build status
[22:05:11.082] Build 8927131329029589488: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[22:05:11.082] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.ci",
"canary_preference": "AUTO",
"completed_ts": "1544825106298043",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1544821154526586",
"id": "8927131329029589488",
"parameters_json": "{\"builder_name\": \"linux_64-newlib-x86_64-pnacl-spec\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"af5947d13e6794eac489365ff58fd45c0dd4ca2a\"}}",
"project": "nacl",
"result": "SUCCESS",
"result_details_json": "{\"ui\": {\"info\": \"\"}, \"swarming\": {\"bot_dimensions\": {\"gce\": [\"1\"], \"zone\": [\"us\", \"us-west\", \"us-west1\", \"us-west1-b\"], \"inside_docker\": [\"0\"], \"python\": [\"2.7.6\"], \"image\": [\"chrome-trusty-18091700-38cc06ee3ee\"], \"kvm\": [\"1\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"server_version\": [\"3945-402d3be\"], \"machine_type\": [\"n1-standard-8\"], \"gpu\": [\"none\"], \"cores\": [\"8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-14.04\"], \"id\": [\"gce-trusty-e833d7b0-us-west1-b-lmhp\"], \"pool\": [\"luci.flex.ci\"], \"caches\": [\"git\", \"goma_v2\", \"infra_gclient_with_go\", \"vpython\"]}}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"buildnumber\": 93, \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"buildername\": \"linux_64-newlib-x86_64-pnacl-spec\", \"got_revision\": \"af5947d13e6794eac489365ff58fd45c0dd4ca2a\", \"recipe\": \"nacl\", \"mastername\": \"client.nacl\", \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"buildbucket\": {\"hostname\": \"cr-buildbucket.appspot.com\", \"build\": {\"created_ts\": 1544821154526586, \"tags\": [\"builder:linux_64-newlib-x86_64-pnacl-spec\", \"buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a\", \"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a\", \"gitiles_ref:refs/heads/master\", \"scheduler_invocation_id:9092561391275315664\", \"scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec\", \"user_agent:luci-scheduler\"], \"bucket\": \"luci.nacl.ci\", \"created_by\": \"user:luci-scheduler@appspot.gserviceaccount.com\", \"project\": \"nacl\", \"id\": \"8927131329029589488\"}}, \"slavetype\": \"BuilderTester\", \"branch\": \"refs/heads/master\", \"path_config\": \"generic\", \"revision\": \"af5947d13e6794eac489365ff58fd45c0dd4ca2a\", \"bot_id\": \"gce-trusty-e833d7b0-us-west1-b-lmhp\"}}",
"service_account": "nacl-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1544821433805958",
"status": "COMPLETED",
"status_changed_ts": "1544825109562913",
"tags": [
"build_address:luci.nacl.ci/linux_64-newlib-x86_64-pnacl-spec/93",
"builder:linux_64-newlib-x86_64-pnacl-spec",
"buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9092561391275315664",
"scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec",
"swarming_dimension:caches:builder_72f7de4266b10a3c57219ed8f7bf22c2a5e6b20d479961516158ed6c989314d0_v2",
"swarming_dimension:cores:8",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Ubuntu-14.04",
"swarming_dimension:pool:luci.flex.ci",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:build_address:luci.nacl.ci/linux_64-newlib-x86_64-pnacl-spec/93",
"swarming_tag:buildbucket_bucket:nacl/ci",
"swarming_tag:buildbucket_build_id:8927131329029589488",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:daaff082e95b94bec84fa6e440a8b97677d6f76d",
"swarming_tag:builder:linux_64-newlib-x86_64-pnacl-spec",
"swarming_tag:buildset:commit/git/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/af5947d13e6794eac489365ff58fd45c0dd4ca2a",
"swarming_tag:caches:builder_72f7de4266b10a3c57219ed8f7bf22c2a5e6b20d479961516158ed6c989314d0_v2",
"swarming_tag:cores:8",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8927131329029589488/+/annotations",
"swarming_tag:luci_project:nacl",
"swarming_tag:os:Ubuntu-14.04",
"swarming_tag:pool:luci.flex.ci",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:nacl",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_tag:scheduler_invocation_id:9092561391275315664",
"swarming_tag:scheduler_job_id:nacl/linux_64-newlib-x86_64-pnacl-spec",
"swarming_tag:service_account:nacl-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:ee62e96c73f38e03db7f2d5dd18fea50e0f44727",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:41c755ad6218d110",
"user_agent:luci-scheduler"
],
"updated_ts": "1544825109566485",
"url": "https://ci.chromium.org/b/8927131329029589488",
"utcnow_ts": "1544825111071232"
}
}
[22:05:11.082] Invocation finished in 1h5m58.080739592s with status SUCCEEDED