[18:11:08.634] New invocation is queued and will start shortly
[18:11:09.706] Starting the invocation (attempt 1)
[18:11:09.746] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/6dc561aa43a09737a114a0b233d9476b4ec902e5"
[18:11:09.747] Popped gitiles commit info from properties and tags
[18:11:09.747] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[18:11:09.747] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[18:11:09.747] Buildbucket request:
{
"requestId": "8955861143230369920",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8955861143230369920",
"job": "r8/linux-internal",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "8c67ec2137e66483fde526a612b73b445ceaa343"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@8c67ec2137e66483fde526a612b73b445ceaa343",
"title": "8c67ec2137e66483fde526a612b73b445ceaa343",
"url": "https://r8.googlesource.com/r8/+/8c67ec2137e66483fde526a612b73b445ceaa343"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "3a75bd93f91818591e85536d9f7cdb4cfc5dd2a5"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@3a75bd93f91818591e85536d9f7cdb4cfc5dd2a5",
"title": "3a75bd93f91818591e85536d9f7cdb4cfc5dd2a5",
"url": "https://r8.googlesource.com/r8/+/3a75bd93f91818591e85536d9f7cdb4cfc5dd2a5"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "9c64e352fcf9781c4639e21e62459ea6fd0e4d04"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@9c64e352fcf9781c4639e21e62459ea6fd0e4d04",
"title": "9c64e352fcf9781c4639e21e62459ea6fd0e4d04",
"url": "https://r8.googlesource.com/r8/+/9c64e352fcf9781c4639e21e62459ea6fd0e4d04"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "df9425555855c6f7d30de05d035701a2530c0d56"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@df9425555855c6f7d30de05d035701a2530c0d56",
"title": "df9425555855c6f7d30de05d035701a2530c0d56",
"url": "https://r8.googlesource.com/r8/+/df9425555855c6f7d30de05d035701a2530c0d56"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "f304a9deb2f3398149c89adc0c3997b9d36bc7b4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@f304a9deb2f3398149c89adc0c3997b9d36bc7b4",
"title": "f304a9deb2f3398149c89adc0c3997b9d36bc7b4",
"url": "https://r8.googlesource.com/r8/+/f304a9deb2f3398149c89adc0c3997b9d36bc7b4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "98951842b32d50b08eb6279f2a6e755feeb7f808"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@98951842b32d50b08eb6279f2a6e755feeb7f808",
"title": "98951842b32d50b08eb6279f2a6e755feeb7f808",
"url": "https://r8.googlesource.com/r8/+/98951842b32d50b08eb6279f2a6e755feeb7f808"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "3376ec6bc675506c32a4b8d46662e42e883c1d77"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@3376ec6bc675506c32a4b8d46662e42e883c1d77",
"title": "3376ec6bc675506c32a4b8d46662e42e883c1d77",
"url": "https://r8.googlesource.com/r8/+/3376ec6bc675506c32a4b8d46662e42e883c1d77"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "2b6a05dc04f6d59ed9bb3f1ff7eb580f5a2f9fd4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@2b6a05dc04f6d59ed9bb3f1ff7eb580f5a2f9fd4",
"title": "2b6a05dc04f6d59ed9bb3f1ff7eb580f5a2f9fd4",
"url": "https://r8.googlesource.com/r8/+/2b6a05dc04f6d59ed9bb3f1ff7eb580f5a2f9fd4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "795c446be21123750246f677f79d60acbb54151c"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@795c446be21123750246f677f79d60acbb54151c",
"title": "795c446be21123750246f677f79d60acbb54151c",
"url": "https://r8.googlesource.com/r8/+/795c446be21123750246f677f79d60acbb54151c"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "35c5ab799b1c221d3a2ae3812c7ad0563eb1aa3b"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@35c5ab799b1c221d3a2ae3812c7ad0563eb1aa3b",
"title": "35c5ab799b1c221d3a2ae3812c7ad0563eb1aa3b",
"url": "https://r8.googlesource.com/r8/+/35c5ab799b1c221d3a2ae3812c7ad0563eb1aa3b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "7d3f78b5f8e822b8710dd5f223a34b3e3dfcee83"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@7d3f78b5f8e822b8710dd5f223a34b3e3dfcee83",
"title": "7d3f78b5f8e822b8710dd5f223a34b3e3dfcee83",
"url": "https://r8.googlesource.com/r8/+/7d3f78b5f8e822b8710dd5f223a34b3e3dfcee83"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "6dc561aa43a09737a114a0b233d9476b4ec902e5"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@6dc561aa43a09737a114a0b233d9476b4ec902e5",
"title": "6dc561aa43a09737a114a0b233d9476b4ec902e5",
"url": "https://r8.googlesource.com/r8/+/6dc561aa43a09737a114a0b233d9476b4ec902e5"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "6dc561aa43a09737a114a0b233d9476b4ec902e5",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8955861143230369920"
},
{
"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"
}
}
[18:11:10.202] Scheduled build:
{
"id": "8790431081245214625",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 3007,
"createdBy": "project:r8",
"createTime": "2023-01-31T18:11:09.885171769Z",
"updateTime": "2023-01-31T18:11:09.885171769Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "6dc561aa43a09737a114a0b233d9476b4ec902e5",
"ref": "refs/heads/main"
}
}
}
[18:11:10.202] Task URL: https://cr-buildbucket.appspot.com/build/8790431081245214625
[18:11:10.202] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:2:0) after 3m52s
[18:12:15.113] Received PubSub notification, asking Buildbucket for the build status
[18:12:15.203] Build status: STARTED
[18:15:02.224] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:2:0)
[18:15:02.319] Build status: STARTED
[18:15:02.319] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:4:0) after 1m53s
[18:16:55.344] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:4:0)
[18:16:55.372] Build status: STARTED
[18:16:55.372] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:5:0) after 5m37s
[18:22:32.390] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:5:0)
[18:22:32.411] Build status: STARTED
[18:22:32.411] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:6:0) after 5m42s
[18:28:14.437] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:6:0)
[18:28:14.462] Build status: STARTED
[18:28:14.462] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:7:0) after 1m12s
[18:29:26.483] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:7:0)
[18:29:26.528] Build status: STARTED
[18:29:26.528] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:8:0) after 8m51s
[18:38:17.794] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:8:0)
[18:38:17.820] Build status: STARTED
[18:38:17.820] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:9:0) after 5m31s
[18:43:48.838] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:9:0)
[18:43:48.858] Build status: STARTED
[18:43:48.858] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:10:0) after 3m6s
[18:46:54.940] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:10:0)
[18:46:54.973] Build status: STARTED
[18:46:54.973] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:11:0) after 6m8s
[18:53:02.991] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:11:0)
[18:53:03.048] Build status: STARTED
[18:53:03.048] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:12:0) after 9m3s
[19:02:06.068] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:12:0)
[19:02:06.089] Build status: STARTED
[19:02:06.089] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:13:0) after 3m49s
[19:05:55.110] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:13:0)
[19:05:55.130] Build status: STARTED
[19:05:55.131] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:14:0) after 7m27s
[19:13:22.161] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:14:0)
[19:13:22.217] Build status: STARTED
[19:13:22.217] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:15:0) after 4m44s
[19:18:06.233] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:15:0)
[19:18:06.260] Build status: STARTED
[19:18:06.260] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:16:0) after 9m32s
[19:27:38.329] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:16:0)
[19:27:38.355] Build status: STARTED
[19:27:38.355] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:17:0) after 6m51s
[19:34:29.374] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:17:0)
[19:34:29.402] Build status: STARTED
[19:34:29.402] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:18:0) after 6m21s
[19:40:50.420] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:18:0)
[19:40:50.457] Build status: STARTED
[19:40:50.457] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:19:0) after 6m42s
[19:47:32.519] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:19:0)
[19:47:32.541] Build status: STARTED
[19:47:32.541] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:20:0) after 9m58s
[19:57:30.749] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:20:0)
[19:57:30.775] Build status: STARTED
[19:57:30.775] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:21:0) after 2m0s
[19:59:30.794] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:21:0)
[19:59:30.845] Build status: STARTED
[19:59:30.845] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:22:0) after 3m9s
[20:02:40.069] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:22:0)
[20:02:40.109] Build status: STARTED
[20:02:40.109] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:23:0) after 1m38s
[20:04:18.196] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:23:0)
[20:04:18.225] Build status: STARTED
[20:04:18.225] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:24:0) after 6m58s
[20:11:16.273] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:24:0)
[20:11:16.296] Build status: STARTED
[20:11:16.296] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:25:0) after 6m46s
[20:18:02.350] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:25:0)
[20:18:02.382] Build status: STARTED
[20:18:02.382] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:26:0) after 2m59s
[20:21:01.399] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:26:0)
[20:21:01.433] Build status: STARTED
[20:21:01.433] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:27:0) after 7m24s
[20:28:25.555] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:27:0)
[20:28:25.589] Build status: STARTED
[20:28:25.589] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:28:0) after 4m7s
[20:32:32.607] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:28:0)
[20:32:32.632] Build status: STARTED
[20:32:32.632] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:29:0) after 9m54s
[20:42:26.710] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:29:0)
[20:42:26.752] Build status: STARTED
[20:42:26.752] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:30:0) after 9m40s
[20:52:07.067] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:30:0)
[20:52:07.095] Build status: STARTED
[20:52:07.095] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:31:0) after 4m27s
[20:56:34.152] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:31:0)
[20:56:34.180] Build status: STARTED
[20:56:34.180] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:32:0) after 9m50s
[21:06:24.352] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:32:0)
[21:06:24.394] Build status: STARTED
[21:06:24.394] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:33:0) after 5m19s
[21:11:43.659] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:33:0)
[21:11:43.694] Build status: STARTED
[21:11:43.694] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:34:0) after 4m5s
[21:15:49.192] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:34:0)
[21:15:49.213] Build status: STARTED
[21:15:49.213] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:35:0) after 5m43s
[21:21:32.412] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:35:0)
[21:21:32.439] Build status: STARTED
[21:21:32.439] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:36:0) after 5m30s
[21:27:02.540] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:36:0)
[21:27:02.565] Build status: STARTED
[21:27:02.565] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:37:0) after 7m57s
[21:34:59.579] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:37:0)
[21:34:59.601] Build status: STARTED
[21:34:59.601] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:38:0) after 6m52s
[21:41:51.650] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:38:0)
[21:41:51.673] Build status: STARTED
[21:41:51.673] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8955861143230369920:39:0) after 6m6s
[21:44:22.702] Received PubSub notification, asking Buildbucket for the build status
[21:44:22.724] Build:
{
"id": "8790431081245214625",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 3007,
"createdBy": "project:r8",
"createTime": "2023-01-31T18:11:09.885171769Z",
"startTime": "2023-01-31T18:12:05.139481Z",
"endTime": "2023-01-31T21:44:22.277909643Z",
"updateTime": "2023-01-31T21:44:22.277909643Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "6dc561aa43a09737a114a0b233d9476b4ec902e5",
"ref": "refs/heads/main"
}
}
}
[21:44:22.725] Invocation finished in 3h33m14.116243349s with status SUCCEEDED