PostgreSQL pg_stat_activity shows COMMIT

Question

We recently replaced our database server with an upgraded machine with 4 x quad core CPUs and 32Gb of ram. We also repurposed our old box to serve as a slave with streaming replication. Both boxes are running CentOS 6.3 and PostgreSQL 9.2. Postgres is the only thing running on each of the boxes.

This configuration has been in place for about a month or so, when suddenly we started running into some issues as traffic started ramping up. What we have started to see is an extremely high CPU load at times (top shows a load average of 270), and when we can look at pg_stat_activity we will see most of our connections are in the COMMIT state. When left alone, this will eventually finish and the system will become responsive with the connections becoming IDLE. We have tried disabling replication to see if that might be the issue, but the problem still persists.

We have tried diagnosing what is happening, and are a bit lost. The output from running perf shows something similar to below, and I have no idea what 0x347ba9 represents.

+  41.40%       48154  postmaster  0x347ba9         f 0x347ba9                                   ◆
+   9.55%       10956  postmaster  0x2dc820         f set_config_option                          ▒
+   8.64%        9946  postmaster  0x5a3d4          f writeListPage     
+   5.75%        6609  postmaster  0x5a2b0          f ginHeapTupleFastCollect                    ▒
+   2.68%        3084  postmaster  0x192483         f build_implied_join_equality                ▒
+   2.61%        2990  postmaster  0x187a55         f build_paths_for_OR                         ▒
+   1.86%        2131  postmaster  0x794aa          f get_collation_oid                          ▒
+   1.56%        1822  postmaster  0x5a67e          f ginHeapTupleFastInsert                     ▒
+   1.53%        1766  postmaster  0x1929bc         f distribute_qual_to_rels                    ▒
+   1.33%        1558  postmaster  0x249671         f cmp_numerics

None of the queries performed by the app are particularly complex, with explain plans taking at most 1 second (most are much quicker). Additionally, while this happens when the traffic starts to pick up, we're not talking about a huge traffic load (The old machine used to be able to handle it pretty easily).

At this point I am a bit stumped about what to try next. Any help or suggestions would be appreciated. If there is any additional information that would help, just ask and I can amend the question.

Disk Configuration:

• Perc 6i RAID Controller
• 5 x 146GB 15K SAS drives
• Configured as 2x146GB RAID-1 for WAL and 3x146GB RAID-5 for System and Data

Update:

Below is the VMStat output when the system is functioning normally and when the CPU shoots up. When there is an issue, the interrupts seem to skyrocket.

During normal operation:

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ ---timestamp---
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 18938590 303763 21947154    0    0    28    52 7466 12649  2  1 97  0  0   2013-01-14 16:03:25 EST
 0  0      0 18938396 303763 21947154    0    0     0    19 7107 12679  2  0 98  0  0   2013-01-14 16:03:35 EST
 1  0      0 18938904 303763 21947162    0    0     0    54 7042 12708  1  1 99  0  0   2013-01-14 16:03:45 EST
 1  0      0 18938520 303763 21947260    0    0    33    66 7120 12738  1  1 99  0  0   2013-01-14 16:03:55 EST

When CPU usage is high:

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ ---timestamp---
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
343 0      0 32680468 226279 11339612    0    0     0   214 26692 12225 80  20  0  0  0   2013-01-11 16:45:53 EST
374 1      0 32673764 226291 11340345    0    0     0    77 54893 11572 80  20  0  0  0   2013-01-11 16:46:03 EST
383 0      0 32616620 226304 11340956    0    0     0   102 55540 12922 82  18  0  0  0   2013-01-11 16:46:13 EST
315 0      0 32602038 226320 11341378    0    0     0    79 54539 12441 82  18  0  0  0   2013-01-11 16:46:23 EST

Answer 1

After further diagnostics and some Googling, we came across this article that described many of the same symtoms we were experiencing. The root cause of their problem (and from what we can tell, ours too) was related to the Transparent Huge Pages implementation.

After disabling Transparent Huge Pages with this command:

echo never > /sys/kernel/mm/redhat_transparent_hugepage/enabled

The problem appears to have been resolved. We've been running under an increased workload for the last two weeks and the issue has not resurfaced. The system's contexts and interrupts are consistently 1/10th of what they had been and average system time has decreased as well.

Not sure if it is the solution for everyone, but I post it here as a possible cause in case it can help anyone else resolve a similar issue.