[11:18:46.759] New invocation is queued and will start shortly
[11:18:47.850] Starting the invocation (attempt 1)
[11:18:47.885] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/a3b899ac4d52f258f21f1d1313395e1c37482522"
[11:18:47.885] Popped gitiles commit info from properties and tags
[11:18:47.885] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[11:18:47.886] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[11:18:47.886] Buildbucket request:
{
"requestId": "9011060639491273216",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "80c863cdb91fb82c7f575af2f239a7a79010f4e4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@80c863cdb91fb82c7f575af2f239a7a79010f4e4",
"title": "80c863cdb91fb82c7f575af2f239a7a79010f4e4",
"url": "https://r8.googlesource.com/r8/+/80c863cdb91fb82c7f575af2f239a7a79010f4e4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "25eea3152c89c6bb664a22e6fba7a94a386f09ae"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@25eea3152c89c6bb664a22e6fba7a94a386f09ae",
"title": "25eea3152c89c6bb664a22e6fba7a94a386f09ae",
"url": "https://r8.googlesource.com/r8/+/25eea3152c89c6bb664a22e6fba7a94a386f09ae"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "3e261d5cfe1801442588ad156adc308feb8fd444"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@3e261d5cfe1801442588ad156adc308feb8fd444",
"title": "3e261d5cfe1801442588ad156adc308feb8fd444",
"url": "https://r8.googlesource.com/r8/+/3e261d5cfe1801442588ad156adc308feb8fd444"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "396bee894b018f952f82edd1c99424e18744f4e0"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@396bee894b018f952f82edd1c99424e18744f4e0",
"title": "396bee894b018f952f82edd1c99424e18744f4e0",
"url": "https://r8.googlesource.com/r8/+/396bee894b018f952f82edd1c99424e18744f4e0"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "2293f0997816dc7389c836a0283972e366df9871"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@2293f0997816dc7389c836a0283972e366df9871",
"title": "2293f0997816dc7389c836a0283972e366df9871",
"url": "https://r8.googlesource.com/r8/+/2293f0997816dc7389c836a0283972e366df9871"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "06d108205f98d572c13d335e406d02ae5004f1bb"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@06d108205f98d572c13d335e406d02ae5004f1bb",
"title": "06d108205f98d572c13d335e406d02ae5004f1bb",
"url": "https://r8.googlesource.com/r8/+/06d108205f98d572c13d335e406d02ae5004f1bb"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "3d69ea814d68de0f6b23dd06d8fade31feebe198"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@3d69ea814d68de0f6b23dd06d8fade31feebe198",
"title": "3d69ea814d68de0f6b23dd06d8fade31feebe198",
"url": "https://r8.googlesource.com/r8/+/3d69ea814d68de0f6b23dd06d8fade31feebe198"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "c921397a162df4a1f054dc32f1f08ae4c7b41739"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@c921397a162df4a1f054dc32f1f08ae4c7b41739",
"title": "c921397a162df4a1f054dc32f1f08ae4c7b41739",
"url": "https://r8.googlesource.com/r8/+/c921397a162df4a1f054dc32f1f08ae4c7b41739"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "9facf93da70f90980da129339092c6a9a9034ad5"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@9facf93da70f90980da129339092c6a9a9034ad5",
"title": "9facf93da70f90980da129339092c6a9a9034ad5",
"url": "https://r8.googlesource.com/r8/+/9facf93da70f90980da129339092c6a9a9034ad5"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "a3b899ac4d52f258f21f1d1313395e1c37482522"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@a3b899ac4d52f258f21f1d1313395e1c37482522",
"title": "a3b899ac4d52f258f21f1d1313395e1c37482522",
"url": "https://r8.googlesource.com/r8/+/a3b899ac4d52f258f21f1d1313395e1c37482522"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "a3b899ac4d52f258f21f1d1313395e1c37482522",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9011060639491273216"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-internal"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[11:18:48.407] Scheduled build:
{
"id": "8845630577542345472",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 1838,
"createdBy": "project:r8",
"createTime": "2021-06-01T11:18:47.988735Z",
"updateTime": "2021-06-01T11:18:48.340559Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "a3b899ac4d52f258f21f1d1313395e1c37482522",
"ref": "refs/heads/main"
}
}
}
[11:18:48.407] Task URL: https://cr-buildbucket.appspot.com/build/8845630577542345472
[11:18:48.407] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:2:0) after 9m48s
[11:18:51.383] Received PubSub notification, asking Buildbucket for the build status
[11:18:51.413] Build status: STARTED
[11:28:36.524] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:2:0)
[11:28:36.554] Build status: STARTED
[11:28:36.554] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:4:0) after 9m39s
[11:38:15.745] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:4:0)
[11:38:15.782] Build status: STARTED
[11:38:15.782] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:5:0) after 1m30s
[11:39:45.798] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:5:0)
[11:39:45.830] Build status: STARTED
[11:39:45.830] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:6:0) after 7m50s
[11:47:35.846] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:6:0)
[11:47:35.888] Build status: STARTED
[11:47:35.888] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:7:0) after 5m46s
[11:53:21.987] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:7:0)
[11:53:22.013] Build status: STARTED
[11:53:22.013] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:8:0) after 3m26s
[11:56:48.042] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:8:0)
[11:56:48.076] Build status: STARTED
[11:56:48.076] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:9:0) after 6m52s
[12:03:40.105] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:9:0)
[12:03:40.136] Build status: STARTED
[12:03:40.136] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:10:0) after 4m37s
[12:08:17.253] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:10:0)
[12:08:17.324] Build status: STARTED
[12:08:17.324] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:11:0) after 1m46s
[12:10:03.346] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:11:0)
[12:10:03.373] Build status: STARTED
[12:10:03.373] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:12:0) after 7m39s
[12:17:42.350] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:12:0)
[12:17:42.412] Build status: STARTED
[12:17:42.412] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:13:0) after 8m53s
[12:26:35.438] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:13:0)
[12:26:35.464] Build status: STARTED
[12:26:35.464] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:14:0) after 5m18s
[12:31:53.707] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:14:0)
[12:31:53.770] Build status: STARTED
[12:31:53.770] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:15:0) after 6m32s
[12:38:26.118] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:15:0)
[12:38:26.141] Build status: STARTED
[12:38:26.141] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:16:0) after 1m21s
[12:39:47.277] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:16:0)
[12:39:47.304] Build status: STARTED
[12:39:47.304] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:17:0) after 6m38s
[12:46:25.326] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:17:0)
[12:46:25.357] Build status: STARTED
[12:46:25.357] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:18:0) after 1m54s
[12:48:19.410] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:18:0)
[12:48:19.440] Build status: STARTED
[12:48:19.440] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:19:0) after 7m17s
[12:55:36.455] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:19:0)
[12:55:36.500] Build status: STARTED
[12:55:36.500] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:20:0) after 3m2s
[12:58:38.516] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:20:0)
[12:58:38.545] Build status: STARTED
[12:58:38.545] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:21:0) after 1m36s
[13:00:14.630] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:21:0)
[13:00:14.671] Build status: STARTED
[13:00:14.671] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:22:0) after 2m54s
[13:03:08.690] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:22:0)
[13:03:08.719] Build status: STARTED
[13:03:08.719] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:23:0) after 7m35s
[13:10:43.841] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:23:0)
[13:10:43.864] Build status: STARTED
[13:10:43.864] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:24:0) after 6m4s
[13:16:47.894] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:24:0)
[13:16:47.932] Build status: STARTED
[13:16:47.932] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:25:0) after 3m6s
[13:19:54.196] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:25:0)
[13:19:54.316] Build status: STARTED
[13:19:54.317] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:26:0) after 2m34s
[13:22:28.312] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:26:0)
[13:22:28.343] Build status: STARTED
[13:22:28.343] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:27:0) after 9m25s
[13:31:53.366] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:27:0)
[13:31:53.395] Build status: STARTED
[13:31:53.395] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:28:0) after 7m16s
[13:39:09.564] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:28:0)
[13:39:09.590] Build status: STARTED
[13:39:09.590] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:29:0) after 5m24s
[13:44:33.711] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:29:0)
[13:44:33.819] Build status: STARTED
[13:44:33.819] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:30:0) after 7m35s
[13:52:08.979] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:30:0)
[13:52:09.011] Build status: STARTED
[13:52:09.011] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:31:0) after 1m55s
[13:54:04.027] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:31:0)
[13:54:04.071] Build status: STARTED
[13:54:04.071] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:32:0) after 4m48s
[13:58:52.090] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:32:0)
[13:58:52.129] Build status: STARTED
[13:58:52.129] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:33:0) after 6m42s
[14:05:34.201] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:33:0)
[14:05:34.244] Build status: STARTED
[14:05:34.244] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:34:0) after 1m13s
[14:06:47.353] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:34:0)
[14:06:47.384] Build status: STARTED
[14:06:47.384] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:35:0) after 6m30s
[14:13:17.425] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:35:0)
[14:13:17.453] Build status: STARTED
[14:13:17.453] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:36:0) after 5m40s
[14:18:57.594] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:36:0)
[14:18:57.641] Build status: STARTED
[14:18:57.641] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:37:0) after 8m5s
[14:27:02.658] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:37:0)
[14:27:02.687] Build status: STARTED
[14:27:02.687] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:38:0) after 2m53s
[14:29:55.874] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:38:0)
[14:29:55.897] Build status: STARTED
[14:29:55.897] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:39:0) after 6m14s
[14:36:09.915] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:39:0)
[14:36:09.955] Build status: STARTED
[14:36:09.955] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:40:0) after 3m20s
[14:39:30.846] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:40:0)
[14:39:30.889] Build status: STARTED
[14:39:30.889] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:41:0) after 3m41s
[14:43:11.915] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:41:0)
[14:43:11.960] Build status: STARTED
[14:43:11.960] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:42:0) after 8m36s
[14:51:48.046] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:42:0)
[14:51:48.071] Build status: STARTED
[14:51:48.071] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:43:0) after 1m56s
[14:53:44.094] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:43:0)
[14:53:44.133] Build status: STARTED
[14:53:44.133] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:44:0) after 6m2s
[14:59:46.155] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:44:0)
[14:59:46.206] Build status: STARTED
[14:59:46.206] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:45:0) after 8m37s
[15:08:23.235] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:45:0)
[15:08:23.266] Build status: STARTED
[15:08:23.266] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:46:0) after 3m13s
[15:11:36.273] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:46:0)
[15:11:36.404] Build status: STARTED
[15:11:36.404] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:47:0) after 2m57s
[15:14:33.613] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:47:0)
[15:14:33.646] Build status: STARTED
[15:14:33.646] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:48:0) after 5m40s
[15:20:13.971] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:48:0)
[15:20:14.042] Build status: STARTED
[15:20:14.042] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:49:0) after 6m33s
[15:26:47.205] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:49:0)
[15:26:47.246] Build status: STARTED
[15:26:47.246] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:50:0) after 1m55s
[15:28:42.389] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:50:0)
[15:28:42.442] Build status: STARTED
[15:28:42.442] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:51:0) after 1m41s
[15:30:23.538] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:51:0)
[15:30:23.592] Build status: STARTED
[15:30:23.592] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:52:0) after 4m20s
[15:34:43.756] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:52:0)
[15:34:43.787] Build status: STARTED
[15:34:43.787] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:53:0) after 9m0s
[15:43:43.969] Handling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:53:0)
[15:43:44.040] Build status: STARTED
[15:43:44.040] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:9011060639491273216:54:0) after 9m26s
[15:47:39.245] Received PubSub notification, asking Buildbucket for the build status
[15:47:39.322] Build:
{
"id": "8845630577542345472",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 1838,
"createdBy": "project:r8",
"createTime": "2021-06-01T11:18:47.988735Z",
"startTime": "2021-06-01T11:18:50.798756Z",
"endTime": "2021-06-01T15:47:38.443722Z",
"updateTime": "2021-06-01T15:47:38.862089Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "a3b899ac4d52f258f21f1d1313395e1c37482522",
"ref": "refs/heads/main"
}
}
}
[15:47:39.322] Invocation finished in 4h28m52.576968507s with status SUCCEEDED