query slow; strace output worrisome

From: Brian Cox <brian(dot)cox(at)ca(dot)com>
To: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: query slow; strace output worrisome
Date: 2010-04-06 01:01:16
Message-ID: 4BBA87DC.1030205@ca.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

The SELECT show below has been running for 30+mins and the strace output
is alarming:

[root(at)dione ~]# strace -p 10083
Process 10083 attached - interrupt to quit
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(NULL, 037777777777) = 216203264
restart_syscall(<... resuming interrupted call ...>) = 8192
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608
creat(umovestr: Input/output error
0x2, 037777777777) = 1025220608

however, I can find no indication of I/O errors in the postgres log.
Anyone have any idea what's going on here?

postgres 8.3.7

[root(at)dione ~]# uname -a
Linux dione.ca.com 2.6.18-164.el5 #1 SMP Tue Aug 18 15:51:48 EDT 2009
x86_64 x86_64 x86_64 GNU/Linux

Thanks,
Brian

top:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
10083 postgres 25 0 2288m 822m 817m R 100.0 1.7 28:08.79 postgres

cemdb=# select procpid,query_start,current_query from pg_stat_activity;
10083 | 2010-04-05 17:18:34.989022-07 | select b.ts_id from
ts_stats_transetgroup_usergroup_daily b , ts_stats_transet_user_interval
c, ts_transetgroup_transets_map tm, ts_usergroup_users_map um where
b.ts_transet_group_id =
tm.ts_transet_group_id and tm.ts_transet_incarnation_id =
c.ts_transet_incarnation_id and b.ts_usergroup_id = um.ts_usergroup_id
and um.ts_user_incarnation_id = c.ts_user_incarnation_id and
c.ts_interval_start_time >= '2010-03-29 21:00' and
c.ts_interval_start_time < '2010-03-29 22:00' and
b.ts_interval_start_time >= '2010-03-29 00:00' and
b.ts_interval_start_time < '2010-03-30 00:00'

cemdb=# explain select b.ts_id from
ts_stats_transetgroup_usergroup_daily b , ts_stats_transet_user_interval
c, ts_transetgroup_transets_map tm, ts_usergroup_users_map um where
b.ts_transet_group_id =
tm.ts_transet_group_id and tm.ts_transet_incarnation_id =
c.ts_transet_incarnation_id and b.ts_usergroup_id = um.ts_usergroup_id
and um.ts_user_incarnation_id = c.ts_user_incarnation_id and
c.ts_interval_start_time >= '2010-03-29 21:00' and
c.ts_interval_start_time < '2010-03-29 22:00' and
b.ts_interval_start_time >= '2010-03-29 00:00' and
b.ts_interval_start_time < '2010-03-30 00:00';
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hash Join (cost=1169.95..7046.23 rows=1 width=8)
Hash Cond: ((b.ts_transet_group_id = tm.ts_transet_group_id) AND
(c.ts_transet_incarnation_id = tm.ts_transet_incarnation_id))
-> Nested Loop (cost=1159.95..7036.15 rows=10 width=24)
-> Nested Loop (cost=0.00..28.16 rows=6 width=24)
-> Index Scan using
ts_stats_transetgroup_usergroup_daily_starttimeindex on
ts_stats_transetgroup_usergroup_daily b (cost=0.00..8.86 rows=1 width=24)
Index Cond: ((ts_interval_start_time >=
'2010-03-29 00:00:00-07'::timestamp with time zone) AND
(ts_interval_start_time < '2010-03-30 00:00:00-07'::timestamp with time
zone))
-> Index Scan using
ts_usergroup_users_map_usergroupindex on ts_usergroup_users_map um
(cost=0.00..19.23 rows=6 width=16)
Index Cond: (um.ts_usergroup_id = b.ts_usergroup_id)
-> Bitmap Heap Scan on ts_stats_transet_user_interval c
(cost=1159.95..1167.97 rows=2 width=16)
Recheck Cond: ((c.ts_user_incarnation_id =
um.ts_user_incarnation_id) AND (c.ts_interval_start_time >= '2010-03-29
21:00:00-07'::timestamp with time zone) AND (c.ts_interval_start_time <
'2010-03-29 22:00:00-07'::timestamp with time zone))
-> BitmapAnd (cost=1159.95..1159.95 rows=2 width=0)
-> Bitmap Index Scan on
ts_stats_transet_user_interval_userincarnationidindex (cost=0.00..14.40
rows=438 width=0)
Index Cond: (c.ts_user_incarnation_id =
um.ts_user_incarnation_id)
-> Bitmap Index Scan on
ts_stats_transet_user_interval_starttime (cost=0.00..1134.09 rows=44856
width=0)
Index Cond: ((c.ts_interval_start_time >=
'2010-03-29 21:00:00-07'::timestamp with time zone) AND
(c.ts_interval_start_time < '2010-03-29 22:00:00-07'::timestamp with
time zone))
-> Hash (cost=7.00..7.00 rows=200 width=16)
-> Seq Scan on ts_transetgroup_transets_map tm
(cost=0.00..7.00 rows=200 width=16)
(17 rows)

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Craig Ringer 2010-04-06 01:53:51 Re: query slow; strace output worrisome
Previous Message Oliver Kindernay 2010-04-05 17:11:52 Re: Huge table searching optimization