Received: from localhost (maia-1.hub.org [200.46.204.191]) by postgresql.org (Postfix) with ESMTP id 63F1E9FA473 for ; Wed, 3 Jan 2007 12:13:48 -0400 (AST) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.204.191]) (amavisd-new, port 10024) with ESMTP id 39477-07 for ; Wed, 3 Jan 2007 12:13:35 -0400 (AST) X-Greylist: from auto-whitelisted by SQLgrey-1.7.4 Received: from myemma.com (db1.e2ma.net [66.179.147.163]) by postgresql.org (Postfix) with ESMTP id 728AD9FA238 for ; Wed, 3 Jan 2007 12:13:35 -0400 (AST) Received: from localhost (localhost.localdomain [127.0.0.1]) by myemma.com (Postfix) with ESMTP id AA60923D1C; Wed, 3 Jan 2007 10:13:34 -0600 (CST) Received: from myemma.com ([127.0.0.1]) by localhost (velma [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 05602-08; Wed, 3 Jan 2007 10:13:32 -0600 (CST) Received: from [10.0.23.39] (unknown [209.149.59.218]) by myemma.com (Postfix) with ESMTP id CB05523D33; Wed, 3 Jan 2007 10:13:19 -0600 (CST) Message-ID: <459BD61C.3030202@myemma.com> Date: Wed, 03 Jan 2007 10:13:16 -0600 From: Erik Jones User-Agent: Thunderbird 1.5.0.7 (Windows/20060909) MIME-Version: 1.0 To: Tom Lane Cc: pgsql-performance@postgresql.org Subject: Re: More 8.2 client issues (Was: [Slow dump?) References: <459AD5A8.7030102@myemma.com> <22512.1167779361@sss.pgh.pa.us> In-Reply-To: <22512.1167779361@sss.pgh.pa.us> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: by amavisd-new-20030616-p10 (Debian) at myemma.com X-Virus-Scanned: Maia Mailguard 1.0.1 X-Archive-Number: 200701/33 X-Sequence-Number: 22634 Tom Lane wrote: > Erik Jones writes: > >> Hmm... This gets stranger and stranger. When connecting to the >> database with the psql client in 8.2's bin directory and using commands >> such as \d the client hangs, or takes an extremely long time. >> > > Hangs at what point? During connection? Try strace'ing psql (or > whatever the Solaris equivalent is) to see what it's doing. > Ok, here's the truss output when attached to psql with "\d pg_class", I put a marker where the pause is. Note that today the pause is only (sic) about 3-4 seconds long before the command completes and the output is displayed and that the only difference in the system between yesterday and today is that today we don't have a dump running. I realize that most of this output below is unnecessary, but while I know what most of this is doing individually, I wouldn't know what to cut out for brevity's sake without accidentally also clipping something that is needed. read(0, 0x08047B7B, 1) (sleeping...) read(0, " \", 1) = 1 write(1, " \", 1) = 1 read(0, " d", 1) = 1 write(1, " d", 1) = 1 read(0, " ", 1) = 1 write(1, " ", 1) = 1 read(0, " ", 1) = 1 write(1, " ", 1) = 1 read(0, " p", 1) = 1 write(1, " p", 1) = 1 read(0, "7F", 1) = 1 write(1, "\b \b", 3) = 3 read(0, "7F", 1) = 1 write(1, "\b \b", 3) = 3 read(0, " p", 1) = 1 write(1, " p", 1) = 1 read(0, " g", 1) = 1 write(1, " g", 1) = 1 read(0, " _", 1) = 1 write(1, " _", 1) = 1 read(0, " c", 1) = 1 write(1, " c", 1) = 1 read(0, " l", 1) = 1 write(1, " l", 1) = 1 read(0, " a", 1) = 1 write(1, " a", 1) = 1 read(0, " s", 1) = 1 write(1, " s", 1) = 1 read(0, " s", 1) = 1 write(1, " s", 1) = 1 read(0, "\r", 1) = 1 write(1, "\n", 1) = 1 lwp_sigmask(SIG_SETMASK, 0x00000002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF] ioctl(0, TCSETSW, 0xFEF431E0) = 0 lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF] sigaction(SIGINT, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGTERM, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGQUIT, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGALRM, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGTSTP, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGTTOU, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGTTIN, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGWINCH, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGWINCH, 0x08047B80, 0x08047BD0) = 0 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 send(4, " Q\0\0\0E5 S E L E C T ".., 230, 0) = 230 <----------------------------------------------------------- Hang is right here! sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) (sleeping...) pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) = 1 recv(4, " T\0\0\0 P\003 o i d\0\0".., 16384, 0) = 140 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 send(4, " Q\0\0\08F S E L E C T ".., 144, 0) = 144 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) = 1 recv(4, " T\0\0\0D3\007 r e l h a".., 16384, 0) = 272 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 send(4, " Q\0\00186 S E L E C T ".., 391, 0) = 391 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) = 1 recv(4, " T\0\0\08F\005 a t t n a".., 16384, 0) = 1375 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 send(4, " Q\0\001 g S E L E C T ".., 360, 0) = 360 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) = 1 recv(4, " T\0\0\0DD\007 r e l n a".., 16384, 0) = 526 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 send(4, " Q\0\0\090 S E L E C T ".., 145, 0) = 145 sigaction(SIGPIPE, 0x08046E20, 0x08046E70) = 0 pollsys(0x08046EE8, 1, 0x00000000, 0x00000000) = 1 recv(4, " T\0\0\0 \001 r e l n a".., 16384, 0) = 51 ioctl(0, TCGETA, 0x08046F24) = 0 ioctl(1, TCGETA, 0x08046F24) = 0 ioctl(1, TIOCGWINSZ, 0x08046F58) = 0 write(1, " T a b l e ".., 34) = 34 write(1, " C o l u m n ".., 41) = 41 write(1, " - - - - - - - - - - - -".., 41) = 41 write(1, " r e l n a m e ".., 39) = 39 write(1, " r e l n a m e s p a c".., 39) = 39 write(1, " r e l t y p e ".., 39) = 39 write(1, " r e l o w n e r ".., 39) = 39 write(1, " r e l a m ".., 39) = 39 write(1, " r e l f i l e n o d e".., 39) = 39 write(1, " r e l t a b l e s p a".., 39) = 39 write(1, " r e l p a g e s ".., 39) = 39 write(1, " r e l t u p l e s ".., 39) = 39 write(1, " r e l t o a s t r e l".., 39) = 39 write(1, " r e l t o a s t i d x".., 39) = 39 write(1, " r e l h a s i n d e x".., 39) = 39 write(1, " r e l i s s h a r e d".., 39) = 39 write(1, " r e l k i n d ".., 39) = 39 write(1, " r e l n a t t s ".., 39) = 39 write(1, " r e l c h e c k s ".., 39) = 39 write(1, " r e l t r i g g e r s".., 39) = 39 write(1, " r e l u k e y s ".., 39) = 39 write(1, " r e l f k e y s ".., 39) = 39 write(1, " r e l r e f s ".., 39) = 39 write(1, " r e l h a s o i d s ".., 39) = 39 write(1, " r e l h a s p k e y ".., 39) = 39 write(1, " r e l h a s r u l e s".., 39) = 39 write(1, " r e l h a s s u b c l".., 39) = 39 write(1, " r e l f r o z e n x i".., 39) = 39 write(1, " r e l a c l ".., 31) = 31 write(1, " r e l o p t i o n s ".., 31) = 31 write(1, " I n d e x e s :\n", 9) = 9 write(1, " " p g _ c l a s".., 45) = 45 write(1, " " p g _ c l a s".., 71) = 71 write(1, "\n", 1) = 1 lwp_sigmask(SIG_SETMASK, 0x00000002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF] ioctl(0, TIOCGWINSZ, 0x08047B58) = 0 ioctl(0, TIOCSWINSZ, 0x08047B58) = 0 ioctl(0, TCGETS, 0x08047BB0) = 0 ioctl(0, TCSETSW, 0x08047BB0) = 0 lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF] sigaction(SIGINT, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGTERM, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGQUIT, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGALRM, 0x08047B00, 0x08047B70) = 0 sigaction(SIGTSTP, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGTTOU, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGTTIN, 0x08047AA0, 0x08047B10) = 0 sigaction(SIGWINCH, 0x08047AA0, 0x08047B10) = 0 write(1, " e m m a 2 = # ", 8) = 8 read(0, 0x08047B7B, 1) (sleeping...) -- erik jones software development emma(r)