> Kari Lavikka <tuner@bdb.fi> writes:
> > samples % symbol name
> > 13513390 16.0074 AtEOXact_CatCache
>
> That seems quite odd --- I'm not used to seeing that function at the
top
> of a profile. What is the workload being profiled, exactly?

He is running a commit_delay of 80000. Could that be playing a role?

Merlin

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql.org so that your
message can get through to the mailing list cleanly

"Merlin Moncure" <merlin.moncure@rcsonline.com> writes:
>> Kari Lavikka <tuner@bdb.fi> writes:
>>> samples % symbol name
>>> 13513390 16.0074 AtEOXact_CatCache
>>
>> That seems quite odd --- I'm not used to seeing that function at the top
>> of a profile. What is the workload being profiled, exactly?

> He is running a commit_delay of 80000. Could that be playing a role?

It wouldn't cause AtEOXact_CatCache to suddenly get expensive. (I have
little or no faith in the value of nonzero commit_delay, though.)

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

Actually I modified postgresql.conf a bit and there isn't commit delay any
more. That didn't make noticeable difference though..

Workload is generated by a website with about 1000 dynamic page views a
second. Finland's biggest site among youths btw.

Anyway, there are about 70 tables and here's some of the most important:
relname | reltuples
----------------------------------+-------------
comment | 1.00723e+08
comment_archive | 9.12764e+07
channel_comment | 6.93912e+06
image | 5.80314e+06
admin_event | 5.1936e+06
user_channel | 3.36877e+06
users | 325929
channel | 252267

Queries to "comment" table are mostly IO-bound but are performing quite
well. Here's an example:

(SELECT u.nick, c.comment, c.private, c.admin, c.visible, c.parsable,
c.uid_sender, to_char(c.stamp, 'DD.MM.YY HH24:MI') AS stamp, c.comment_id
FROM comment c INNER JOIN users u ON u.uid = c.uid_sender WHERE u.status =
'a' AND c.image_id = 15500900 AND c.uid_target = 780345 ORDER BY
uid_target DESC, image_id DESC, c.comment_id DESC) LIMIT 36

And explain analyze:
Limit (cost=0.00..6.81 rows=1 width=103) (actual time=0.263..17.522 rows=12 loops=1)
-> Nested Loop (cost=0.00..6.81 rows=1 width=103) (actual time=0.261..17.509 rows=12 loops=1)
-> Index Scan Backward using comment_uid_target_image_id_comment_id_20050527 on "comment" c (cost=0.00..3.39 rows=1 width=92) (actual time=0.129..16.213 rows=12 loops=1)
Index Cond: ((uid_target = 780345) AND (image_id = 15500900))
-> Index Scan using users_pkey on users u (cost=0.00..3.40 rows=1 width=15) (actual time=0.084..0.085 rows=1 loops=12)
Index Cond: (u.uid = "outer".uid_sender)
Filter: (status = 'a'::bpchar)
Total runtime: 17.653 ms


We are having performance problems with some smaller tables and very
simple queries. For example:

SELECT u.uid, u.nick, extract(epoch from uc.stamp) AS stamp FROM
user_channel uc INNER JOIN users u USING (uid) WHERE channel_id = 281321
AND u.status = 'a' ORDER BY uc.channel_id, upper(uc.nick)

And explain analyze:
Nested Loop (cost=0.00..200.85 rows=35 width=48) (actual time=0.414..38.128 rows=656 loops=1)
-> Index Scan using user_channel_channel_id_nick on user_channel uc (cost=0.00..40.18 rows=47 width=27) (actual time=0.090..0.866 rows=667 loops=1)
Index Cond: (channel_id = 281321)
-> Index Scan using users_pkey on users u (cost=0.00..3.40 rows=1 width=25) (actual time=0.048..0.051 rows=1 loops=667)
Index Cond: ("outer".uid = u.uid)
Filter: (status = 'a'::bpchar)
Total runtime: 38.753 ms

Under heavy load these queries tend to take several minutes to execute
although there's plenty of free cpu available. There aren't any blocking
locks in pg_locks.

|\__/|
( oo ) Kari Lavikka - tuner@bdb.fi - (050) 380 3808
__ooO( )Ooo_______ _____ ___ _ _ _ _ _ _ _
""

On Mon, 8 Aug 2005, Merlin Moncure wrote:

>> Kari Lavikka <tuner@bdb.fi> writes:
>>> samples % symbol name
>>> 13513390 16.0074 AtEOXact_CatCache
>>
>> That seems quite odd --- I'm not used to seeing that function at the
> top
>> of a profile. What is the workload being profiled, exactly?
>
> He is running a commit_delay of 80000. Could that be playing a role?
>
> Merlin
>
> ---------------------------(end of broadcast)---------------------------
> TIP 1: if posting/reading through Usenet, please send an appropriate
> subscribe-nomail command to majordomo@postgresql.org so that your
> message can get through to the mailing list cleanly
>

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Kari Lavikka <tuner@bdb.fi> writes:
> We are having performance problems with some smaller tables and very
> simple queries. For example:

> SELECT u.uid, u.nick, extract(epoch from uc.stamp) AS stamp FROM
> user_channel uc INNER JOIN users u USING (uid) WHERE channel_id = 281321
> AND u.status = 'a' ORDER BY uc.channel_id, upper(uc.nick)

> And explain analyze:
> Nested Loop (cost=0.00..200.85 rows=35 width=48) (actual time=0.414..38.128 rows=656 loops=1)
> -> Index Scan using user_channel_channel_id_nick on user_channel uc (cost=0.00..40.18 rows=47 width=27) (actual time=0.090..0.866 rows=667 loops=1)
> Index Cond: (channel_id = 281321)
> -> Index Scan using users_pkey on users u (cost=0.00..3.40 rows=1 width=25) (actual time=0.048..0.051 rows=1 loops=667)
> Index Cond: ("outer".uid = u.uid)
> Filter: (status = 'a'::bpchar)
> Total runtime: 38.753 ms

> Under heavy load these queries tend to take several minutes to execute
> although there's plenty of free cpu available.

What that sounds like to me is a machine with inadequate disk I/O bandwidth.
Your earlier comment that checkpoint drives the machine into the ground
fits right into that theory, too. You said there is "almost no IO-wait"
but are you sure you are measuring that correctly?

Something else just struck me from your first post:

> Queries accumulate and when checkpointing is over, there can be
> something like 400 queries running but over 50% of cpu is just idling.

400 queries? Are you launching 400 separate backends to do that?
Some sort of connection pooling seems like a good idea, if you don't
have it in place already. If the system's effective behavior in the
face of heavy load is to start even more concurrent backends, that
could easily drive things into the ground.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql.org so that your
message can get through to the mailing list cleanly

On Mon, 8 Aug 2005, Tom Lane wrote:
> What that sounds like to me is a machine with inadequate disk I/O bandwidth.
> Your earlier comment that checkpoint drives the machine into the ground
> fits right into that theory, too. You said there is "almost no IO-wait"
> but are you sure you are measuring that correctly?

Currently there's some iowait caused by "fragmentation" of the comment
table. Periodic clustering helps a lot.

Disk configurations looks something like this:
sda: data (10 spindles, raid10)
sdb: xlog & clog (2 spindles, raid1)
sdc: os and other stuff

Usually iostat (2 second interval) says:
avg-cpu: %user %nice %sys %iowait %idle
32.38 0.00 12.88 11.62 43.12

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 202.00 1720.00 0.00 3440 0
sdb 152.50 4.00 2724.00 8 5448
sdc 0.00 0.00 0.00 0 0

And during checkpoint:
avg-cpu: %user %nice %sys %iowait %idle
31.25 0.00 14.75 54.00 0.00

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 3225.50 1562.00 35144.00 3124 70288
sdb 104.50 10.00 2348.00 20 4696
sdc 0.00 0.00 0.00 0 0

I think (insufficiency of) disk IO shouldn't cause those lingering queries
because dataset is rather small and it's continuously accessed. It should
fit into cache and stay there(?)

> 400 queries? Are you launching 400 separate backends to do that?

Well yes. That's the common problem with php and persistent connections.

> Some sort of connection pooling seems like a good idea, if you don't
> have it in place already.

pg_pool for example? I'm planning to give it a try.

> regards, tom lane


|\__/|
( oo ) Kari Lavikka - tuner@bdb.fi - (050) 380 3808
__ooO( )Ooo_______ _____ ___ _ _ _ _ _ _ _
""


---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Kari Lavikka <tuner@bdb.fi> writes:
> Disk configurations looks something like this:
> sda: data (10 spindles, raid10)
> sdb: xlog & clog (2 spindles, raid1)
> sdc: os and other stuff

That's definitely wrong. Put clog on the data disk. The entire point
of giving xlog its own spindle is that you don't ever want the disk
heads moving off the current xlog file. I'm not sure how much this is
hurting you, given that clog is relatively low volume, but if you're
going to go to the trouble of putting xlog on a separate spindle then
it should be a completely dedicated spindle.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

On Mon, 8 Aug 2005, Tom Lane wrote:
> What that sounds like to me is a machine with inadequate disk I/O bandwidth.
> Your earlier comment that checkpoint drives the machine into the ground
> fits right into that theory, too. You said there is "almost no IO-wait"
> but are you sure you are measuring that correctly?

Reducing checkpoint_timeout to 600 seconds had a positive effect. Previous
value was 1800 seconds.

We have a spare disk array from the old server and I'm planning to use it
as a tablespace for the comment table (the 100M+ rows one) as Ron
suggested.

>> Queries accumulate and when checkpointing is over, there can be
>> something like 400 queries running but over 50% of cpu is just idling.
>
> 400 queries? Are you launching 400 separate backends to do that?
> Some sort of connection pooling seems like a good idea, if you don't
> have it in place already. If the system's effective behavior in the
> face of heavy load is to start even more concurrent backends, that
> could easily drive things into the ground.

Ok, I implemented connection pooling using pgpool and it increased
performance a lot! We are now delivering about 1500 dynamic pages a second
without problems. Each of the eight single-cpu webservers are running a
pgpool instance with 20 connections.

However, those configuration changes didn't have significant effect to
oprofile results. AtEOXact_CatCache consumes even more cycles. This isn't
a problem right now but it may be in the future...

CPU: AMD64 processors, speed 2190.23 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Cycles outside of halt state) with a unit mask of 0x00 (No unit mask) count 100000
samples % symbol name
1147870 21.1602 AtEOXact_CatCache
187466 3.4558 hash_seq_search
174357 3.2142 AllocSetAlloc
170896 3.1504 nocachegetattr
131724 2.4282 ExecMakeFunctionResultNoSets
125292 2.3097 SearchCatCache
117264 2.1617 StrategyDirtyBufferList
105741 1.9493 hash_search
98245 1.8111 FunctionCall2
97878 1.8043 yyparse
90932 1.6763 LWLockAcquire
83555 1.5403 LWLockRelease
81045 1.4940 _bt_compare
.... and so on ...

----->8 Signigicant rows from current postgresql.conf 8<-----

max_connections = 768 # unnecessarily large with connection
pooling
shared_buffers = 15000
work_mem = 2048
maintenance_work_mem = 32768
max_fsm_pages = 1000000
max_fsm_relations = 5000
bgwriter_percent = 2
fsync = true
wal_buffers = 512
checkpoint_segments = 200 # less would probably be enuff with 600sec
timeout
checkpoint_timeout = 600
effective_cache_size = 500000
random_page_cost = 1.5
default_statistics_target = 150
stats_start_collector = true
stats_command_string = true


|\__/|
( oo ) Kari Lavikka - tuner@bdb.fi - (050) 380 3808
__ooO( )Ooo_______ _____ ___ _ _ _ _ _ _ _
""


---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Kari Lavikka <tuner@bdb.fi> writes:
> However, those configuration changes didn't have significant effect to
> oprofile results. AtEOXact_CatCache consumes even more cycles.

I believe I've fixed that for 8.1.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend