Skip to content

Issues to start gitea with MariaDB since last update #33714

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
ejalal opened this issue Feb 25, 2025 · 12 comments
Closed

Issues to start gitea with MariaDB since last update #33714

ejalal opened this issue Feb 25, 2025 · 12 comments
Labels
issue/needs-feedback For bugs, we need more details. For features, the feature must be described in more detail type/bug

Comments

@ejalal
Copy link

ejalal commented Feb 25, 2025

Description

I'm having issues with my gitea instance, running with Docker since last gitea update 1.23.3 to 1.23.4 (watchtower doing the auto updates)

Gitea is starting, I see logs with slow SQL queries, and it ends up with a timeout error

The MariaDB instance is also running with Docker, and it's working OK, no issues whatsoever to access the gitea DB

2025-02-25T07:16:11.495854984Z 2025/02/25 08:16:11 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3641.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:16:16.495361837Z 2025/02/25 08:16:16 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3639.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:16:21.495753014Z 2025/02/25 08:16:21 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3638.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:16:26.494769978Z 2025/02/25 08:16:26 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3636.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:16:31.494889823Z 2025/02/25 08:16:31 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3635.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:16:36.494723199Z 2025/02/25 08:16:36 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54362, elapsed 3634.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:18:45.008971338Z 2025/02/25 08:18:45 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740466928] - 16m37.007225195s
2025-02-25T07:18:48.495311369Z 2025/02/25 08:18:48 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60906, elapsed 3465.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:19:00.112220848Z 2025/02/25 08:19:00 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740466328] - 16m52.110161738s
2025-02-25T07:19:00.112284518Z 2025/02/25 08:19:00 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND started<? ORDER BY `id` DESC [running 1740456128] - 16m52.110217136s
2025-02-25T07:20:34.494768182Z 2025/02/25 08:20:34 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52378, elapsed 3697.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:21:51.495196883Z 2025/02/25 08:21:51 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36276, elapsed 3581.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:24:05.008343252Z 2025/02/25 08:24:05 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT count(*) FROM `action_schedule_spec` WHERE next<=? [1740467168] - 16m37.118300902s
2025-02-25T07:26:47.495673621Z 2025/02/25 08:26:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41658, elapsed 3003.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:28:33.495895628Z 2025/02/25 08:28:33 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54392, elapsed 3050.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:29:41.495420369Z 2025/02/25 08:29:41 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48540, elapsed 3900.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:29:46.495506848Z 2025/02/25 08:29:46 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48540, elapsed 3899.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:29:51.495097882Z 2025/02/25 08:29:51 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44412, elapsed 3896.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:29:56.495604225Z 2025/02/25 08:29:56 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44412, elapsed 3895.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:30:01.495345560Z 2025/02/25 08:30:01 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44412, elapsed 3894.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:30:56.495286139Z 2025/02/25 08:30:56 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52198, elapsed 3774.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:32:56.495390296Z 2025/02/25 08:32:56 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49078, elapsed 3712.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:33:01.495943514Z 2025/02/25 08:33:01 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49078, elapsed 3712.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:34:15.494744821Z 2025/02/25 08:34:15 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34990, elapsed 3513.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:34:23.246897392Z 2025/02/25 08:34:23 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740468128] - 12m15.243060919s
2025-02-25T07:34:23.247004170Z 2025/02/25 08:34:23 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740467528] - 12m15.243060296s
2025-02-25T07:34:25.494814455Z 2025/02/25 08:34:25 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52526, elapsed 3494.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:34:38.348702313Z 2025/02/25 08:34:38 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Update Mirrors canceled: invalid connection 1740468863] - 15.10389559s
2025-02-25T07:34:39.672756675Z 2025/02/25 08:34:39 .../actions/schedule.go:52:GetReposMapByIDs() [W] [Slow SQL Query] SELECT `id`, `owner_id`, `owner_name`, `lower_name`, `name`, `description`, `website`, `original_service_type`, `original_url`, `default_branch`, `default_wiki_branch`, `num_watches`, `num_stars`, `num_forks`, `num_issues`, `num_closed_issues`, `num_pulls`, `num_closed_pulls`, `num_milestones`, `num_closed_milestones`, `num_projects`, `num_closed_projects`, `num_action_runs`, `num_closed_action_runs`, `is_private`, `is_empty`, `is_archived`, `is_mirror`, `status`, `is_fork`, `fork_id`, `is_template`, `template_id`, `size`, `git_size`, `lfs_size`, `is_fsck_enabled`, `close_issues_via_commit_in_any_branch`, `topics`, `object_format_name`, `trust_model`, `avatar`, `created_unix`, `updated_unix`, `archived_unix` FROM `repository` WHERE 0=1 [] - 10m31.45719781s
2025-02-25T07:37:41.495108206Z 2025/02/25 08:37:41 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:37234, elapsed 3292.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:38:22.495746010Z 2025/02/25 08:38:22 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53192, elapsed 3186.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:50:29.907902532Z 2025/02/25 08:50:29 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Stop actions zombie tasks canceled: find tasks: invalid connection 1740468863] - 16m6.662949973s
2025-02-25T07:52:56.495410819Z 2025/02/25 08:52:56 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41550, elapsed 3234.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:55:57.495127331Z 2025/02/25 08:55:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35296, elapsed 3092.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:56:46.495052340Z 2025/02/25 08:56:46 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34636, elapsed 3858.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:58:16.845545551Z 2025/02/25 08:58:16 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740468908] - 23m8.843778861s
2025-02-25T07:58:29.903868620Z 2025/02/25 08:58:29 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740469328] - 16m21.902089809s
2025-02-25T07:59:17.495523327Z 2025/02/25 08:59:17 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51010, elapsed 3306.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T07:59:39.494667768Z 2025/02/25 08:59:39 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:37036, elapsed 3159.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:00:28.494999632Z 2025/02/25 09:00:28 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35448, elapsed 3970.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:00:54.499458974Z 2025/02/25 09:00:54 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44390, elapsed 3985.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:00:59.495473616Z 2025/02/25 09:00:59 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44390, elapsed 3981.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:06:38.495025813Z 2025/02/25 09:06:38 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36354, elapsed 3985.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:14:53.964448272Z 2025/02/25 09:14:53 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Start actions schedule tasks canceled: find specs: invalid connection 1740470296] - 16m37.119286813s
2025-02-25T08:15:04.495277665Z 2025/02/25 09:15:04 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:38650, elapsed 3867.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:15:09.503803766Z 2025/02/25 09:15:09 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49752, elapsed 3867.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:15:14.495421160Z 2025/02/25 09:15:14 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49766, elapsed 3862.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:15:37.237280191Z 2025/02/25 09:15:37 ...s/repo/pushmirror.go:151:PushMirrorsIterate() [W] [Slow SQL Query] SELECT * FROM `push_mirror` INNER JOIN `repository` ON `repository`.id = `push_mirror`.repo_id WHERE (`push_mirror`.last_update + (`push_mirror`.`interval` / ?) <= ?) AND (`push_mirror`.`interval` != 0) AND (`repository`.is_archived = ?) ORDER BY last_update ASC LIMIT 50 [1s 1740470309 false] - 17m7.328390175s
2025-02-25T08:16:15.495403928Z 2025/02/25 09:16:15 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57740, elapsed 3993.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:16:20.495419172Z 2025/02/25 09:16:20 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34596, elapsed 3989.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:17:52.494802786Z 2025/02/25 09:17:52 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:47414, elapsed 3927.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:21:36.495436198Z 2025/02/25 09:21:36 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48054, elapsed 3637.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:22:55.495432916Z 2025/02/25 09:22:55 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35316, elapsed 3546.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:23:05.495707146Z 2025/02/25 09:23:05 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:40324, elapsed 3625.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:23:10.494951931Z 2025/02/25 09:23:10 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36964, elapsed 3623.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:23:59.494957627Z 2025/02/25 09:23:59 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41884, elapsed 3541.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:24:51.478795797Z 2025/02/25 09:24:51 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740469328] - 32m43.476787097s
2025-02-25T08:28:08.495232253Z 2025/02/25 09:28:08 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60290, elapsed 3232.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:28:13.494913855Z 2025/02/25 09:28:13 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60290, elapsed 3229.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:28:48.494738155Z 2025/02/25 09:28:48 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52162, elapsed 3132.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:29:10.494705868Z 2025/02/25 09:29:10 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:59684, elapsed 3532.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:29:15.495572206Z 2025/02/25 09:29:15 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:59684, elapsed 3532.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:30:05.494654109Z 2025/02/25 09:30:05 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41986, elapsed 3429.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:30:10.494732301Z 2025/02/25 09:30:10 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:33904, elapsed 3425.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:31:04.494599192Z 2025/02/25 09:31:04 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35686, elapsed 3836.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:31:09.495460536Z 2025/02/25 09:31:09 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35686, elapsed 3619.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:31:16.495538705Z 2025/02/25 09:31:16 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:46696, elapsed 3553.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:31:21.499982716Z 2025/02/25 09:31:21 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34650, elapsed 3549.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:31:26.495275173Z 2025/02/25 09:31:26 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34650, elapsed 3548.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:32:20.494684006Z 2025/02/25 09:32:20 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:47518, elapsed 3842.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:33:16.559200848Z 2025/02/25 09:33:16 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740471308] - 18m8.558476121s
2025-02-25T08:33:47.494901756Z 2025/02/25 09:33:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39852, elapsed 3661.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:33:52.495728135Z 2025/02/25 09:33:52 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41408, elapsed 3659.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:33:57.495527664Z 2025/02/25 09:33:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41418, elapsed 3655.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:34:04.494986605Z 2025/02/25 09:34:04 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56780, elapsed 3648.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:35:40.495249361Z 2025/02/25 09:35:40 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52556, elapsed 3437.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:38:24.495736235Z 2025/02/25 09:38:24 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44560, elapsed 3138.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:38:26.357831422Z 2025/02/25 09:38:26 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.000064978s
2025-02-25T08:38:55.494863914Z 2025/02/25 09:38:55 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49296, elapsed 3098.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:39:58.495060426Z 2025/02/25 09:39:58 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41474, elapsed 3086.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:45:34.494845636Z 2025/02/25 09:45:34 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:45948, elapsed 3660.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:45:39.495221841Z 2025/02/25 09:45:39 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:45948, elapsed 3658.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:45:44.495394419Z 2025/02/25 09:45:44 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53716, elapsed 3656.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:46:52.495695934Z 2025/02/25 09:46:52 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34110, elapsed 3649.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:46:57.495652239Z 2025/02/25 09:46:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34110, elapsed 3648.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:47:47.495312145Z 2025/02/25 09:47:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51070, elapsed 3546.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:48:45.069768163Z 2025/02/25 09:48:45 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740471728] - 16m37.067843786s
2025-02-25T08:50:11.495745020Z 2025/02/25 09:50:11 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35608, elapsed 3418.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T08:50:39.495272897Z 2025/02/25 09:50:39 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39896, elapsed 3322.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:00:32.416025956Z 2025/02/25 10:00:32 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740472508] - 25m24.412641885s
2025-02-25T09:00:57.495788732Z 2025/02/25 10:00:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:46420, elapsed 3402.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:00:59.096116588Z 2025/02/25 10:00:59 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.002281042s
2025-02-25T09:01:38.495330997Z 2025/02/25 10:01:38 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39148, elapsed 3632.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:01:43.495459998Z 2025/02/25 10:01:43 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39148, elapsed 3631.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:01:48.495091337Z 2025/02/25 10:01:48 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39148, elapsed 3414.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:01:50.080927595Z 2025/02/25 10:01:50 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.000130736s
2025-02-25T09:03:42.861111408Z 2025/02/25 10:03:42 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740472928] - 11m34.859517095s
2025-02-25T09:07:44.535091601Z 2025/02/25 10:07:44 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740473528] - 15m36.533708846s
2025-02-25T09:10:20.494988684Z 2025/02/25 10:10:20 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53708, elapsed 3360.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:10:25.495449817Z 2025/02/25 10:10:25 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53708, elapsed 3359.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:12:10.765556700Z 2025/02/25 10:12:10 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740473828] - 5m2.763425588s
2025-02-25T09:13:04.495502047Z 2025/02/25 10:13:04 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60940, elapsed 3068.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:14:51.494747652Z 2025/02/25 10:14:51 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54700, elapsed 3817.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:15:10.494632651Z 2025/02/25 10:15:10 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34526, elapsed 3757.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:17:44.594599243Z 2025/02/25 10:17:44 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND started<? ORDER BY `id` DESC [running 1740463328] - 15m36.591587292s
2025-02-25T09:18:15.054703219Z 2025/02/25 10:18:15 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740474068] - 17m7.053667615s
2025-02-25T09:18:21.494741704Z 2025/02/25 10:18:21 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:50428, elapsed 3591.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:19:46.495709104Z 2025/02/25 10:19:46 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36654, elapsed 3521.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:22:05.495094862Z 2025/02/25 10:22:05 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51878, elapsed 3242.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:22:24.496433611Z 2025/02/25 10:22:24 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60196, elapsed 3264.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:22:52.499416984Z 2025/02/25 10:22:52 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:55240, elapsed 3617.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:22:57.495478105Z 2025/02/25 10:22:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:55256, elapsed 3614.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:23:02.495452939Z 2025/02/25 10:23:02 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:55256, elapsed 3612.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:24:36.749083581Z 2025/02/25 10:24:36 ...s/repo/pushmirror.go:151:PushMirrorsIterate() [W] [Slow SQL Query] SELECT * FROM `push_mirror` INNER JOIN `repository` ON `repository`.id = `push_mirror`.repo_id WHERE (`push_mirror`.last_update + (`push_mirror`.`interval` / ?) <= ?) AND (`push_mirror`.`interval` != 0) AND (`repository`.is_archived = ?) ORDER BY last_update ASC LIMIT 50 [1s 1740474464 false] - 16m52.212691018s
2025-02-25T09:26:08.495348529Z 2025/02/25 10:26:08 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:50240, elapsed 3265.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:26:13.495532038Z 2025/02/25 10:26:13 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:50240, elapsed 3264.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:28:03.344453075Z 2025/02/25 10:28:03 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Stop actions zombie tasks canceled: find tasks: invalid connection 1740474730] - 15m52.578698497s
2025-02-25T09:32:02.495301562Z 2025/02/25 10:32:02 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48030, elapsed 3333.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:34:30.494676292Z 2025/02/25 10:34:30 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54474, elapsed 3152.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:34:35.495687054Z 2025/02/25 10:34:35 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54488, elapsed 3151.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:41:17.495490442Z 2025/02/25 10:41:17 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:41292, elapsed 3112.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:49:33.328835514Z 2025/02/25 10:49:33 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740475148] - 30m25.327378144s
2025-02-25T09:50:36.495450276Z 2025/02/25 10:50:36 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:43010, elapsed 3391.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:50:41.495795780Z 2025/02/25 10:50:41 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34646, elapsed 3389.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:50:43.106849292Z 2025/02/25 10:50:43 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.000000298s
2025-02-25T09:52:11.495558685Z 2025/02/25 10:52:11 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49008, elapsed 3799.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:52:27.405526820Z 2025/02/25 10:52:27 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740477068] - 1m19.404679283s
2025-02-25T09:53:01.494863906Z 2025/02/25 10:53:01 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51424, elapsed 3210.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:53:45.494717035Z 2025/02/25 10:53:45 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54752, elapsed 3178.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:54:15.180723110Z 2025/02/25 10:54:15 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740475628] - 17m7.1787146s
2025-02-25T09:54:41.552658997Z 2025/02/25 10:54:41 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Stop actions zombie tasks canceled: find tasks: invalid connection 1740477255] - 26.371800156s
2025-02-25T09:57:31.495961398Z 2025/02/25 10:57:31 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56426, elapsed 3960.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:57:36.495388556Z 2025/02/25 10:57:36 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56440, elapsed 3955.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:59:47.494925581Z 2025/02/25 10:59:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:37146, elapsed 3662.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T09:59:52.494661570Z 2025/02/25 10:59:52 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:49476, elapsed 3659.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:01:14.494705499Z 2025/02/25 11:01:14 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:42872, elapsed 3338.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:01:28.495429307Z 2025/02/25 11:01:28 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:50504, elapsed 3515.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:02:59.494839501Z 2025/02/25 11:02:59 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53544, elapsed 3354.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:03:13.495797970Z 2025/02/25 11:03:13 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52148, elapsed 3465.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:03:18.495066844Z 2025/02/25 11:03:18 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52158, elapsed 3462.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:05:25.495708405Z 2025/02/25 11:05:25 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:34284, elapsed 3334.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:07:57.495086782Z 2025/02/25 11:07:57 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36890, elapsed 3178.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:10:44.367810497Z 2025/02/25 11:10:44 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740477308] - 15m36.36704856s
2025-02-25T10:11:42.494786086Z 2025/02/25 11:11:42 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60606, elapsed 3890.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:12:46.494723319Z 2025/02/25 11:12:46 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57748, elapsed 3889.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:18:03.495364444Z 2025/02/25 11:18:03 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:46804, elapsed 3893.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:23:16.494905977Z 2025/02/25 11:23:16 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:55672, elapsed 3454.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:26:45.391137731Z 2025/02/25 11:26:45 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740478268] - 15m37.390261651s
2025-02-25T10:27:59.628392404Z 2025/02/25 11:27:59 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740478328] - 15m51.627236068s
2025-02-25T10:34:45.388815836Z 2025/02/25 11:34:45 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740478028] - 17m37.387290286s
2025-02-25T10:35:16.494698887Z 2025/02/25 11:35:16 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44414, elapsed 3920.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:35:33.495971266Z 2025/02/25 11:35:33 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51234, elapsed 3304.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:35:38.494754769Z 2025/02/25 11:35:38 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51250, elapsed 3302.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:42:53.324651488Z 2025/02/25 11:42:53 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT count(*) FROM `action_schedule_spec` WHERE next<=? [1740478268] - 16m7.933401773s
2025-02-25T10:43:00.493869354Z 2025/02/25 11:43:00 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740479528] - 52.491375314s
2025-02-25T10:43:36.076378908Z 2025/02/25 11:43:36 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Update Mirrors canceled: invalid connection 1740479279] - 15m36.447785229s
2025-02-25T10:43:46.495128530Z 2025/02/25 11:43:46 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:47986, elapsed 3374.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:44:38.494987434Z 2025/02/25 11:44:38 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:36500, elapsed 3314.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:45:44.495737324Z 2025/02/25 11:45:44 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54318, elapsed 3475.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:46:32.494761176Z 2025/02/25 11:46:32 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35300, elapsed 3548.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:47:08.494758479Z 2025/02/25 11:47:08 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:37330, elapsed 3421.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:47:11.495509065Z 2025/02/25 11:47:11 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57584, elapsed 3397.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:48:15.494717738Z 2025/02/25 11:48:15 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48026, elapsed 3256.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:48:35.495515292Z 2025/02/25 11:48:35 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60506, elapsed 3449.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:52:38.495444709Z 2025/02/25 11:52:38 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:45752, elapsed 3020.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:52:43.495594491Z 2025/02/25 11:52:43 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:45752, elapsed 3020.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:52:45.476699039Z 2025/02/25 11:52:45 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.000300868s
2025-02-25T10:53:31.495619061Z 2025/02/25 11:53:31 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:43716, elapsed 3801.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:53:49.494794975Z 2025/02/25 11:53:49 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60296, elapsed 3368.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:54:58.495646576Z 2025/02/25 11:54:58 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:42102, elapsed 3217.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:55:03.495454526Z 2025/02/25 11:55:03 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:40246, elapsed 3213.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T10:59:15.340820313Z 2025/02/25 11:59:15 ...els/system/notice.go:54:CreateNotice() [W] [Slow SQL Query] INSERT INTO `notice` (`type`,`description`,`created_unix`) VALUES (?,?,?) [2 Cron: Start actions schedule tasks canceled: find specs: invalid connection 1740480173] - 16m22.015953926s
2025-02-25T11:00:28.495262885Z 2025/02/25 12:00:28 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:43198, elapsed 3228.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:02:24.494947563Z 2025/02/25 12:02:24 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53530, elapsed 3921.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:02:29.494762726Z 2025/02/25 12:02:29 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:53534, elapsed 3918.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:02:34.495464255Z 2025/02/25 12:02:34 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:39388, elapsed 3917.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:03:15.495630604Z 2025/02/25 12:03:15 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44034, elapsed 3323.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:04:34.494720149Z 2025/02/25 12:04:34 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:42384, elapsed 3740.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:04:54.495182310Z 2025/02/25 12:04:54 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57978, elapsed 3442.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:22.495330993Z 2025/02/25 12:05:22 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51884, elapsed 3426.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:27.495366034Z 2025/02/25 12:05:27 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:59078, elapsed 3423.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:32.495376708Z 2025/02/25 12:05:32 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:40682, elapsed 3421.1ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:37.495897596Z 2025/02/25 12:05:37 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:40690, elapsed 3416.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:42.496065614Z 2025/02/25 12:05:42 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60140, elapsed 3410.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:05:47.495255250Z 2025/02/25 12:05:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60142, elapsed 3408.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:07:42.495648661Z 2025/02/25 12:07:42 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60142, elapsed 3347.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:08:48.495512060Z 2025/02/25 12:08:48 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:60180, elapsed 3170.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:11:17.494706218Z 2025/02/25 12:11:17 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52768, elapsed 3208.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:13:59.495726449Z 2025/02/25 12:13:59 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:59400, elapsed 3386.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:14:01.112648626Z 2025/02/25 12:14:01 ...ls/actions/runner.go:240:GetRunnerByUUID() [W] [Slow SQL Query] SELECT `id`, `uuid`, `name`, `version`, `owner_id`, `repo_id`, `description`, `base`, `repo_range`, `token_hash`, `token_salt`, `last_online`, `last_active`, `agent_labels`, `created`, `updated`, `deleted` FROM `action_runner` WHERE (uuid=?) AND (`deleted`=? OR `deleted` IS NULL) LIMIT 1 [493aeab4-86d1-40f3-970e-8a783040c826 0] - 5.002514587s
2025-02-25T11:15:43.495515606Z 2025/02/25 12:15:43 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:51282, elapsed 3354.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:15:59.886760730Z 2025/02/25 12:15:59 models/repo/repo.go:830:GetRepositoriesMapByIDs() [W] [Slow SQL Query] SELECT `id`, `owner_id`, `owner_name`, `lower_name`, `name`, `description`, `website`, `original_service_type`, `original_url`, `default_branch`, `default_wiki_branch`, `num_watches`, `num_stars`, `num_forks`, `num_issues`, `num_closed_issues`, `num_pulls`, `num_closed_pulls`, `num_milestones`, `num_closed_milestones`, `num_projects`, `num_closed_projects`, `num_action_runs`, `num_closed_action_runs`, `is_private`, `is_empty`, `is_archived`, `is_mirror`, `status`, `is_fork`, `fork_id`, `is_template`, `template_id`, `size`, `git_size`, `lfs_size`, `is_fsck_enabled`, `close_issues_via_commit_in_any_branch`, `topics`, `object_format_name`, `trust_model`, `avatar`, `created_unix`, `updated_unix`, `archived_unix` FROM `repository` WHERE 0=1 [] - 15m51.651174924s
2025-02-25T11:19:44.495562205Z 2025/02/25 12:19:44 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57714, elapsed 3042.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:22:39.494986585Z 2025/02/25 12:22:39 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:54290, elapsed 3606.3ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:25:23.495497151Z 2025/02/25 12:25:23 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:44622, elapsed 3386.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:26:47.495094537Z 2025/02/25 12:26:47 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:57668, elapsed 3292.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:26:54.495427158Z 2025/02/25 12:26:54 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:52680, elapsed 3083.0ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:33:15.148615688Z 2025/02/25 12:33:15 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740482168] - 17m7.147626712s
2025-02-25T11:33:44.847472941Z 2025/02/25 12:33:44 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND updated<? ORDER BY `id` DESC [running 1740481628] - 16m36.846564536s
2025-02-25T11:39:02.495493587Z 2025/02/25 12:39:02 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:38644, elapsed 3374.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:39:26.495492745Z 2025/02/25 12:39:26 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56272, elapsed 3472.7ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:39:31.495908297Z 2025/02/25 12:39:31 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56272, elapsed 3471.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:39:52.460396235Z 2025/02/25 12:39:52 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `schedule_id`, `next`, `prev`, `spec`, `created`, `updated` FROM `action_schedule_spec` WHERE next<=? ORDER BY `id` DESC LIMIT 50 [1740483248] - 5m44.458721157s
2025-02-25T11:41:21.495046212Z 2025/02/25 12:41:21 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:48696, elapsed 3337.8ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:44:01.495798427Z 2025/02/25 12:44:01 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:46284, elapsed 3218.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:47:45.562682303Z 2025/02/25 12:47:45 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=? AND started<? ORDER BY `id` DESC [running 1740472328] - 15m37.561759034s
2025-02-25T11:47:45.562749281Z 2025/02/25 12:47:45 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT `id`, `repo_id`, `interval`, `enable_prune`, `updated_unix`, `next_update_unix`, `lfs_enabled`, `lfs_endpoint`, `remote_address` FROM `mirror` WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740483128] - 15m37.561875473s
2025-02-25T11:50:44.495022991Z 2025/02/25 12:50:44 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:35166, elapsed 3905.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:51:01.495538268Z 2025/02/25 12:51:01 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:43802, elapsed 3145.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:51:39.021401865Z 2025/02/25 12:51:39 models/db/list.go:210:]() [W] [Slow SQL Query] SELECT count(*) FROM `action_schedule_spec` WHERE next<=? [1740483248] - 11m46.560103712s
2025-02-25T11:52:58.495338008Z 2025/02/25 12:52:58 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:56386, elapsed 3696.6ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
2025-02-25T11:53:03.495221587Z 2025/02/25 12:53:03 ...eb/routing/logger.go:68:func1() [W] router: slow      POST /api/actions/runner.v1.RunnerService/FetchTask for 172.17.0.1:58726, elapsed 3694.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)

Gitea Version

1.23.4

Can you reproduce the bug on the Gitea demo site?

Yes

Log Gist

No response

Screenshots

No response

Git Version

No response

Operating System

Debian/Docker

How are you running Gitea?

Official Gitea Docker image docker.io/gitea/gitea:latest

Database

MySQL/MariaDB
@ChristopherHX
Copy link
Contributor

I could imagine that the recently added database transaction increased the database workload of fetchTask on your system.

Add a transaction to pickTask (#33543) (#33563)

  • Reducing the amount of act_runner connected to gitea could increase responsiveness and resolve timeouts.
  • Allocating more resources to the mariadb
  • I would also think, an in memory gitea actions queue could help (me as well, if I use 60 act_runners on a raspberry pi4 8GB) however this is more something of a new release than a patch

@wxiaoguang
Copy link
Contributor

wxiaoguang commented Feb 25, 2025 •
edited
Loading

I could imagine that the recently added database transaction increased the database workload of fetchTask on your system.

TBH I do not think it could be the case, a transaction is quite lightweight in most cases and it shouldn't make a SQL run that long

Below is outdated, see next comment.

2025-02-25T08:24:51.478795797Z 2025/02/25 09:24:51 models/db/list.go:164:]() [W] [Slow SQL Query] SELECT id, job_id, attempt, runner_id, status, started, stopped, repo_id, owner_id, commit_sha, is_fork_pull_request, token_hash, token_salt, token_last_eight, log_filename, log_in_storage, log_length, log_size, log_indexes, log_expired, created, updated FROM action_task WHERE status=? AND updated<? ORDER BY id DESC [running 1740469328] - 32m43.476787097s

I guess there is something wrong with the SQL or the data/index in database. I think something like:

  • And try to run the SQL manually:
SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=6 AND updated<1740469328 ORDER BY `id`
  • And try to explain the SQL:
EXPLAIN SELECT `id`, `job_id`, `attempt`, `runner_id`, `status`, `started`, `stopped`, `repo_id`, `owner_id`, `commit_sha`, `is_fork_pull_request`, `token_hash`, `token_salt`, `token_last_eight`, `log_filename`, `log_in_storage`, `log_length`, `log_size`, `log_indexes`, `log_expired`, `created`, `updated` FROM `action_task` WHERE status=6 AND updated<1740469328 ORDER BY `id`

(status "running" = 6)

could help to explain the problem.

@wxiaoguang
Copy link
Contributor

And one more thing, maybe it is not related to the "Actions" SQL.

I can see there are various different SQLs in the slow log, like this:

2025-02-25T10:27:59.628392404Z 2025/02/25 11:27:59 ...odels/repo/mirror.go:116:MirrorsIterate() [W] [Slow SQL Query] SELECT id, repo_id, interval, enable_prune, updated_unix, next_update_unix, lfs_enabled, lfs_endpoint, remote_address FROM mirror WHERE (next_update_unix<=?) AND (next_update_unix!=0) ORDER BY updated_unix ASC LIMIT 50 [1740478328] - 15m51.627236068s

I think it's better to see what happens on MariaDB side. Is it running a lot of SQLs concurrently? Is there any bottleneck from network or disk? Or is the MariaDB itself is quite busy? What causes the MariaDB's heavy load? What does MariaDB's slow query log say?

@ejalal
Copy link
Author

ejalal commented Feb 25, 2025 •
edited
Loading

My MariaDB instantance is doing nothing, no load, also my homelab server as 4 cores, 16 Gb of RAM, CPU load avg is always under 2, and RAM usage is always under 55%

I'm getting other SQL error at statrup like

2025-02-25T15:46:28.170303748Z 2025/02/25 16:46:28 routers/common/db.go:30:InitDBEngine() [I] ORM engine initialization attempt #5/10...
2025-02-25T15:46:28.170360946Z 2025/02/25 16:46:28 cmd/web.go:205:serveInstalled() [I] PING DATABASE mysql
2025-02-25T15:47:07.920549025Z 2025/02/25 16:47:07 models/db/engine.go:196:InitEngineWithMigration() [W] [Slow SQL Query] SELECT `TABLE_NAME`, `ENGINE`, `AUTO_INCREMENT`, `TABLE_COMMENT`, `TABLE_COLLATION` from `INFORMATION_SCHEMA`.`TABLES` WHERE `TABLE_SCHEMA`=? AND (`ENGINE`='MyISAM' OR `ENGINE` = 'InnoDB' OR `ENGINE` = 'TokuDB') [gitea] - 39.747901192s
2025-02-25T15:47:53.742725534Z 2025/02/25 16:47:53 ...dels/db/collation.go:160:preprocessDatabaseCollation() [W] [Slow SQL Query] SELECT `COLUMN_NAME`, `IS_NULLABLE`, `COLUMN_DEFAULT`, `COLUMN_TYPE`, `COLUMN_KEY`, `EXTRA`, `COLUMN_COMMENT`, `CHARACTER_MAXIMUM_LENGTH`, (INSTR(VERSION(), 'maria') > 0 && (SUBSTRING_INDEX(VERSION(), '.', 1) > 10 || (SUBSTRING_INDEX(VERSION(), '.', 1) = 10 && (SUBSTRING_INDEX(SUBSTRING(VERSION(), 4), '.', 1) > 2 || (SUBSTRING_INDEX(SUBSTRING(VERSION(), 4), '.', 1) = 2 && SUBSTRING_INDEX(SUBSTRING(VERSION(), 6), '-', 1) >= 7))))) AS NEEDS_QUOTE, `COLLATION_NAME` FROM `INFORMATION_SCHEMA`.`COLUMNS` WHERE `TABLE_SCHEMA` = ? AND `TABLE_NAME` = ? ORDER BY `COLUMNS`.ORDINAL_POSITION ASC [gitea action_artifact] - 45.186903053s
2025-02-25T16:03:46.317074176Z [mysql] 2025/02/25 17:03:46 connection.go:49: read tcp 172.17.0.6:42822->192.168.0.1:3306: read: connection reset by peer
2025-02-25T16:03:46.317338794Z 2025/02/25 17:03:46 ...dels/db/collation.go:160:preprocessDatabaseCollation() [W] [Slow SQL Query] SELECT `COLUMN_NAME`, `IS_NULLABLE`, `COLUMN_DEFAULT`, `COLUMN_TYPE`, `COLUMN_KEY`, `EXTRA`, `COLUMN_COMMENT`, `CHARACTER_MAXIMUM_LENGTH`, (INSTR(VERSION(), 'maria') > 0 && (SUBSTRING_INDEX(VERSION(), '.', 1) > 10 || (SUBSTRING_INDEX(VERSION(), '.', 1) = 10 && (SUBSTRING_INDEX(SUBSTRING(VERSION(), 4), '.', 1) > 2 || (SUBSTRING_INDEX(SUBSTRING(VERSION(), 4), '.', 1) = 2 && SUBSTRING_INDEX(SUBSTRING(VERSION(), 6), '-', 1) >= 7))))) AS NEEDS_QUOTE, `COLLATION_NAME` FROM `INFORMATION_SCHEMA`.`COLUMNS` WHERE `TABLE_SCHEMA` = ? AND `TABLE_NAME` = ? ORDER BY `COLUMNS`.ORDINAL_POSITION ASC [gitea user_blocking] - 15m51.668678655s
2025-02-25T16:03:46.317667772Z 2025/02/25 17:03:46 ...dels/db/collation.go:162:preprocessDatabaseCollation() [E] Failed to check database collation: invalid connection
2025-02-25T16:04:59.536317644Z [mysql] 2025/02/25 17:04:59 connection.go:49: unexpected EOF
2025-02-25T16:04:59.536561780Z 2025/02/25 17:04:59 ...ations/migrations.go:448:Migrate() [W] [Slow SQL Query] SELECT `TABLE_NAME`, `ENGINE`, `AUTO_INCREMENT`, `TABLE_COMMENT`, `TABLE_COLLATION` from `INFORMATION_SCHEMA`.`TABLES` WHERE `TABLE_SCHEMA`=? AND (`ENGINE`='MyISAM' OR `ENGINE` = 'InnoDB' OR `ENGINE` = 'TokuDB') [gitea] - 1m13.219619282s
2025-02-25T16:04:59.536575930Z 2025/02/25 17:04:59 routers/common/db.go:36:InitDBEngine() [E] ORM engine initialization attempt #5/10 failed. Error: migrate: sync: invalid connection

Unless something has changed in the latest Docker 28 update regarding networking, which I doubt, as my Zabbix server under docker is able to connect to my MariaDB instance.

@wxiaoguang
Copy link
Contributor

If you downgrade to 1.23.3, does the problem still exist?

@wxiaoguang wxiaoguang added the issue/needs-feedback For bugs, we need more details. For features, the feature must be described in more detail label Feb 25, 2025
@ejalal
Copy link
Author

ejalal commented Feb 25, 2025

Yes I downgraded down until 1.22, problem still persists

@wxiaoguang
Copy link
Contributor

So I would still suggest you to check your other services including MariaDB, it doesn't seem to be a Gitea's problem.

@ejalal
Copy link
Author

ejalal commented Feb 26, 2025

Well, it looks like there's no issue with my MadiaDB container, I double checked and it works OK with my other phpmyadmin and zabbix server containers.

@ejalal
Copy link
Author

ejalal commented Feb 26, 2025

I'm having plenty of these errors in MariaDB logs

2025-02-26 14:28:18 613 [Warning] Aborted connection 613 to db: 'unconnected' user: 'unauthenticated' host: '172.17.0.6' (This connection closed normally without authentication)
2025-02-26 14:46:09 614 [Warning] Aborted connection 614 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 15:04:10 640 [Warning] Aborted connection 640 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 15:20:23 657 [Warning] Aborted connection 657 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 15:32:48 687 [Warning] Aborted connection 687 to db: 'unconnected' user: 'unauthenticated' host: '172.17.0.6' (This connection closed normally without authentication)
2025-02-26 15:48:33 688 [Warning] Aborted connection 688 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 16:04:25 705 [Warning] Aborted connection 705 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 16:09:28 722 [Warning] Aborted connection 722 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 16:11:06 728 [Warning] Aborted connection 728 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)
2025-02-26 16:11:21 731 [Warning] Aborted connection 731 to db: 'unconnected' user: 'unauthenticated' host: '172.17.0.6' (This connection closed normally without authentication)
2025-02-26 16:11:36 732 [Warning] Aborted connection 732 to db: 'unconnected' user: 'unauthenticated' host: '172.17.0.6' (This connection closed normally without authentication)
2025-02-26 16:29:49 735 [Warning] Aborted connection 735 to db: 'gitea' user: 'gitea' host: '172.17.0.6' (Got an error reading communication packets)

I also used the gitea db username/password to connect through phpmyadmin (which is also in a docker container) and all works OK.

Also double checked the db IP, port, username, password... in the app.ini file and all looks OK

@ejalal
Copy link
Author

ejalal commented Feb 27, 2025 •
edited
Loading

Issue fixed by moving the gitea docker container from bridge network to host network, it was working OK for ages on the bridge network. Probably a recent change from Docker v28

Still doesn't explain why phpmyadmin which is still running OK on the bridge network

Well, not entirely fixed, I'm now having an issue with SSH_LISTEN_PORT not being taken into account, SSH still trying to use port 22, where my app.ini has SSH_LISTEN_PORT = 2222

2025-02-27T15:23:53.973490538Z Bind to port 22 on :: failed: Address in use.
2025-02-27T15:23:53.973544657Z Bind to port 22 on 0.0.0.0 failed: Address in use.
2025-02-27T15:23:53.973553509Z Cannot bind any address.

@ejalal
Copy link
Author

ejalal commented Mar 5, 2025

Switched back to bridge network and came back up and running again

@ejalal ejalal closed this as completed Mar 5, 2025
@lunny
Copy link
Member

lunny commented Mar 5, 2025

I'm curious how did you resolve your problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
issue/needs-feedback For bugs, we need more details. For features, the feature must be described in more detail type/bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@lunny @wxiaoguang @ejalal @ChristopherHX