On my installation koji takes over 200 connection's to the database.
postgres=# select usename, count(usename) from pg_stat_activity where usename='koji' GROUP BY usename; usename | count ---------+------- koji | 201
Over the time the connections will grow until the database server will reject new connections. It looks for me, that the connections will never closed. Only an restart of the apache will fix it for some minutes. It was happens after upgrading from RHEL-8 to RHEL-9 of the hub server
I can reproduce it, on every API call new connections will be created, but none will be closed. Start only the hub, without any builders and no kojira. That call
koji hello
on any workstation. This will result in 4 database connection. Now call it again and you will see 8.
Metadata Update from @tkopecek: - Custom field Size adjusted to None - Issue set to the milestone: 1.36
The hub uses a db connection per worker, so you need to balance your worker limit with your db connection limit. It shouldn't be growing without bound.
When I reduce the default worker settings then it will result in:
[Thu Aug 22 10:53:10.896434 2024] [mpm_event:error] [pid 30421:tid 30421] AH03490: scoreboard is full, not at MaxRequestWorkers.Increase ServerLimit. [Thu Aug 22 10:53:11.897603 2024] [mpm_event:error] [pid 30421:tid 30421] AH03490: scoreboard is full, not at MaxRequestWorkers.Increase ServerLimit. [Thu Aug 22 10:53:12.898640 2024] [mpm_event:error] [pid 30421:tid 30421] AH03490: scoreboard is full, not at MaxRequestWorkers.Increase ServerLimit.
without any real load. Only one builder and kojira will run. This will looks like for me, that some connections will not be closed. Here are my limit config:
<IfModule event.c> MaxRequestWorkers 10 ThreadsPerChild 5 MaxRequestsPerChild 100 MaxSpareThreads 2 MinSpareThreads 2 </IfModule>
This result in using 80 db connections.
Sorry this fell through the cracks. Did you ever figure it out?
Your situation is quite strange. Koji should only have one open connection per worker. Workers can only keep a reference to one connection at a time. The connection is recycled across calls, and is deleted and replaced if there is a problem recycling it.
Hello, I still have no explanation for this. But unfortunately the problem persists. As soon as kojira starts, there are 20 open connections. And if a package build is started, there are immediately 40 connections and these do not decrease. What is always noticeable is that stopping Apache on the hub takes forever.
How many separate httpd processes do you see on your hub? For us, it is roughly in line with the the connection numbers
Currently I have 50 database connections and 12 apache processes.
ps ax|grep httpd | grep -v grep|wc -l 12 koji=# select usename, count(usename) from pg_stat_activity where usename='koji' GROUP BY usename; usename | count ---------+------- koji | 50
Some debug logging might help. E.g. https://pagure.io/fork/mikem/koji/commits/log-db-connections
If your httpd is using threads, kojihub make a connection per thread, not just per process. This might be the missing factor here.
Good morning, I have now installed the patch and as the connections increase, only the message ‘Creating a fresh database connection’ is written. The message ‘Unable to recycle database connection’ does not appear in the log. mod_mpm_event is used as the worker for Apache. The worker itself is operated with the options:
<IfModule event.c> MaxConnectionsPerChild 100 MaxRequestWorkers 10 ThreadsPerChild 5 </IfModule>
Does the number of "fresh connection" messages match the connection count reported by your db?
Do your httpd logs include process/thread id? Do you see multiple connections for the same thread id? Is the number of distinct threads in line with what you expect from your settings?
Hi, when I analyse the log file of the apache, I can see, that every time 5 new connections are created for the same process with differed threads. Here an sample of it:
[Wed Feb 19 08:01:40.883493 2025] [wsgi:error] [pid 4155460:tid 4155497] [client <HUB>:53984] 2025-02-19 08:01:40,883 [INFO] m=None u=None p=4155460 r=<HUB>:53984 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:40.935583 2025] [wsgi:error] [pid 4155460:tid 4155498] [client <HUB>:53984] 2025-02-19 08:01:40,935 [INFO] m=None u=None p=4155460 r=<HUB>:53984 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:40.987318 2025] [wsgi:error] [pid 4155460:tid 4155499] [client <HUB>:53984] 2025-02-19 08:01:40,987 [INFO] m=None u=None p=4155460 r=<HUB>:53984 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:41.695328 2025] [wsgi:error] [pid 4155460:tid 4155495] [client <HUB>:53984] 2025-02-19 08:01:41,695 [INFO] m=None u=None p=4155460 r=<HUB>:53984 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:41.820743 2025] [wsgi:error] [pid 4155460:tid 4155496] [client <HUB>:53984] 2025-02-19 08:01:41,820 [INFO] m=None u=None p=4155460 r=<HUB>:53984 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:47.784992 2025] [wsgi:error] [pid 4155463:tid 4155503] [client <HUB>:56698] 2025-02-19 08:01:47,784 [INFO] m=None u=None p=4155463 r=<HUB>:56698 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:47.834227 2025] [wsgi:error] [pid 4155463:tid 4155505] [client <HUB>:56698] 2025-02-19 08:01:47,834 [INFO] m=None u=None p=4155463 r=<HUB>:56698 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:48.539957 2025] [wsgi:error] [pid 4155463:tid 4155504] [client <HUB>:56722] 2025-02-19 08:01:48,539 [INFO] m=None u=None p=4155463 r=<HUB>:56722 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:48.766871 2025] [wsgi:error] [pid 4155463:tid 4155506] [client <HUB>:56722] 2025-02-19 08:01:48,766 [INFO] m=None u=None p=4155463 r=<HUB>:56722 koji.db: Creating a fresh database connection [Wed Feb 19 08:01:50.083260 2025] [wsgi:error] [pid 4155463:tid 4155502] [client <Builder>:59204] 2025-02-19 08:01:50,083 [INFO] m=None u=None p=4155463 r=<Builder>:59204 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:02.777730 2025] [wsgi:error] [pid 4157263:tid 4157300] [client <Builder>:50382] 2025-02-19 08:05:02,777 [INFO] m=None u=None p=4157263 r=<Builder>:50382 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:03.850133 2025] [wsgi:error] [pid 4157263:tid 4157302] [client <Builder>:50382] 2025-02-19 08:05:03,849 [INFO] m=None u=None p=4157263 r=<Builder>:50382 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:03.899340 2025] [wsgi:error] [pid 4157263:tid 4157304] [client <Builder>:50382] 2025-02-19 08:05:03,899 [INFO] m=None u=None p=4157263 r=<Builder>:50382 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:03.947905 2025] [wsgi:error] [pid 4157263:tid 4157306] [client <Builder>:50382] 2025-02-19 08:05:03,947 [INFO] m=None u=None p=4157263 r=<Builder>:50382 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:04.025338 2025] [wsgi:error] [pid 4157263:tid 4157308] [client <Builder>:50382] 2025-02-19 08:05:04,025 [INFO] m=None u=None p=4157263 r=<Builder>:50382 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:10.895151 2025] [wsgi:error] [pid 4157264:tid 4157299] [client <Builder>:37664] 2025-02-19 08:05:10,895 [INFO] m=None u=None p=4157264 r=<Builder>:37664 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:10.979600 2025] [wsgi:error] [pid 4157264:tid 4157303] [client <Builder>:37664] 2025-02-19 08:05:10,979 [INFO] m=None u=None p=4157264 r=<Builder>:37664 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:11.062044 2025] [wsgi:error] [pid 4157264:tid 4157305] [client <Builder>:37664] 2025-02-19 08:05:11,061 [INFO] m=None u=None p=4157264 r=<Builder>:37664 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:11.132518 2025] [wsgi:error] [pid 4157264:tid 4157307] [client <Builder>:37664] 2025-02-19 08:05:11,132 [INFO] m=None u=None p=4157264 r=<Builder>:37664 koji.db: Creating a fresh database connection [Wed Feb 19 08:05:11.206793 2025] [wsgi:error] [pid 4157264:tid 4157301] [client <Builder>:37664] 2025-02-19 08:05:11,206 [INFO] m=None u=None p=4157264 r=<Builder>:37664 koji.db: Creating a fresh database connection [Wed Feb 19 08:11:04.735736 2025] [wsgi:error] [pid 4160744:tid 4160754] [client <HUB>:41500] 2025-02-19 08:11:04,735 [INFO] m=None u=None p=4160744 r=<HUB>:41500 koji.db: Creating a fresh database connection [Wed Feb 19 08:11:04.780758 2025] [wsgi:error] [pid 4160744:tid 4160755] [client <HUB>:41500] 2025-02-19 08:11:04,780 [INFO] m=None u=None p=4160744 r=<HUB>:41500 koji.db: Creating a fresh database connection [Wed Feb 19 08:11:09.953501 2025] [wsgi:error] [pid 4160744:tid 4160758] [client <Client>:53722] 2025-02-19 08:11:09,953 [INFO] m=None u=None p=4160744 r=<Client>:53722 koji.db: Creating a fresh database connection [Wed Feb 19 08:11:09.995607 2025] [wsgi:error] [pid 4160744:tid 4160757] [client <Client>:53722] 2025-02-19 08:11:09,995 [INFO] m=None u=None p=4160744 r=<Client>:53722 koji.db: Creating a fresh database connection [Wed Feb 19 08:11:10.048549 2025] [wsgi:error] [pid 4160744:tid 4160756] [client <Client>:53722] 2025-02-19 08:11:10,048 [INFO] m=None u=None p=4160744 r=<Client>:53722 koji.db: Creating a fresh database connection [Wed Feb 19 08:14:13.943174 2025] [wsgi:error] [pid 4162511:tid 4162521] [client <Builder>:57310] 2025-02-19 08:14:13,943 [INFO] m=None u=None p=4162511 r=<Builder>:57310 koji.db: Creating a fresh database connection [Wed Feb 19 08:14:13.991724 2025] [wsgi:error] [pid 4162511:tid 4162524] [client <Builder>:57310] 2025-02-19 08:14:13,991 [INFO] m=None u=None p=4162511 r=<Builder>:57310 koji.db: Creating a fresh database connection [Wed Feb 19 08:14:14.044818 2025] [wsgi:error] [pid 4162511:tid 4162523] [client <Builder>:57310] 2025-02-19 08:14:14,044 [INFO] m=None u=None p=4162511 r=<Builder>:57310 koji.db: Creating a fresh database connection [Wed Feb 19 08:14:14.094193 2025] [wsgi:error] [pid 4162511:tid 4162525] [client <Builder>:57310] 2025-02-19 08:14:14,094 [INFO] m=None u=None p=4162511 r=<Builder>:57310 koji.db: Creating a fresh database connection [Wed Feb 19 08:14:14.147784 2025] [wsgi:error] [pid 4162511:tid 4162522] [client <Builder>:57310] 2025-02-19 08:14:14,147 [INFO] m=None u=None p=4162511 r=<Builder>:57310 koji.db: Creating a fresh database connection [Wed Feb 19 08:17:50.100204 2025] [wsgi:error] [pid 4164104:tid 4164114] [client <Client>:58806] 2025-02-19 08:17:50,100 [INFO] m=None u=None p=4164104 r=<Client>:58806 koji.db: Creating a fresh database connection [Wed Feb 19 08:17:50.142235 2025] [wsgi:error] [pid 4164104:tid 4164115] [client <Client>:58806] 2025-02-19 08:17:50,142 [INFO] m=None u=None p=4164104 r=<Client>:58806 koji.db: Creating a fresh database connection [Wed Feb 19 08:17:50.183707 2025] [wsgi:error] [pid 4164104:tid 4164116] [client <Client>:58806] 2025-02-19 08:17:50,183 [INFO] m=None u=None p=4164104 r=<Client>:58806 koji.db: Creating a fresh database connection [Wed Feb 19 08:17:50.225172 2025] [wsgi:error] [pid 4164104:tid 4164117] [client <Client>:58806] 2025-02-19 08:17:50,225 [INFO] m=None u=None p=4164104 r=<Client>:58806 koji.db: Creating a fresh database connection [Wed Feb 19 08:17:50.269378 2025] [wsgi:error] [pid 4164104:tid 4164118] [client <Client>:58806] 2025-02-19 08:17:50,269 [INFO] m=None u=None p=4164104 r=<Client>:58806 koji.db: Creating a fresh database connection [Wed Feb 19 08:20:49.781613 2025] [wsgi:error] [pid 4165966:tid 4165976] [client <Builder>:45536] 2025-02-19 08:20:49,781 [INFO] m=None u=None p=4165966 r=<Builder>:45536 koji.db: Creating a fresh database connection [Wed Feb 19 08:20:49.831688 2025] [wsgi:error] [pid 4165966:tid 4165977] [client <Builder>:45536] 2025-02-19 08:20:49,831 [INFO] m=None u=None p=4165966 r=<Builder>:45536 koji.db: Creating a fresh database connection [Wed Feb 19 08:20:49.882397 2025] [wsgi:error] [pid 4165966:tid 4165978] [client <Builder>:45536] 2025-02-19 08:20:49,882 [INFO] m=None u=None p=4165966 r=<Builder>:45536 koji.db: Creating a fresh database connection [Wed Feb 19 08:20:49.933512 2025] [wsgi:error] [pid 4165966:tid 4165979] [client <Builder>:45536] 2025-02-19 08:20:49,933 [INFO] m=None u=None p=4165966 r=<Builder>:45536 koji.db: Creating a fresh database connection [Wed Feb 19 08:20:49.979072 2025] [wsgi:error] [pid 4165966:tid 4165980] [client <Builder>:45536] 2025-02-19 08:20:49,978 [INFO] m=None u=None p=4165966 r=<Builder>:45536 koji.db: Creating a fresh database connection [Wed Feb 19 08:24:17.260828 2025] [wsgi:error] [pid 4167005:tid 4167015] [client <Builder>:55464] 2025-02-19 08:24:17,260 [INFO] m=None u=None p=4167005 r=<Builder>:55464 koji.db: Creating a fresh database connection [Wed Feb 19 08:24:22.508944 2025] [wsgi:error] [pid 4167005:tid 4167018] [client <HUB>:46792] 2025-02-19 08:24:22,508 [INFO] m=None u=None p=4167005 r=<HUB>:46792 koji.db: Creating a fresh database connection [Wed Feb 19 08:24:22.562598 2025] [wsgi:error] [pid 4167005:tid 4167019] [client <HUB>:46792] 2025-02-19 08:24:22,562 [INFO] m=None u=None p=4167005 r=<HUB>:46792 koji.db: Creating a fresh database connection [Wed Feb 19 08:24:24.289741 2025] [wsgi:error] [pid 4167005:tid 4167016] [client <Builder>:55464] 2025-02-19 08:24:24,289 [INFO] m=None u=None p=4167005 r=<Builder>:55464 koji.db: Creating a fresh database connection [Wed Feb 19 08:24:24.616592 2025] [wsgi:error] [pid 4167005:tid 4167017] [client <HUB>:52982] 2025-02-19 08:24:24,616 [INFO] m=None u=None p=4167005 r=<HUB>:52982 koji.db: Creating a fresh database connection [Wed Feb 19 08:26:18.604094 2025] [wsgi:error] [pid 4168141:tid 4168151] [client <Client>:40558] 2025-02-19 08:26:18,604 [INFO] m=None u=None p=4168141 r=<Client>:40558 koji.db: Creating a fresh database connection [Wed Feb 19 08:26:18.643448 2025] [wsgi:error] [pid 4168141:tid 4168152] [client <Client>:40558] 2025-02-19 08:26:18,643 [INFO] m=None u=None p=4168141 r=<Client>:40558 koji.db: Creating a fresh database connection [Wed Feb 19 08:26:18.683356 2025] [wsgi:error] [pid 4168141:tid 4168153] [client <Client>:40558] 2025-02-19 08:26:18,683 [INFO] m=None u=None p=4168141 r=<Client>:40558 koji.db: Creating a fresh database connection [Wed Feb 19 08:26:18.724443 2025] [wsgi:error] [pid 4168141:tid 4168154] [client <Client>:40558] 2025-02-19 08:26:18,724 [INFO] m=None u=None p=4168141 r=<Client>:40558 koji.db: Creating a fresh database connection [Wed Feb 19 08:26:24.817239 2025] [wsgi:error] [pid 4168141:tid 4168155] [client <Client>:52504] 2025-02-19 08:26:24,817 [INFO] m=None u=None p=4168141 r=<Client>:52504 koji.db: Creating a fresh database connection [Wed Feb 19 08:30:56.936014 2025] [wsgi:error] [pid 4170750:tid 4170760] [client <HUB>:49746] 2025-02-19 08:30:56,935 [INFO] m=None u=None p=4170750 r=<HUB>:49746 koji.db: Creating a fresh database connection [Wed Feb 19 08:30:56.988393 2025] [wsgi:error] [pid 4170750:tid 4170761] [client <HUB>:49746] 2025-02-19 08:30:56,988 [INFO] m=None u=None p=4170750 r=<HUB>:49746 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:04.609456 2025] [wsgi:error] [pid 4170750:tid 4170763] [client <HUB>:60106] 2025-02-19 08:31:04,609 [INFO] m=None u=None p=4170750 r=<HUB>:60106 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:07.290111 2025] [wsgi:error] [pid 4170750:tid 4170764] [client <HUB>:60122] 2025-02-19 08:31:07,289 [INFO] m=None u=None p=4170750 r=<HUB>:60122 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:08.017160 2025] [wsgi:error] [pid 4170750:tid 4170762] [client <HUB>:60122] 2025-02-19 08:31:08,016 [INFO] m=None u=None p=4170750 r=<HUB>:60122 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:43.976926 2025] [wsgi:error] [pid 4171263:tid 4171273] [client <Builder>:52954] 2025-02-19 08:31:43,976 [INFO] m=None u=None p=4171263 r=<Builder>:52954 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:44.027126 2025] [wsgi:error] [pid 4171263:tid 4171274] [client <Builder>:52954] 2025-02-19 08:31:44,027 [INFO] m=None u=None p=4171263 r=<Builder>:52954 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:44.075203 2025] [wsgi:error] [pid 4171263:tid 4171275] [client <Builder>:52954] 2025-02-19 08:31:44,075 [INFO] m=None u=None p=4171263 r=<Builder>:52954 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:44.125318 2025] [wsgi:error] [pid 4171263:tid 4171276] [client <Builder>:52954] 2025-02-19 08:31:44,125 [INFO] m=None u=None p=4171263 r=<Builder>:52954 koji.db: Creating a fresh database connection [Wed Feb 19 08:31:44.175738 2025] [wsgi:error] [pid 4171263:tid 4171277] [client <Builder>:52954] 2025-02-19 08:31:44,175 [INFO] m=None u=None p=4171263 r=<Builder>:52954 koji.db: Creating a fresh database connection [Wed Feb 19 08:37:40.531350 2025] [wsgi:error] [pid 4174459:tid 4174470] [client <HUB>:41962] 2025-02-19 08:37:40,531 [INFO] m=None u=None p=4174459 r=<HUB>:41962 koji.db: Creating a fresh database connection [Wed Feb 19 08:37:40.575628 2025] [wsgi:error] [pid 4174459:tid 4174469] [client <HUB>:41962] 2025-02-19 08:37:40,575 [INFO] m=None u=None p=4174459 r=<HUB>:41962 koji.db: Creating a fresh database connection [Wed Feb 19 08:37:45.818774 2025] [wsgi:error] [pid 4174459:tid 4174472] [client <HUB>:51102] 2025-02-19 08:37:45,818 [INFO] m=None u=None p=4174459 r=<HUB>:51102 koji.db: Creating a fresh database connection [Wed Feb 19 08:37:45.865918 2025] [wsgi:error] [pid 4174459:tid 4174473] [client <HUB>:51102] 2025-02-19 08:37:45,865 [INFO] m=None u=None p=4174459 r=<HUB>:51102 koji.db: Creating a fresh database connection [Wed Feb 19 08:37:46.684086 2025] [wsgi:error] [pid 4174459:tid 4174471] [client <HUB>:51102] 2025-02-19 08:37:46,683 [INFO] m=None u=None p=4174459 r=<HUB>:51102 koji.db: Creating a fresh database connection
The hub does not share connections across threads, so it will use a connection per thread. If you have 10 workers with 5 threads each, that will tend to reach 50 connections.
So I think this comes back to balancing the limit settings on your db vs httpd.
If you do have a case where these connections are growing without bound as you seemed to suggest at first, I would definitely like to hear the details.
Hi, today I tested it again. With every package build initiated by an "koji build --scratch" call I see 5 new databases connections. At an count of 80 I have stopped it. It looks for me, that the threads never gets cleaned up.
It looks for me, that the threads never gets cleaned up
koji does not control the threads, it is executed that way by httpd. You may be able to get httpd to throttle down the workers when idle. Perhaps trying lowering MinSpareThreads?
MinSpareThreads
In the documentation of apache, 75 threads are noted as default. But lowering it to 5 will not change anything :(
Metadata Update from @mikem: - Issue set to the milestone: 1.36.1 (was: 1.36)
@mikem , @tkopecek : same issue for https://cbs.centos.org Same settings for the VM, same kojihub version but it was just migrated to RHEL9 (from RHEL8) We see the same behavior and so it's filling the connections until postgresql is rejecting and so only workaround is to restart httpd multiple times a day, while it was just stable and working. Other difference is then also the postgresql version, as it bumped from 11 to 13 (postgresql is on localhost for koji-hub and with only that DB)
Also worth knowing that due to other issue in the past for another koji call (for moving files to other volumes) we had to migrate to mpm_event (http://httpd.apache.org/docs/2.4/mod/event.html) instead of mpm_worker (http://httpd.apache.org/docs/2.4/mod/worker.html) Would that be related and worth trying back to worker now ?
Sorry, found the issue (https://issues.redhat.com/browse/CS-2090) and it's for another kojihub and also https://pagure.io/koji/issue/3755#comment-895292 So worth trying to just move to mpm_prefork and see if that solves the db connection issues
@frank-mdc : just fwiw, I switched httpd to prefork and it seems really stable, including for number of postgresql connections .. it was growing above 1000 in event mode, but it's now between 85 and 125 connections . Worth trying switching to http://httpd.apache.org/docs/2.4/mod/prefork.html ?
I wonder if #4330 makes a difference here?
@arrfab it looks much better now.
So, the more I think about it, the more I think #4330 might solve the issue seen here. I was never able to reproduce it locally (event though I also use the event module for testing), so I'd be really curious if you could verify that.
Of course using prefork will also work since it takes threads out of the equation.
Yes I will retry it, as soon 1.36 are releases under EPEL for RHEL-9.
This issue has been migrated to Fedora Forge: https://forge.fedoraproject.org/koji/koji/issues/4175
Please continue any further discussion there.