9

using PostgreSQL 9.1.2

I'm seeing excessive CPU usage and large amounts of writes to disk from postmaster tasks. This happens even while my application is doing almost nothing (10s of inserts per MINUTE). There are a reasonable number of connections open however.

I've been trying to determine what in my application is causing this. I'm pretty newb with postgresql, and haven't gotten anywhere so far. I've turned on some logging options in my config file, and looked at connections in the pg_stat_activity table, but they are all idle. Yet each connection consumes ~ 50% CPU, and is writing ~15M/s to disk (reading nothing).

I'm basically using the stock postgresql.conf with very little tweaks. I'd appreciate any advice or pointers on what I can do to track this down.

Here is a sample of what top/iotop is showing me:

Cpu(s): 18.9%us, 14.4%sy,  0.0%ni, 53.4%id, 11.8%wa,  0.0%hi,  1.5%si,  0.0%st
Mem:  32865916k total,  7263720k used, 25602196k free,   575608k buffers
Swap: 16777208k total,        0k used, 16777208k free,  4464212k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                          
17057 postgres  20   0  236m  33m  13m R 45.0  0.1  73:48.78 postmaster                                                                                                                       
17188 postgres  20   0  219m  15m  11m R 42.3  0.0  61:45.57 postmaster                                                                                                                       
17963 postgres  20   0  219m  16m  11m R 42.3  0.1  27:15.01 postmaster                                                                                                                       
17084 postgres  20   0  219m  15m  11m S 41.7  0.0  63:13.64 postmaster                                                                                                                       
17964 postgres  20   0  219m  17m  12m R 41.7  0.1  27:23.28 postmaster                                                                                                                       
18688 postgres  20   0  219m  15m  11m R 41.3  0.0  63:46.81 postmaster                                                                                                                       
17088 postgres  20   0  226m  24m  12m R 41.0  0.1  64:39.63 postmaster                                                                                                                       
24767 postgres  20   0  219m  17m  12m R 41.0  0.1  24:39.24 postmaster                                                                                                                       
18660 postgres  20   0  219m  14m 9.9m S 40.7  0.0  60:51.52 postmaster                                                                                                                       
18664 postgres  20   0  218m  15m  11m S 40.7  0.0  61:39.61 postmaster                                                                                                                       
17962 postgres  20   0  222m  19m  11m S 40.3  0.1  11:48.79 postmaster                                                                                                                       
18671 postgres  20   0  219m  14m   9m S 39.4  0.0  60:53.21 postmaster                                                                                                                       
26168 postgres  20   0  219m  15m  10m S 38.4  0.0  59:04.55 postmaster  


Total DISK READ: 0.00 B/s | Total DISK WRITE: 195.97 M/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND                                                                                                                        
17962 be/4 postgres    0.00 B/s   14.83 M/s  0.00 %  0.25 % postgres: aggw aggw [local] idle
17084 be/4 postgres    0.00 B/s   15.53 M/s  0.00 %  0.24 % postgres: aggw aggw [local] idle
17963 be/4 postgres    0.00 B/s   15.00 M/s  0.00 %  0.24 % postgres: aggw aggw [local] idle
17188 be/4 postgres    0.00 B/s   14.80 M/s  0.00 %  0.24 % postgres: aggw aggw [local] idle
17964 be/4 postgres    0.00 B/s   15.50 M/s  0.00 %  0.24 % postgres: aggw aggw [local] idle
18664 be/4 postgres    0.00 B/s   15.13 M/s  0.00 %  0.23 % postgres: aggw aggw [local] idle
17088 be/4 postgres    0.00 B/s   14.71 M/s  0.00 %  0.13 % postgres: aggw aggw [local] idle
18688 be/4 postgres    0.00 B/s   14.72 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle
24767 be/4 postgres    0.00 B/s   14.93 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle
18671 be/4 postgres    0.00 B/s   16.14 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle
17057 be/4 postgres    0.00 B/s   13.58 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle
26168 be/4 postgres    0.00 B/s   15.50 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle
18660 be/4 postgres    0.00 B/s   15.85 M/s  0.00 %  0.00 % postgres: aggw aggw [local] idle

Update: A lot of the file writing seems to be to some temporary (?) files in the $PG_DATA/base/ directory. My understanding of the file structure here is that each table is basically stored as a file whose name is the OID of the table. However, there are tons of files named tnn_nnnnnnn, and it is these files that appear to be written to (perhaps written over) constantly. What are these files for? There is ~4700 of the files, and all are 8K in size:

-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t12_1430975
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t16_1432736
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t28_1439066
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t24_1436243
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t24_1436210
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t19_1393372
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t28_1439051
-rw-------. 1 postgres postgres     8192 Jul  3 23:08 t8_1430334

Update: Running strace on the postmaster processes basically shows a lot of file I/O stuff:

open("base/16388/t24_1435947_fsm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/16388/t24_1435947_vm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/16388/t24_1435947", O_RDWR)  = 9
lseek(9, 0, SEEK_END)                   = 8192
ftruncate(9, 0)                         = 0
lseek(9, 0, SEEK_END)                   = 0
open("base/16388/t24_1435941", O_RDWR)  = 18
lseek(18, 0, SEEK_END)                  = 0
write(9, "\0\0\0\0\0\0\0\0\1\0\0\0000\0\360\37\360\37\4 \0\0\0\0b1\5\0\2\0\0\0"..., 8192) = 8192
lseek(18, 0, SEEK_END)                  = 0
close(9)                                = 0
open("base/16388/t24_1435947", O_RDWR)  = 9
lseek(9, 0, SEEK_END)                   = 8192
close(18)                               = 0
close(9)                                = 0
open("base/16388/t24_1435944_fsm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/16388/t24_1435944_vm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/16388/t24_1435944", O_RDWR)  = 9
lseek(9, 0, SEEK_END)                   = 0
close(9)                                = 0

Update: So this problem does appear to be everything to do with temporary tables. We changed our setup so the temporary tables are 'regular' tables, and all the disk activity went away, and performance is back to where I expected it to be. Now, this change was just a quick and dirty test: if we are really going to change to use regular tables, we have issues with concurrency, and cleanup. Are temporary tables really that evil, or are we abusing them?

Update: Some more background. I'm making use of a in-house developed statement based replication middleware. It's quite mature and has been in use on a number of projects over a number of years, but using MySQL. We've only been working with PostgreSQL for the last year or two. We were essentially using the temporary tables as part of the replication mechanism. Whenever a new connection is established, we create a temporary table for each table in the database. With 10-20 (long-lived) connections and ~50 tables, this can amount to a lot of temporary tables. All temporary tables were created with:

CREATE TEMPORARY TABLE... ON COMMIT DELETE ROWS;

The semantics of temporary tables fit very well with our replication scheme, and simplified a lot of the code we had to use for MySQL, but it looks like the implementation didn't fair as well. From the bit of research I've done, I don't think temporary tables were really meant for the function we were using them for.

I'm not the in-house expert (not even close) on this subject, just a user of it, so my explanation might not be 100% accurate, but I think it's pretty close.

9
  • 3
    Your understanding is a bit outdated, if you look at the official documention, you'll find that "... for temporary relations, the file name is of the form tBBB_FFF, where BBB is the backend ID of the backend which created the file, and FFF is the filenode number. ..." Jul 4, 2012 at 0:00
  • Wow, that's a well-performing disk I/O subsystem. What does strace say about what the workers are actually doing?
    – womble
    Jul 4, 2012 at 5:58
  • @MilenA.Radev, so it looks like I might be doing something weird/excessive with temporary tables. This is interesting. I do have a lot of triggers in place that do make use of temporary tables. I will look closer at these.
    – wolfcastle
    Jul 4, 2012 at 15:04
  • @womble, I have updated the question with output from strace.
    – wolfcastle
    Jul 4, 2012 at 15:05
  • Are you actually experiencing a performance problem?
    – voretaq7
    Aug 1, 2012 at 15:23

3 Answers 3

1

Your PostgreSQL configuration is way off. This was suspicious from your initial post,

 Cpu(s): 18.9%us, 14.4%sy,  0.0%ni, 53.4%id, 11.8%wa,  0.0%hi,  1.5%si,  0.0%st
 Mem:  32865916k total,  7263720k used, 25602196k free,   575608k buffers
 Swap: 16777208k total,        0k used, 16777208k free,  4464212k cached

Out of 32GB on your server, ~25GB is free excluding ~575MB of buffer.

From your postgresql.conf file,

 shared_buffers = 32MB                   # min 128kB                               
 #temp_buffers = 8MB                     # min 800kB
 #max_prepared_transactions = 0          # zero disables the feature
 ...
 #work_mem = 1MB                         # min 64kB
 #maintenance_work_mem = 16MB            # min 1MB
 #max_stack_depth = 2MB   

I'm assuming this is a dedicated database. If so, change it to the following parameters and reload/restart,

 shared_buffers = 16GB                   # min 128kB                               
 temp_buffers = 128MB                     # min 800kB
 #max_prepared_transactions = 0          # zero disables the feature
 ...
 work_mem = 8MB                         # min 64kB
 maintenance_work_mem = 64MB            # min 1MB
 max_stack_depth = 4MB   

Do let me know how this changes your performance and can further tune it as needed.

Regards to unlogged tables, if your temporary tables contain temporary data that is ephemeral and, as you mentioned, are created on session, it's better to use unlogged tables.

You can truncate your tables post session if that is acceptable.

More info here -- http://michael.otacoo.com/postgresql-2/unlogged-table-performance-in-postgresql-9-1/

I'm unsure of why you need temp tables for replication. Can't you use PostgreSQL streaming replication?

0

Using temporary tables and having long standing connections (probably connection pooling is involved) can be a burden if your server is not prepared to it. One PostgreSQL parameter you can try to play with is temp_buffers which controls the RAM allocated to temporary tables. Those temporary buffers are allocated per connection and the default value (8MB) is probably too low for your site.

Maybe you also need to change a bit of the behavior of your client application, depending on how you use your temporary tables. There is a similar question with a nice answer on Stack Overflow.

2
  • I'll have to ask my in-house expert on whether we tried adjusting the temp_buffers value or not (we tried a lot of different things). The question you point to doesn't really apply as we're not using temporary tables in that way. I've updated the question with some more details.
    – wolfcastle
    Aug 13, 2012 at 3:54
  • Thanks for the update to the question and for the postgresql.conf file, that is what we need to try to improve on this situation. I agree with @Chida answer which are inline with what I suggested wrt temp_buffers. Can you also tell us what is the size of the DB you're trying to replicate? How many tables, mean size per table and total size of the DB?
    – Lætitia
    Aug 13, 2012 at 11:49
0

Could you post your postgresql.conf file? Your postgresql seem to be significantly under optimized.

Could you also post:

  • If you are using unlogged tables for your temporary tables?

  • How many disks and in what RAID configuration?

1
  • I've put the postgresql.conf file here. I believe you cannot create a table that is both temporary AND unlogged. There are 6 1TB disks in a RAID 1+0 (3TB total storage)
    – wolfcastle
    Aug 13, 2012 at 3:38

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .