[19:30:07.278] New invocation is queued and will start shortly
[19:30:08.959] Starting the invocation (attempt 1)
[19:30:08.991] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/e8451687bb55c14bfd8df2f35d93e436f1b84cef"
[19:30:08.991] Popped gitiles commit info from properties and tags
[19:30:08.991] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[19:30:08.991] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[19:30:08.991] Buildbucket request:
{
"requestId": "9017552708509203968",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux Viz"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "e8451687bb55c14bfd8df2f35d93e436f1b84cef",
"ref": "refs/heads/master"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9017552708509203968"
},
{
"key": "scheduler_job_id",
"value": "chromium/Linux Viz"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[19:30:09.547] Scheduled build:
{
"id": "8852122645953907696",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux Viz"
},
"number": 26891,
"createdBy": "project:chromium",
"createTime": "2021-03-21T19:30:09.083690Z",
"updateTime": "2021-03-21T19:30:09.450360Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "e8451687bb55c14bfd8df2f35d93e436f1b84cef",
"ref": "refs/heads/master"
}
}
}
[19:30:09.547] Task URL: https://cr-buildbucket.appspot.com/build/8852122645953907696
[19:30:09.547] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:2:0) after 9m6s
[19:39:15.569] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:2:0)
[19:39:15.569] Timer tick, asking Buildbucket for the build status
[19:39:15.651] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:39:15.651] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:3:0) after 1m0s
[19:40:15.683] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:3:0)
[19:40:15.683] Timer tick, asking Buildbucket for the build status
[19:40:15.761] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:40:15.761] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:4:0) after 1m0s
[19:41:15.789] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:4:0)
[19:41:15.789] Timer tick, asking Buildbucket for the build status
[19:41:15.903] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:41:15.903] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:5:0) after 1m0s
[19:42:15.948] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:5:0)
[19:42:15.948] Timer tick, asking Buildbucket for the build status
[19:42:16.026] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:42:16.026] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:6:0) after 1m0s
[19:43:16.228] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:6:0)
[19:43:16.228] Timer tick, asking Buildbucket for the build status
[19:43:16.291] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:43:16.291] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:7:0) after 1m0s
[19:44:16.410] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:7:0)
[19:44:16.410] Timer tick, asking Buildbucket for the build status
[19:44:16.471] Build 8852122645953907696: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:44:16.471] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:8:0) after 1m0s
[19:45:16.490] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:8:0)
[19:45:16.524] Build status: SCHEDULED
[19:45:16.524] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:9:0) after 8m33s
[19:51:57.006] Received PubSub notification, asking Buildbucket for the build status
[19:51:57.225] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:53:49.621] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:9:0)
[19:53:49.621] Timer tick, asking Buildbucket for the build status
[19:53:49.679] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:53:49.679] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:11:0) after 1m0s
[19:54:50.339] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:11:0)
[19:54:50.365] Build status: STARTED
[19:54:50.365] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:12:0) after 6m34s
[20:01:24.389] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:12:0)
[20:01:24.389] Timer tick, asking Buildbucket for the build status
[20:01:24.595] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:01:24.595] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:13:0) after 1m0s
[20:02:24.612] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:13:0)
[20:02:24.641] Build status: STARTED
[20:02:24.641] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:14:0) after 6m27s
[20:08:51.716] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:14:0)
[20:08:51.750] Build status: STARTED
[20:08:51.750] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:15:0) after 4m52s
[20:13:43.838] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:15:0)
[20:13:43.866] Build status: STARTED
[20:13:43.866] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:16:0) after 4m41s
[20:18:24.891] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:16:0)
[20:18:24.891] Timer tick, asking Buildbucket for the build status
[20:18:24.966] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:18:24.966] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:17:0) after 1m0s
[20:19:25.092] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:17:0)
[20:19:25.118] Build status: STARTED
[20:19:25.118] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:18:0) after 8m47s
[20:28:12.177] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:18:0)
[20:28:12.206] Build status: STARTED
[20:28:12.206] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:19:0) after 7m9s
[20:35:21.225] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:19:0)
[20:35:21.251] Build status: STARTED
[20:35:21.251] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:20:0) after 6m21s
[20:41:42.266] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:20:0)
[20:41:42.266] Timer tick, asking Buildbucket for the build status
[20:41:42.345] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:41:42.345] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:21:0) after 1m0s
[20:42:42.883] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:21:0)
[20:42:42.883] Timer tick, asking Buildbucket for the build status
[20:42:43.127] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:42:43.127] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:22:0) after 1m0s
[20:43:43.158] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:22:0)
[20:43:43.158] Timer tick, asking Buildbucket for the build status
[20:43:43.314] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:43:43.314] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:23:0) after 1m0s
[20:44:43.330] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:23:0)
[20:44:43.373] Build status: STARTED
[20:44:43.373] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:24:0) after 5m48s
[20:50:31.390] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:24:0)
[20:50:31.390] Timer tick, asking Buildbucket for the build status
[20:50:31.629] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:50:31.629] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:25:0) after 1m0s
[20:51:31.646] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:25:0)
[20:51:31.646] Timer tick, asking Buildbucket for the build status
[20:51:31.720] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:51:31.720] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:26:0) after 1m0s
[20:52:31.758] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:26:0)
[20:52:31.784] Build status: STARTED
[20:52:31.784] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:27:0) after 3m20s
[20:55:51.803] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:27:0)
[20:55:51.852] Build status: STARTED
[20:55:51.852] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:28:0) after 5m43s
[21:01:34.969] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:28:0)
[21:01:34.995] Build status: STARTED
[21:01:34.995] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:29:0) after 9m24s
[21:10:58.995] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:29:0)
[21:10:59.024] Build status: STARTED
[21:10:59.024] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:30:0) after 3m27s
[21:14:26.041] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:30:0)
[21:14:26.041] Timer tick, asking Buildbucket for the build status
[21:14:26.293] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:14:26.293] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:31:0) after 1m0s
[21:15:26.322] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:31:0)
[21:15:26.322] Timer tick, asking Buildbucket for the build status
[21:15:26.436] Build 8852122645953907696: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:15:26.436] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:32:0) after 1m0s
[21:16:26.456] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:32:0)
[21:16:26.481] Build status: STARTED
[21:16:26.481] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:33:0) after 7m42s
[21:24:08.503] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:33:0)
[21:24:08.531] Build status: STARTED
[21:24:08.531] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:34:0) after 2m49s
[21:26:57.652] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:34:0)
[21:26:57.677] Build status: STARTED
[21:26:57.678] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017552708509203968:35:0) after 9m59s
[21:32:55.806] Received PubSub notification, asking Buildbucket for the build status
[21:32:56.079] Build 8852122645953907696: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[21:32:56.079] Buildbucket build:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "PROD",
"completed_ts": "1616362373531919",
"created_by": "project:chromium",
"created_ts": "1616355009083690",
"id": "8852122645953907696",
"parameters_json": "{\"builder_name\": \"Linux Viz\", \"properties\": {}}",
"project": "chromium",
"result": "SUCCESS",
"result_details_json": "{\"properties\": {\"$recipe_engine/milo/blamelist_pins\": [{\"host\": \"chromium.googlesource.com\", \"id\": \"e8451687bb55c14bfd8df2f35d93e436f1b84cef\", \"project\": \"chromium/src\"}], \"got_angle_revision\": \"90cf278c36871437c89b8f88d62e6a538b51501d\", \"got_dawn_revision\": \"6b80743d3f5bb389665590585c43eeb9cfa70a34\", \"got_nacl_revision\": \"abf3277f295c6c87f0b103f291ed5e3e73933b76\", \"got_revision\": \"e8451687bb55c14bfd8df2f35d93e436f1b84cef\", \"got_revision_cp\": \"refs/heads/master@{#865004}\", \"got_swarming_client_revision\": \"a32a1607f6093d338f756c7e7c7b4333b0c50c9c\", \"got_swiftshader_revision\": \"a98fb3f8380a3a5c9ae3e0175634ba88c85a434f\", \"got_v8_revision\": \"6092f990f654f2d7a4534ee8c5bbb5c4fb800bdc\", \"got_v8_revision_cp\": \"refs/heads/9.1.170@{#1}\", \"got_webrtc_revision\": \"8bf1cd1c665a538a366bce4770acbb990b025388\", \"got_webrtc_revision_cp\": \"refs/heads/master@{#33513}\", \"is_cached\": false, \"isolate_server\": \"https://isolateserver.appspot.com\", \"mirrored_builders\": [\"tryserver.chromium.linux:linux-viz-rel\"], \"swarm_hashes_refs/heads/master(at){#865004}_without_patch\": {\"blink_web_tests\": \"c1ac6b4534e1aca5d53f6ac528f0f2feada69270\", \"browser_tests\": \"c230bc38c76136c3425fc87d51043c7a6969d5d0\", \"content_browsertests\": \"70e6d56b9b69a85f5aee93d7c37cba0adb82f651\"}}, \"swarming\": {\"bot_dimensions\": {\"builderless\": [\"1\"], \"caches\": [\"builder_0ba11647c3777752a9345c9a31488a30e4a4f8f072cd97454b4c4835355bfe20_v2\", \"builder_1f79602663d9ad088e67440e285ce3aa4e667ee6079f6847203831e9639d7662_v2\", \"builder_4a782824ba39c0c6a32b2128ebb0687e83cb58dc0cbed64e2911b02f7893cfe6_v2\", \"builder_db15b71ef3cc643e8b8a6db72309cfdfa15c11bf324abacf3c7ac043fc971405_v2\", \"git\", \"goma_v2\", \"vpython\"], \"cores\": [\"8\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Haswell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gcp\": [\"google.com:chromecompute\"], \"gpu\": [\"none\"], \"id\": [\"luci-chromium-ci-xenial-us-east1-d-8-19-dteo\"], \"image\": [\"chrome-xenial-21011100-9488e34e558\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"e2-standard-8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16\", \"Ubuntu-16.04\", \"Ubuntu-16.04.6\"], \"pool\": [\"luci.chromium.ci\"], \"python\": [\"2\", \"2.7\", \"2.7.12\"], \"server_version\": [\"5776-cb9e157\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-d\"]}}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1616356309656087",
"status": "COMPLETED",
"status_changed_ts": "1616356316707707",
"tags": [
"build_address:luci.chromium.ci/Linux Viz/26891",
"builder:Linux Viz",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/e8451687bb55c14bfd8df2f35d93e436f1b84cef",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9017552708509203968",
"scheduler_job_id:chromium/Linux Viz",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8852122645953907696/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:os:Linux",
"swarming_tag:recipe_name:chromium",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:526f15af3619fa10",
"user_agent:luci-scheduler"
],
"updated_ts": "1616362373532407",
"url": "https://ci.chromium.org/b/8852122645953907696",
"utcnow_ts": "1616362376066843"
}
}
[21:32:56.079] Invocation finished in 2h2m48.816052079s with status SUCCEEDED