[08:50:54.921] New invocation is queued and will start shortly
[08:50:56.009] Starting the invocation (attempt 1)
[08:50:56.040] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/c0f9fc515c962497b90c8c8fa3b72e77b8a88647"
[08:50:56.040] Popped gitiles commit info from properties and tags
[08:50:56.040] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[08:50:56.041] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[08:50:56.041] Buildbucket request:
{
"requestId": "9011975911953315536",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux CFI"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "c0f9fc515c962497b90c8c8fa3b72e77b8a88647",
"ref": "refs/heads/master"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9011975911953315536"
},
{
"key": "scheduler_job_id",
"value": "chromium/Linux CFI"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[08:50:56.813] Scheduled build:
{
"id": "8846545850041288176",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux CFI"
},
"number": 20402,
"createdBy": "project:chromium",
"createTime": "2021-05-22T08:50:56.113652Z",
"updateTime": "2021-05-22T08:50:56.485727Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "c0f9fc515c962497b90c8c8fa3b72e77b8a88647",
"ref": "refs/heads/master"
}
}
}
[08:50:56.813] Task URL: https://cr-buildbucket.appspot.com/build/8846545850041288176
[08:50:56.813] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:2:0) after 7m39s
[08:58:36.292] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:2:0)
[08:58:36.331] Build status: SCHEDULED
[08:58:36.331] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:3:0) after 4m40s
[08:58:57.046] Received PubSub notification, asking Buildbucket for the build status
[08:58:57.136] Build status: STARTED
[09:03:16.391] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:3:0)
[09:03:16.419] Build status: STARTED
[09:03:16.419] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:5:0) after 1m11s
[09:04:27.836] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:5:0)
[09:04:27.867] Build status: STARTED
[09:04:27.867] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:6:0) after 1m47s
[09:06:14.890] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:6:0)
[09:06:14.926] Build status: STARTED
[09:06:14.926] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:7:0) after 4m16s
[09:10:30.944] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:7:0)
[09:10:30.977] Build status: STARTED
[09:10:30.977] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:8:0) after 5m3s
[09:15:33.998] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:8:0)
[09:15:34.024] Build status: STARTED
[09:15:34.024] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:9:0) after 7m29s
[09:23:03.041] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:9:0)
[09:23:03.068] Build status: STARTED
[09:23:03.068] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:10:0) after 1m30s
[09:24:33.098] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:10:0)
[09:24:33.130] Build status: STARTED
[09:24:33.130] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:11:0) after 9m50s
[09:34:23.110] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:11:0)
[09:34:23.139] Build status: STARTED
[09:34:23.140] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:12:0) after 9m20s
[09:43:43.161] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:12:0)
[09:43:43.192] Build status: STARTED
[09:43:43.192] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:13:0) after 1m38s
[09:45:21.209] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:13:0)
[09:45:21.271] Build status: STARTED
[09:45:21.271] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:14:0) after 3m3s
[09:48:24.314] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:14:0)
[09:48:24.348] Build status: STARTED
[09:48:24.348] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:15:0) after 7m14s
[09:55:38.366] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:15:0)
[09:55:38.394] Build status: STARTED
[09:55:38.394] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:16:0) after 7m57s
[10:03:35.638] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:16:0)
[10:03:35.670] Build status: STARTED
[10:03:35.670] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:17:0) after 4m25s
[10:08:00.688] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:17:0)
[10:08:00.717] Build status: STARTED
[10:08:00.717] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:18:0) after 2m28s
[10:10:28.784] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:18:0)
[10:10:28.818] Build status: STARTED
[10:10:28.818] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:19:0) after 8m43s
[10:19:11.835] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:19:0)
[10:19:11.868] Build status: STARTED
[10:19:11.868] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:20:0) after 4m7s
[10:23:18.888] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:20:0)
[10:23:18.917] Build status: STARTED
[10:23:18.917] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:21:0) after 2m36s
[10:25:55.129] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:21:0)
[10:25:55.161] Build status: STARTED
[10:25:55.161] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:22:0) after 5m8s
[10:31:03.183] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:22:0)
[10:31:03.214] Build status: STARTED
[10:31:03.214] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:23:0) after 2m51s
[10:33:54.452] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:23:0)
[10:33:54.482] Build status: STARTED
[10:33:54.482] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:24:0) after 1m50s
[10:35:44.704] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:24:0)
[10:35:44.735] Build status: STARTED
[10:35:44.735] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:25:0) after 9m37s
[10:45:22.922] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:25:0)
[10:45:22.948] Build status: STARTED
[10:45:22.948] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:26:0) after 6m37s
[10:52:00.211] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:26:0)
[10:52:00.239] Build status: STARTED
[10:52:00.239] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:27:0) after 1m13s
[10:53:13.267] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:27:0)
[10:53:13.297] Build status: STARTED
[10:53:13.297] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:28:0) after 5m54s
[10:59:07.451] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:28:0)
[10:59:07.487] Build status: STARTED
[10:59:07.487] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:29:0) after 1m48s
[11:00:55.506] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:29:0)
[11:00:55.546] Build status: STARTED
[11:00:55.546] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:30:0) after 8m30s
[11:09:27.479] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:30:0)
[11:09:27.533] Build status: STARTED
[11:09:27.533] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:31:0) after 9m16s
[11:18:43.951] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:31:0)
[11:18:43.980] Build status: STARTED
[11:18:43.980] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:32:0) after 8m17s
[11:27:01.448] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:32:0)
[11:27:01.478] Build status: STARTED
[11:27:01.478] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:33:0) after 1m41s
[11:28:42.685] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:33:0)
[11:28:42.713] Build status: STARTED
[11:28:42.713] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:34:0) after 1m56s
[11:30:38.991] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:34:0)
[11:30:39.027] Build status: STARTED
[11:30:39.027] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:35:0) after 5m46s
[11:36:27.463] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:35:0)
[11:36:27.501] Build status: STARTED
[11:36:27.501] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:36:0) after 5m27s
[11:41:54.520] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:36:0)
[11:41:54.553] Build status: STARTED
[11:41:54.553] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:37:0) after 5m33s
[11:47:27.897] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:37:0)
[11:47:27.928] Build status: STARTED
[11:47:27.928] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:38:0) after 7m16s
[11:54:43.947] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:38:0)
[11:54:43.981] Build status: STARTED
[11:54:43.981] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:39:0) after 7m19s
[12:02:03.141] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:39:0)
[12:02:03.174] Build status: STARTED
[12:02:03.174] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:40:0) after 7m29s
[12:09:32.194] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:40:0)
[12:09:32.224] Build status: STARTED
[12:09:32.224] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:41:0) after 9m39s
[12:19:11.276] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:41:0)
[12:19:11.327] Build status: STARTED
[12:19:11.327] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:42:0) after 4m46s
[12:23:57.347] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:42:0)
[12:23:57.382] Build status: STARTED
[12:23:57.382] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:43:0) after 3m11s
[12:27:08.400] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:43:0)
[12:27:08.456] Build status: STARTED
[12:27:08.456] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:44:0) after 9m22s
[12:36:30.587] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:44:0)
[12:36:30.619] Build status: STARTED
[12:36:30.619] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:45:0) after 1m31s
[12:38:01.944] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:45:0)
[12:38:02.012] Build status: STARTED
[12:38:02.012] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:46:0) after 3m57s
[12:41:59.189] Handling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:46:0)
[12:41:59.221] Build status: STARTED
[12:41:59.221] Scheduling timer "check-buildbucket-build-status" (chromium/Linux CFI:9011975911953315536:47:0) after 9m46s
[12:49:38.793] Received PubSub notification, asking Buildbucket for the build status
[12:49:38.825] Build:
{
"id": "8846545850041288176",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux CFI"
},
"number": 20402,
"createdBy": "project:chromium",
"createTime": "2021-05-22T08:50:56.113652Z",
"startTime": "2021-05-22T08:58:56.454184Z",
"endTime": "2021-05-22T12:49:37.419308Z",
"updateTime": "2021-05-22T12:49:38.253297Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "c0f9fc515c962497b90c8c8fa3b72e77b8a88647",
"ref": "refs/heads/master"
}
}
}
[12:49:38.825] Invocation finished in 3h58m43.919566697s with status SUCCEEDED