[19:20:00.154] New invocation is queued and will start shortly
[19:20:01.266] Starting the invocation (attempt 1)
[19:20:01.315] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[19:20:01.315] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[19:20:01.315] Buildbucket request:
{
"bucket": "luci.chromium.ci",
"client_operation_id": "9083960921514164352",
"parameters_json": "{\"builder_name\":\"Windows deterministic\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/chromium/src.git\",\"revision\":\"37511ad65414d7d7fd43d4620bc2f7fb91e8b2be\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Windows deterministic",
"scheduler_invocation_id:9083960921514164352",
"scheduler_job_id:chromium/Windows deterministic",
"user_agent:luci-scheduler",
"buildset:commit/git/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"gitiles_ref:refs/heads/master"
]
}
[19:20:02.552] Buildbucket response:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "AUTO",
"created_by": "project:chromium",
"created_ts": "1553023201446318",
"id": "8918530859478647600",
"lease_expiration_ts": "1553142002099615",
"lease_key": "2024561982",
"parameters_json": "{\"builder_name\": \"Windows deterministic\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"revision\": \"37511ad65414d7d7fd43d4620bc2f7fb91e8b2be\"}}",
"project": "chromium",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1553023202349578",
"tags": [
"build_address:luci.chromium.ci/Windows deterministic/12495",
"builder:Windows deterministic",
"buildset:commit/git/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9083960921514164352",
"scheduler_job_id:chromium/Windows deterministic",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8918530859478647600/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:recipe_name:swarming/deterministic_build",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:43b036fa2512dd10",
"user_agent:luci-scheduler"
],
"updated_ts": "1553023202349845",
"url": "https://ci.chromium.org/b/8918530859478647600",
"utcnow_ts": "1553023202539300"
}
}
[19:20:02.552] Task URL: https://ci.chromium.org/b/8918530859478647600
[19:20:02.552] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:2:0) after 1m0s
[19:20:02.976] Received PubSub notification, asking Buildbucket for the build status
[19:20:03.285] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:21:02.563] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:2:0)
[19:21:02.563] Timer tick, asking Buildbucket for the build status
[19:21:02.747] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:21:02.747] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:4:0) after 1m0s
[19:22:02.767] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:4:0)
[19:22:02.767] Timer tick, asking Buildbucket for the build status
[19:22:03.364] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:22:03.364] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:5:0) after 1m0s
[19:23:03.363] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:5:0)
[19:23:03.363] Timer tick, asking Buildbucket for the build status
[19:23:03.497] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:23:03.497] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:6:0) after 1m0s
[19:24:03.490] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:6:0)
[19:24:03.490] Timer tick, asking Buildbucket for the build status
[19:24:03.585] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:24:03.585] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:7:0) after 1m0s
[19:25:03.597] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:7:0)
[19:25:03.597] Timer tick, asking Buildbucket for the build status
[19:25:04.088] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:25:04.088] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:8:0) after 1m0s
[19:26:04.109] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:8:0)
[19:26:04.109] Timer tick, asking Buildbucket for the build status
[19:26:04.211] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:26:04.211] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:9:0) after 1m0s
[19:27:04.217] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:9:0)
[19:27:04.217] Timer tick, asking Buildbucket for the build status
[19:27:04.315] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:27:04.315] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:10:0) after 1m0s
[19:28:04.335] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:10:0)
[19:28:04.335] Timer tick, asking Buildbucket for the build status
[19:28:04.444] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:28:04.444] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:11:0) after 1m0s
[19:29:04.428] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:11:0)
[19:29:04.428] Timer tick, asking Buildbucket for the build status
[19:29:04.700] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:29:04.700] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:12:0) after 1m0s
[19:30:04.770] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:12:0)
[19:30:04.770] Timer tick, asking Buildbucket for the build status
[19:30:05.106] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:30:05.106] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:13:0) after 1m0s
[19:31:05.136] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:13:0)
[19:31:05.136] Timer tick, asking Buildbucket for the build status
[19:31:05.243] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:31:05.243] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:14:0) after 1m0s
[19:32:05.266] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:14:0)
[19:32:05.266] Timer tick, asking Buildbucket for the build status
[19:32:05.383] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:32:05.383] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:15:0) after 1m0s
[19:33:05.387] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:15:0)
[19:33:05.387] Timer tick, asking Buildbucket for the build status
[19:33:05.880] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:33:05.880] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:16:0) after 1m0s
[19:34:05.896] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:16:0)
[19:34:05.896] Timer tick, asking Buildbucket for the build status
[19:34:06.267] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:34:06.267] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:17:0) after 1m0s
[19:35:06.293] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:17:0)
[19:35:06.293] Timer tick, asking Buildbucket for the build status
[19:35:06.404] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:35:06.404] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:18:0) after 1m0s
[19:36:06.432] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:18:0)
[19:36:06.432] Timer tick, asking Buildbucket for the build status
[19:36:07.063] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:36:07.063] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:19:0) after 1m0s
[19:37:07.085] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:19:0)
[19:37:07.085] Timer tick, asking Buildbucket for the build status
[19:37:07.444] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:37:07.444] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:20:0) after 1m0s
[19:38:07.420] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:20:0)
[19:38:07.420] Timer tick, asking Buildbucket for the build status
[19:38:07.551] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:38:07.551] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:21:0) after 1m0s
[19:39:07.559] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:21:0)
[19:39:07.559] Timer tick, asking Buildbucket for the build status
[19:39:07.711] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:39:07.711] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:22:0) after 1m0s
[19:40:07.730] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:22:0)
[19:40:07.730] Timer tick, asking Buildbucket for the build status
[19:40:08.119] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:40:08.119] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:23:0) after 1m0s
[19:41:08.146] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:23:0)
[19:41:08.146] Timer tick, asking Buildbucket for the build status
[19:41:08.685] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:41:08.685] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:24:0) after 1m0s
[19:42:08.684] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:24:0)
[19:42:08.684] Timer tick, asking Buildbucket for the build status
[19:42:08.901] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:42:08.901] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:25:0) after 1m0s
[19:43:08.889] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:25:0)
[19:43:08.889] Timer tick, asking Buildbucket for the build status
[19:43:09.330] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:43:09.330] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:26:0) after 1m0s
[19:44:09.385] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:26:0)
[19:44:09.385] Timer tick, asking Buildbucket for the build status
[19:44:09.604] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:44:09.604] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:27:0) after 1m0s
[19:45:09.592] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:27:0)
[19:45:09.592] Timer tick, asking Buildbucket for the build status
[19:45:09.702] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:45:09.702] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:28:0) after 1m0s
[19:46:09.733] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:28:0)
[19:46:09.733] Timer tick, asking Buildbucket for the build status
[19:46:09.822] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:46:09.822] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:29:0) after 1m0s
[19:47:09.868] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:29:0)
[19:47:09.868] Timer tick, asking Buildbucket for the build status
[19:47:09.990] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:47:09.990] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:30:0) after 1m0s
[19:48:10.017] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:30:0)
[19:48:10.017] Timer tick, asking Buildbucket for the build status
[19:48:10.263] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:48:10.263] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:31:0) after 1m0s
[19:49:10.284] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:31:0)
[19:49:10.284] Timer tick, asking Buildbucket for the build status
[19:49:10.468] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:49:10.468] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:32:0) after 1m0s
[19:50:10.444] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:32:0)
[19:50:10.444] Timer tick, asking Buildbucket for the build status
[19:50:11.066] Build 8918530859478647600: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:50:11.066] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9083960921514164352:33:0) after 1m0s
[19:50:59.952] Received PubSub notification, asking Buildbucket for the build status
[19:51:00.368] Build 8918530859478647600: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[19:51:00.368] Buildbucket build:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "AUTO",
"completed_ts": "1553025058738232",
"created_by": "project:chromium",
"created_ts": "1553023201446318",
"failure_reason": "BUILD_FAILURE",
"id": "8918530859478647600",
"parameters_json": "{\"builder_name\": \"Windows deterministic\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"revision\": \"37511ad65414d7d7fd43d4620bc2f7fb91e8b2be\"}}",
"project": "chromium",
"result": "FAILURE",
"result_details_json": "{\"swarming\": {\"bot_dimensions\": {\"gce\": [\"1\"], \"machine_type\": [\"n1-standard-8\"], \"zone\": [\"us\", \"us-west\", \"us-west1\", \"us-west1-c\"], \"locale\": [\"en_US.cp1252\"], \"os\": [\"Windows\", \"Windows-10\", \"Windows-10-15063\"], \"builder\": [\"Windows deterministic\"], \"id\": [\"windows-deterministic-0-v3qq\"], \"python\": [\"2.7.13\"], \"server_version\": [\"4209-02e057f\"], \"image\": [\"chrome-win10-1703-2018-04-20-61acaf8983f\"], \"gpu\": [\"none\"], \"cores\": [\"8\"], \"integrity\": [\"high\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\"], \"pool\": [\"luci.chromium.ci\"], \"caches\": [\"builder_e8fffaf9fac16164b1ec16ebaa1f377b792d39a582f7640830518d8ff7303d0c_v2\", \"git\", \"goma_v2\", \"vpython\"]}}, \"ui\": {\"info\": \"Failure First build\"}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"C:\\\\b\\\\s\\\\w\\\\ir\\\\cache\", \"temp_dir\": \"C:\\\\b\\\\s\\\\w\\\\ir\\\\tmp\\\\rt\"}, \"got_angle_revision\": \"9b050f846a06463e83160ad192c809692e395dbf\", \"got_nacl_revision\": \"7d24fb15d81f95ed30dde0c04b68584749709657\", \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"got_swarming_client_revision\": \"7a61cf37d6a0163f0ec02d495289a1d038e62457\", \"got_revision_cp\": \"refs/heads/master@{#642127}\", \"got_webrtc_revision\": \"7dbc0eb2efa4708da5e3e44d2a15bfdee4ceb474\", \"got_revision\": \"37511ad65414d7d7fd43d4620bc2f7fb91e8b2be\", \"buildername\": \"Windows deterministic\", \"recipe\": \"swarming/deterministic_build\", \"mastername\": \"chromium.win\", \"buildnumber\": 12495, \"got_v8_revision\": \"93306f1d7b2c10824e1e8876e5b8a3ab37c42b96\", \"got_v8_revision_cp\": \"refs/heads/7.5.72@{#1}\", \"got_dawn_revision\": \"54e4d47db4910ebd1ffce0247b60d4e6f984774f\", \"got_webrtc_revision_cp\": \"refs/heads/master@{#27160}\", \"path_config\": \"generic\", \"bot_id\": \"windows-deterministic-0-v3qq\", \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"revision\": \"37511ad65414d7d7fd43d4620bc2f7fb91e8b2be\"}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1553023202282924",
"status": "COMPLETED",
"status_changed_ts": "1553025059646409",
"tags": [
"build_address:luci.chromium.ci/Windows deterministic/12495",
"builder:Windows deterministic",
"buildset:commit/git/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/37511ad65414d7d7fd43d4620bc2f7fb91e8b2be",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9083960921514164352",
"scheduler_job_id:chromium/Windows deterministic",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8918530859478647600/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:os:Windows",
"swarming_tag:recipe_name:swarming/deterministic_build",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:43b036fa2512dd10",
"user_agent:luci-scheduler"
],
"updated_ts": "1553025059649830",
"url": "https://ci.chromium.org/b/8918530859478647600",
"utcnow_ts": "1553025060358976"
}
}
[19:51:00.368] Invocation finished in 31m0.24710032s with status FAILED