Postgresql – Horrible PostgreSQL locking performance

freebsdperformancepostgresql

I recently noticed a very horrible PostgreSQL locking performance drop after running the DB server for a couple month. The load of the website increased a lot these weeks but the speed is getting slower.

$ psql webspace2_db
psql (9.0.1)
Type "help" for help.
webspace2_db=# 

The DB server is running FreeBSD 8.1 + PostgreSQL 9.0.1

FreeBSD Moncalvo 8.1-RELEASE-p2 FreeBSD 8.1-RELEASE-p2 #1: Mon Jan 10 13:02:48 MYT 2011     hailang@Moncalve:/usr/obj/usr/src/sys/Moncalve  amd64

Total memory on the server is 4GB

Moncalvo# cat /var/run/dmesg.boot | grep memory
real memory  = 4294967296 (4096 MB)
avail memory = 4101955584 (3911 MB)

Totally 3GB of shared memory is entitled in the kernel configuration

# Shared Memory
options          SEMMNI=256
options          SEMMSL=128
options          SEMMNS=32768
options          SEMMAP=512
options          SEMMNU=256
options      SEMOPM=128
options          SHMMNI=512
options          SHMSEG=256
options          SHMMAX=3221225472
options      SHMALL=3221225472
options          SHMMAXPGS=786432

These are key postgresql.conf settings

Moncalvo# cat postgresql.conf | grep shared_buffers
shared_buffers = 512MB          # min 128kB

Moncalvo# cat postgresql.conf | grep effective_cache_size
effective_cache_size = 3276MB

Moncalvo# cat postgresql.conf | grep work_mem
work_mem = 256MB                # min 64kB
maintenance_work_mem = 128MB        # min 1MB

According to the users that the website is getting slower and slower these days, I have tuned web services on another server a lot but without effective performance improvement, so I'm thinking that maybe the problem is with the DB server. So I logged slow queries and found most of them are with locking mechanism, and some of the time consumed are horrible.

LOG:  duration: 4768697.255 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4739020.976 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4709376.119 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4679438.894 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4649714.811 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4619931.184 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4590323.188 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4560627.214 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4530796.297 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4501178.286 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4471515.579 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4441832.934 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4410774.012 ms  statement: SELECT pg_advisory_lock(93690)
LOG:  duration: 4382435.595 ms  statement: SELECT pg_advisory_lock(93690)

Any help and suggestion is highly appreciated.

Best Answer

I am not an DB expert, but it looks like invalid use of Advisory Locks somewhere in your application.

PostgreSQL provides a means for creating locks that have application-defined meanings. These are called advisory locks, because the system does not enforce their use — it is up to the application to use them correctly.

and

Like all locks in PostgreSQL, a complete list of advisory locks currently held by any session can be found in the pg_locks system view.

Edit:

Looking into moodle source code, /moodle/lib/dml/pgsql_native_moodle_database.php I just found something, that might be interesting:

public function get_session_lock($rowid) {
    // NOTE: there is a potential locking problem for database running
    // multiple instances of moodle, we could try to use
    // pg_advisory_lock(int, int), luckily there is not a big chance
    // that they would collide
    if (!$this->session_lock_supported()) {
        return;
    }

    parent::get_session_lock($rowid);
    $sql = "SELECT pg_advisory_lock($rowid)";
    ...
}