Koji DB Issues
This wiki page discusses known issues with the Koji application and its use of the PostgreSQL database which backs it.
Last Updated: 2016-04-13
Long-Running Transactions
Currently one or more processes in Koji are opening transactions and keeping them open for several hours. For example, on 4-13 a process had a transaction open for 5 hours and was running this query, which lasted at least 1 hour:
SELECT standard_buildroot.create_event
FROM buildroot_listing
JOIN standard_buildroot ON buildroot_listing.buildroot_id = standard_buildroot.buildroot_id
WHERE (buildroot_listing.rpm_id = 35643)
ORDER BY standard_buildroot.create_event DESC
LIMIT 1
Is is unclear on whether these long-running transactions are running for a long time due to the individual queries being very slow from some other cause, or due to some other reason.
Regardless, there are several effects of these transactions which eventually cause koji-db to become completely unresponsive, over the course of 18 to 48 hours:
- the transactions hold locks on individual rows in the sessions table, and cause lock pileups. This compounds with the Session Locking Retries issue below.
- it blocks Autovacuum from doing its work, leading to table bloat and out-of-date query statistics.
- it causes side effects with the query planner where certain kinds of queries get very slow due to row visibility overhead.
- sometimes, PostgreSQL is unable to sort out the lock pileup even when the original transaction is done.
Resolution
- Deploy a cron killscipt which kills off idle transactions, long-running transactions and stuck lock waits, and log information about it (done).
- Debug reason(s) for long-running transactions and change application to avoid them.
- Improve IO (see Slow IO below)
Session Locking Retries
When certain calls request locks in the sessions table (and possibly elsewhere), and are unable to obtain them, they apparently retry without ever closing the original database session. It is unknown whether this is happening in Koji, or is a result of the calling RPC being retried; the latter seems more likely. The result, however, is dozens of requests stacked up on requesting a lock on the same row, which then causes database performance issues.
Example query:
SELECT exclusive,authtype,master,EXTRACT(EPOCH FROM update_time),callnum,user_id,start_time,expired,update_time,EXTRACT(EPOCH FROM start_time) FROM sessions WHERE id = 21444149 AND key = 'XXXXXXXXXXXXXXXXXXXX' AND hostip = '10.5.125.62' FOR UPDATE
Resolution
- SELECT FOR UPDATE queries like the above should use NOWAIT;
- Consider upgrading to PostgreSQL 9.5 in order to take advantage of lock_timeout and/or SKIP LOCKED;
- Koji could detect duplicate session requests from RPC, maybe, and reject them.
Session Lock-Blocking
Even though sessions are supposed to be unique, multiple calls trying to use the same sessionIDs is a persistent and frequent reality. This creates unnecessary database overhead, as a significant amount of CPU time is devoted to lock waits. Also, if something else happens to make the database slow, the lock-blocking makes the overall performance situation much worse.
Resolution
- enable log_lock_waits so that we can see the longer-running lock-blocks in the log and debug them in the future;
- Look for places in Koji where multiple clients could have the same session ID, or where one Koji session could have multiple DB connections open.
Slow IO
IO on the current KojiDB system has a low ceiling of around 10MB/s and 1200 TPS. Current query activity frequently hits that limit, especially if one of the larger tables gets queried.
From sar:
04:00:12 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util 04:00:15 PM dev252-0 809.33 21482.67 170.67 26.75 1.27 1.58 1.19 96.33 04:00:15 PM dev253-0 809.33 21482.67 170.67 26.75 1.27 1.59 1.19 96.47
04:00:15 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util 04:00:18 PM dev252-0 1035.00 27578.67 80.00 26.72 1.43 1.38 0.93 96.00 04:00:18 PM dev253-0 1035.00 27578.67 80.00 26.72 1.43 1.38 0.93 96.27
04:00:18 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util 04:00:21 PM dev252-0 1158.67 25824.00 1007.00 23.16 1.46 1.26 0.80 92.50 04:00:21 PM dev253-0 1159.00 25824.00 1007.00 23.15 1.47 1.27 0.80 92.73
Resolution
- Kevin to plan move to server with faster, local storage.
- Josh to recommend some postgresql.conf tuning for better IO.
Design of Sessions Table
The sessions table is frequently queried, and has 8 columns most of which are indexed. It gets updated every time a session has any activity. This places a heavy garbage collection load on PostgreSQL (autovacuum) for rows in the sessions table, and leads to the sessions table becoming extremely "bloated" with poor performance (up to 8GB when only around 100MB is needed). This problem is compounded by the long-running transactions issue.
Fixing this will require a refactor of parts of Koji, so there is no database-only fix. Possibilities might include:
- removing some indexes
- splitting off last_updated into a separate table
- creating a ring buffer set of partitions so that old sessions can be purged more efficiently
A more modest, immediate step might be to include a "TRUNCATE sessions" or "VACUUM FULL sessions" into every planned downtime for Koji.
Slow queries against buildroot
Buildroot_listing table is quite large, 125GB. As a result, any query hitting this table which does not properly use an index will create IO load lasting minutes to hours.
Resolution
- enable log_min_duration_statement=60s and pgbadger log formatting in order to capture slow-running query information.
- audit indexes for this table
- discuss whether there is data in this table which could be archived