Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

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
share|improve this question
    
What kind of disks does the new box have? Is this happening on both nodes or only one of them? –  trygvis Jan 14 '13 at 17:47
    
@trygvis - I Updated the question with the disk specs. The issue is happening on the Master node. I have not tried to promote the Slave and direct traffic to it, so I am not sure if it is an issue there as well under the same circumstances. As a slave, the machine does not seem to experience any issues. –  jcern Jan 14 '13 at 17:54
2  
Consider using the perf tool to do some system-wide profiling and some PostgreSQL profiling. See where the CPU usage is occurring. BTW, the formatting of your 2nd vmstat is hopelessly mangled, and the 1st one's columns are misaligned so it's hard to read. Test to see whether adding a commit_delay improves things. Check if your RAID controller has a battery-backed write-back cache and if it doesn't, get one. Is much time spent in iowait? This appears to be CPU usage in some reporting, but isn't really. –  Craig Ringer Jan 15 '13 at 0:06
    
@CraigRinger the controller does have a battery-backed write cache, and that is currently enabled. Await from iostat remained in the single to low double digits. We will continue to try some more profiling with perf. I also fixed the formatting of the second VMStat, thank you for pointing that out. –  jcern Jan 15 '13 at 20:09

1 Answer 1

up vote 6 down vote accepted

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.

share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.