[03:45:46.567] New invocation is queued and will start shortly
[03:45:47.824] Starting the invocation (attempt 1)
[03:45:47.862] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/f69396514fc47c9fd07c1189c55523c13f69a769"
[03:45:47.862] Popped gitiles commit info from properties and tags
[03:45:47.863] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:45:47.863] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:45:47.863] Buildbucket request:
{
"requestId": "8915599937405939744",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "CrWinAsan"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f69396514fc47c9fd07c1189c55523c13f69a769",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8915599937405939744"
},
{
"key": "scheduler_job_id",
"value": "chromium/CrWinAsan"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[03:45:48.402] Scheduled build:
{
"id": "8750169875288358257",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "CrWinAsan"
},
"number": 15028,
"createdBy": "project:chromium",
"createTime": "2024-04-20T03:45:47.953668735Z",
"updateTime": "2024-04-20T03:45:47.953668735Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f69396514fc47c9fd07c1189c55523c13f69a769",
"ref": "refs/heads/main"
}
}
}
[03:45:48.402] Task URL: https://cr-buildbucket.appspot.com/build/8750169875288358257
[03:45:48.402] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:2:0) after 5m23s
[03:45:49.354] Received PubSub notification, asking Buildbucket for the build status
[03:45:49.388] Build status: SCHEDULED
[03:51:11.484] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:2:0)
[03:51:11.502] Build status: SCHEDULED
[03:51:11.502] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:4:0) after 6m38s
[03:57:50.151] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:4:0)
[03:57:50.180] Build status: SCHEDULED
[03:57:50.180] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:5:0) after 4m4s
[04:01:54.213] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:5:0)
[04:01:54.246] Build status: SCHEDULED
[04:01:54.246] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:6:0) after 4m4s
[04:05:58.318] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:6:0)
[04:05:58.371] Build status: SCHEDULED
[04:05:58.373] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:7:0) after 4m31s
[04:10:29.602] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:7:0)
[04:10:29.638] Build status: SCHEDULED
[04:10:29.639] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:8:0) after 1m1s
[04:11:30.731] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:8:0)
[04:11:30.749] Build status: SCHEDULED
[04:11:30.749] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:9:0) after 7m12s
[04:18:43.017] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:9:0)
[04:18:43.242] Build status: SCHEDULED
[04:18:43.242] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:10:0) after 2m27s
[04:21:11.275] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:10:0)
[04:21:11.303] Build status: SCHEDULED
[04:21:11.303] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:11:0) after 1m2s
[04:22:13.329] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:11:0)
[04:22:13.363] Build status: SCHEDULED
[04:22:13.363] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:12:0) after 7m39s
[04:29:52.593] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:12:0)
[04:29:52.610] Build status: SCHEDULED
[04:29:52.610] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:13:0) after 3m16s
[04:33:08.759] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:13:0)
[04:33:08.834] Build status: SCHEDULED
[04:33:08.835] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:14:0) after 4m45s
[04:35:45.945] Received PubSub notification, asking Buildbucket for the build status
[04:35:45.967] Build status: STARTED
[04:37:53.890] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:14:0)
[04:37:53.916] Build status: STARTED
[04:37:53.916] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:16:0) after 9m57s
[04:47:50.908] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:16:0)
[04:47:50.932] Build status: STARTED
[04:47:50.932] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:17:0) after 3m50s
[04:51:40.981] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:17:0)
[04:51:41.003] Build status: STARTED
[04:51:41.003] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:18:0) after 1m59s
[04:53:40.124] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:18:0)
[04:53:40.140] Build status: STARTED
[04:53:40.140] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:19:0) after 7m25s
[05:01:05.235] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:19:0)
[05:01:05.266] Build status: STARTED
[05:01:05.266] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:20:0) after 6m53s
[05:07:58.477] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:20:0)
[05:07:58.496] Build status: STARTED
[05:07:58.496] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:21:0) after 3m12s
[05:11:10.549] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:21:0)
[05:11:10.642] Build status: STARTED
[05:11:10.642] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:22:0) after 6m51s
[05:18:01.818] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:22:0)
[05:18:01.843] Build status: STARTED
[05:18:01.843] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:23:0) after 7m29s
[05:25:30.965] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:23:0)
[05:25:30.992] Build status: STARTED
[05:25:30.992] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:24:0) after 4m22s
[05:29:53.013] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:24:0)
[05:29:53.032] Build status: STARTED
[05:29:53.032] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:25:0) after 5m58s
[05:35:51.283] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:25:0)
[05:35:51.303] Build status: STARTED
[05:35:51.303] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:26:0) after 4m12s
[05:40:03.455] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:26:0)
[05:40:03.505] Build status: STARTED
[05:40:03.505] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:27:0) after 7m58s
[05:48:01.729] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:27:0)
[05:48:01.753] Build status: STARTED
[05:48:01.753] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:28:0) after 9m10s
[05:57:11.869] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:28:0)
[05:57:11.963] Build status: STARTED
[05:57:11.963] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:29:0) after 9m19s
[06:06:31.363] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:29:0)
[06:06:31.464] Build status: STARTED
[06:06:31.464] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:30:0) after 9m11s
[06:15:42.528] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:30:0)
[06:15:42.598] Build status: STARTED
[06:15:42.598] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:31:0) after 8m59s
[06:24:41.807] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:31:0)
[06:24:41.825] Build status: STARTED
[06:24:41.825] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:32:0) after 5m15s
[06:29:56.852] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:32:0)
[06:29:56.870] Build status: STARTED
[06:29:56.871] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:33:0) after 3m6s
[06:33:02.889] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:33:0)
[06:33:02.909] Build status: STARTED
[06:33:02.909] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:34:0) after 8m26s
[06:41:29.077] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:34:0)
[06:41:29.110] Build status: STARTED
[06:41:29.110] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:35:0) after 7m34s
[06:49:03.147] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:35:0)
[06:49:03.232] Build status: STARTED
[06:49:03.232] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:36:0) after 2m11s
[06:51:14.262] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:36:0)
[06:51:14.322] Build status: STARTED
[06:51:14.322] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:37:0) after 2m46s
[06:54:00.422] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:37:0)
[06:54:00.472] Build status: STARTED
[06:54:00.472] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:38:0) after 9m9s
[07:03:09.491] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:38:0)
[07:03:09.509] Build status: STARTED
[07:03:09.509] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:39:0) after 5m45s
[07:08:54.595] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:39:0)
[07:08:54.621] Build status: STARTED
[07:08:54.621] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:40:0) after 6m28s
[07:15:22.729] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:40:0)
[07:15:22.749] Build status: STARTED
[07:15:22.749] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:41:0) after 2m48s
[07:18:10.872] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:41:0)
[07:18:10.898] Build status: STARTED
[07:18:10.898] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:42:0) after 3m16s
[07:21:27.118] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:42:0)
[07:21:27.198] Build status: STARTED
[07:21:27.198] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:43:0) after 5m33s
[07:27:00.237] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:43:0)
[07:27:00.260] Build status: STARTED
[07:27:00.260] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:44:0) after 1m19s
[07:28:19.387] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:44:0)
[07:28:19.404] Build status: STARTED
[07:28:19.404] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:45:0) after 1m34s
[07:29:53.677] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:45:0)
[07:29:53.752] Build status: STARTED
[07:29:53.752] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:46:0) after 8m38s
[07:38:31.768] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:46:0)
[07:38:31.811] Build status: STARTED
[07:38:31.811] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:47:0) after 9m50s
[07:48:21.838] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:47:0)
[07:48:21.999] Build status: STARTED
[07:48:21.999] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:48:0) after 5m51s
[07:54:13.118] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:48:0)
[07:54:13.152] Build status: STARTED
[07:54:13.152] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:49:0) after 9m42s
[08:03:55.176] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:49:0)
[08:03:55.210] Build status: STARTED
[08:03:55.213] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:50:0) after 8m14s
[08:12:09.355] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:50:0)
[08:12:09.384] Build status: STARTED
[08:12:09.384] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:51:0) after 4m23s
[08:16:32.422] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:51:0)
[08:16:32.440] Build status: STARTED
[08:16:32.440] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:52:0) after 6m41s
[08:23:14.052] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:52:0)
[08:23:14.083] Build status: STARTED
[08:23:14.083] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:53:0) after 3m18s
[08:26:32.155] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:53:0)
[08:26:32.174] Build status: STARTED
[08:26:32.174] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:54:0) after 6m17s
[08:32:49.268] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:54:0)
[08:32:49.286] Build status: STARTED
[08:32:49.286] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:55:0) after 5m11s
[08:38:00.495] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:55:0)
[08:38:00.518] Build status: STARTED
[08:38:00.518] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:56:0) after 1m50s
[08:39:50.690] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:56:0)
[08:39:50.706] Build status: STARTED
[08:39:50.706] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:57:0) after 4m22s
[08:44:12.735] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:57:0)
[08:44:12.755] Build status: STARTED
[08:44:12.755] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:58:0) after 4m25s
[08:48:38.055] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:58:0)
[08:48:38.081] Build status: STARTED
[08:48:38.081] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:59:0) after 3m52s
[08:52:30.084] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:59:0)
[08:52:30.105] Build status: STARTED
[08:52:30.105] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:60:0) after 6m23s
[08:58:53.242] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:60:0)
[08:58:53.312] Build status: STARTED
[08:58:53.312] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:61:0) after 8m6s
[09:06:59.532] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:61:0)
[09:06:59.556] Build status: STARTED
[09:06:59.556] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:62:0) after 2m20s
[09:09:19.582] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:62:0)
[09:09:19.606] Build status: STARTED
[09:09:19.606] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:63:0) after 8m50s
[09:18:09.632] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:63:0)
[09:18:09.647] Build status: STARTED
[09:18:09.647] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:64:0) after 6m56s
[09:25:05.740] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:64:0)
[09:25:05.772] Build status: STARTED
[09:25:05.772] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:65:0) after 3m1s
[09:28:06.775] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:65:0)
[09:28:06.796] Build status: STARTED
[09:28:06.796] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:66:0) after 9m13s
[09:37:19.937] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:66:0)
[09:37:20.048] Build status: STARTED
[09:37:20.049] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:67:0) after 5m58s
[09:43:18.074] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:67:0)
[09:43:18.177] Build status: STARTED
[09:43:18.177] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:68:0) after 9m52s
[09:53:10.298] Handling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:68:0)
[09:53:10.322] Build status: STARTED
[09:53:10.322] Scheduling timer "check-buildbucket-build-status" (chromium/CrWinAsan:8915599937405939744:69:0) after 9m26s
[09:55:15.138] Received PubSub notification, asking Buildbucket for the build status
[09:55:15.213] Build:
{
"id": "8750169875288358257",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "CrWinAsan"
},
"number": 15028,
"createdBy": "project:chromium",
"createTime": "2024-04-20T03:45:47.953668735Z",
"startTime": "2024-04-20T04:35:45.730813371Z",
"endTime": "2024-04-20T09:55:14.877803055Z",
"updateTime": "2024-04-20T09:55:14.877803055Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f69396514fc47c9fd07c1189c55523c13f69a769",
"ref": "refs/heads/main"
}
}
}
[09:55:15.214] Invocation finished in 6h9m28.663248658s with status SUCCEEDED