Re: PostgreSQL 8.4.8 bringing my website down every evening

From: Alexander Farber <alexander(dot)farber(at)gmail(dot)com>
To: pgsql-general(at)postgresql(dot)org
Subject: Re: PostgreSQL 8.4.8 bringing my website down every evening
Date: 2011-05-26 16:02:01
Message-ID: BANLkTimhFYr0hNhLR17izdz6f42fMnaKpw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

I've switched duration and SQL 'all' logging on,
but I have hard time to identify which SQL statement
has had which duration.

For example which SQL statement please has
the duration of 13 seconds (13025.016 ms) below?

LOG: statement: SELECT 1 AS expression
FROM
drupal_sessions sessions
WHERE ( (sid = 'uM2YMQ9c5Z6y93Zaots9jMzF7wS_rjlbDPjSxKffr1I')
AND (ssid = '') ) FOR UPDATE
LOG: statement: SELECT column_name, data_type, column_default FROM
information_schema.columns WHERE table_schema = 'public' AND
table_name = 'drupal_sessions' AND (data_type = 'bytea' OR
(numeric_precision IS NOT NULL AND column_default LIKE '%nextval%'))
LOG: statement: UPDATE drupal_sessions SET uid='8467', cache='0',
hostname='13.106.153.82', session='', timestamp='1306423187'
WHERE ( (sid = 'uM2YMQ9c5Z6y93Zaots9jMzF7wS_rjlbDPjS7Kffr1I')
AND (ssid = '') )
LOG: statement: COMMIT
LOG: statement: SELECT column_name, data_type, column_default FROM
information_schema.columns WHERE table_schema = 'public' AND
table_name = 'drupal_users' AND (data_type = 'bytea' OR
(numeric_precision IS NOT NULL AND column_default LIKE '%nextval%'))
LOG: statement: UPDATE drupal_users SET access='1306423187'
WHERE (uid = '8467')
LOG: duration: 57.913 ms
LOG: statement: SELECT 'DBD::Pg ping test'
LOG: execute dbdpg_1: select pref_update_money($1, $2)
DETAIL: parameters: $1 = 'DE9107', $2 = '13'
LOG: execute dbdpg_2: select pref_update_hand($1, $2, $3)
DETAIL: parameters: $1 = 'DE9107', $2 = '159556649', $3 = '13'
LOG: duration: 54.081 ms
LOG: statement: SELECT 'DBD::Pg ping test'
LOG: execute dbdpg_1: select pref_update_money($1, $2)
DETAIL: parameters: $1 = 'OK397412944345', $2 = '9'
LOG: execute dbdpg_2: select pref_update_hand($1, $2, $3)
DETAIL: parameters: $1 = 'OK397412944345', $2 = '270751304', $3 = '9'
LOG: duration: 56.573 ms
LOG: statement: SELECT 'DBD::Pg ping test'
LOG: execute dbdpg_1: select pref_update_money($1, $2)
DETAIL: parameters: $1 = 'OK368420510411', $2 = '19'
LOG: execute pdo_stmt_0000006b: SELECT u.id, u.first_name, u.avatar,
u.female, r.nice
FROM pref_users u LEFT OUTER JOIN pref_rep r
ON u.id = r.id AND r.author = $1 WHERE u.id in
( $2, $3 )
DETAIL: parameters: $1 = 'OK524015351816', $2 = 'OK491946648759', $3
= 'OK135178454570'
LOG: execute dbdpg_2: select pref_update_hand($1, $2, $3)
DETAIL: parameters: $1 = 'OK368420510411', $2 = '244318614', $3 = '19'
LOG: statement: DEALLOCATE pdo_stmt_0000006b
LOG: execute pdo_stmt_000000aa: SELECT u.id, u.first_name, u.avatar,
u.female, r.nice
FROM pref_users u LEFT OUTER JOIN pref_rep r
ON u.id = r.id AND r.author = $1 WHERE u.id in
( $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14 )
DETAIL: parameters: $1 = 'OK250619934309', $2 = 'OK301001052424', $3
= 'OK353189811941', $4 = 'OK358143063475', $5 = 'DE8890', $6 =
'OK343020320504', $7 = 'MR11145992487713570697', $8 =
'OK488913512462', $9 = 'MR18364595699142101947', $10 =
'OK508907787570', $11 = 'OK345960562675', $12 = 'OK341680565482', $13
= 'OK266334509747', $14 = 'DE10140'
LOG: statement: DEALLOCATE pdo_stmt_000000aa
LOG: duration: 57.492 ms
LOG: statement: SELECT 'DBD::Pg ping test'
LOG: execute dbdpg_1: select pref_update_money($1, $2)
DETAIL: parameters: $1 = 'MR8956887007365082416', $2 = '-27'
LOG: duration: 13025.016 ms
LOG: execute pdo_stmt_00000002: SELECT u.id, u.first_name, u.avatar,
u.female, r.nice
FROM pref_users u LEFT OUTER JOIN pref_rep r
ON u.id = r.id AND r.author = $1 WHERE u.id in
( $2, $3, $4 )
DETAIL: parameters: $1 = 'OK491817224261', $2 = 'OK496106546037', $3
= 'OK491946648759', $4 = 'OK332008971867'
LOG: statement: DEALLOCATE pdo_stmt_00000002
LOG: duration: 7681.654 ms

And below are my stored routnies and few tables just in case:

create or replace function pref_update_hand(_id varchar,
_hand bigint, _money int) returns void as $BODY$
begin

delete from pref_hand where id=_id and stamp in
(select stamp from pref_hand where id=_id order by
stamp desc offset 9);

insert into pref_hand (id, hand, money) values (_id,
_hand, _money);

end;
$BODY$ language plpgsql;

create or replace function pref_update_money(_id varchar,
_money integer) returns void as $BODY$
begin

update pref_money set
money = money + _money
where id = _id and yw = to_char(current_timestamp, 'IYYY-IW');

if not found then
insert into pref_money(id, money)
values (_id, _money);
end if;
end;
$BODY$ language plpgsql;

create table pref_money (
id varchar(32) references pref_users,
money integer not null,
yw char(7) default to_char(current_timestamp, 'IYYY-IW')
);
create index pref_money_yw_index on pref_money(yw);

create table pref_hand (
id varchar(32) references pref_users,
hand bigint not NULL check (hand > 0),
money integer not null,
stamp timestamp default current_timestamp
);

Also I've noticed I had a wrong index:

create table pref_match (
id varchar(32) references pref_users,
started integer default 0 check (started >= 0),
completed integer default 0 check (completed >= 0),
win integer default 0 check (completed >= win and win >= 0),
quit integer default 0 check (quit >= 0),
yw char(7) default to_char(current_timestamp, 'IYYY-IW')
);
create index pref_match_yw_index on pref_money(yw);

Regards
Alex

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Alexander Farber 2011-05-26 16:11:31 Re: PostgreSQL 8.4.8 bringing my website down every evening
Previous Message Merlin Moncure 2011-05-26 15:47:56 Re: When is commited data available