Re: BUG #3504: Some listening sessions never return from writing, problems ensue

From: "Peter Koczan" <pjkoczan(at)gmail(dot)com>
To: "Tom Lane" <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: "Heikki Linnakangas" <heikki(at)enterprisedb(dot)com>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: BUG #3504: Some listening sessions never return from writing, problems ensue
Date: 2007-08-02 19:12:45
Message-ID: 4544e0330708021212v60b863dev5b424780ecd75410@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Whoops, a couple quick changes. This:
[koczan(at)ator] koczan $ ssh newton netstat | grep vero
tcp 64260 0 newton.cs.wisc.edu:32778
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp 0 0 newton.cs.wisc.edu:32777
vero.cs.wisc.edu:postgresqlESTABLISHED

should be this:
[koczan(at)ator] koczan $ ssh newton netstat | grep vero
tcp 64530 0 newton.cs.wisc.edu:32778
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp 0 0 newton.cs.wisc.edu:32777
vero.cs.wisc.edu:postgresqlESTABLISHED

Also, the Send-Q column on the server side doesn't change, even after more
async notifies. They may not have happened at the same time, but it's a bit
perplexing that they all have the exact same amount of data in the queue.

Peter

On 8/2/07, Peter Koczan <pjkoczan(at)gmail(dot)com> wrote:
>
> I found something pretty interesting when running netstat's:
>
> Before a series of 3 async notifies (second column is Recv-Q):
>
> OK connections:
> [koczan(at)ator] koczan $ netstat | grep vero
> tcp 180 0 ator.cs.wisc.edu:32785
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 ator.cs.wisc.edu:32784
> vero.cs.wisc.edu:postgresql ESTABLISHED
> [koczan(at)ator] koczan $ ssh newton netstat | grep vero
> tcp 64260 0 newton.cs.wisc.edu:32778
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 newton.cs.wisc.edu:32777
> vero.cs.wisc.edu:postgresql ESTABLISHED
>
> "notify interrupt" connections:
> [koczan(at)ator] koczan $ ssh brian netstat | grep vero
> tcp 0 0 brian.cs.wisc.edu:40365
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 77800 0 brian.cs.wisc.edu:40366
> vero.cs.wisc.edu:postgresql ESTABLISHED
> [koczan(at)ator] koczan $ ssh zim netstat | grep vero
> tcp 73402 0 zim.cs.wisc.edu:32777
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 zim.cs.wisc.edu:32776
> vero.cs.wisc.edu:postgresql ESTABLISHED
>
> and after said notifies:
>
> OK connections:
> [koczan(at)ator] koczan $ netstat | grep vero
> tcp 450 0 ator.cs.wisc.edu:32785
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 ator.cs.wisc.edu:32784
> vero.cs.wisc.edu:postgresql ESTABLISHED
> [koczan(at)ator] koczan $ ssh newton netstat | grep vero
> tcp 64260 0 newton.cs.wisc.edu:32778
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 newton.cs.wisc.edu:32777
> vero.cs.wisc.edu:postgresql ESTABLISHED
>
> "notify interrupt" connections:
> [koczan(at)ator] koczan $ ssh brian netstat | grep vero
> tcp 0 0 brian.cs.wisc.edu:40365
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 77800 0 brian.cs.wisc.edu:40366
> vero.cs.wisc.edu:postgresql ESTABLISHED
> [koczan(at)ator] koczan $ ssh zim netstat | grep vero
> tcp 73402 0 zim.cs.wisc.edu:32777
> vero.cs.wisc.edu:postgresql ESTABLISHED
> tcp 0 0 zim.cs.wisc.edu:32776
> vero.cs.wisc.edu:postgresql ESTABLISHED
>
> And on the server side things get a little more interesting (Send-Q is the
> 3rd column)...
>
> OK:
> [koczan(at)vero] ~ $ netstat | grep ator
> tcp 0 0 vero.cs.wisc.edu:postgresql ator.cs.wisc.edu:32785
> ESTABLISHED
> tcp 0 0 vero.cs.wisc.edu:postgresql ator.cs.wisc.edu:32784
> ESTABLISHED
> [koczan(at)vero] ~ $ netstat | grep newton
> tcp 0 0 vero.cs.wisc.edu:postgresql newton.cs.wisc.edu:32778
> ESTABLISHED
> tcp 0 0 vero.cs.wisc.edu:postgresql newton.cs.wisc.edu:32777
> ESTABLISHED
>
> "notify interrupt":
> [koczan(at)vero] ~ $ netstat | grep brian
> tcp 0 0 vero.cs.wisc.edu:postgresql brian.cs.wisc.edu:40365
> ESTABLISHED
> tcp 0 13032 vero.cs.wisc.edu:postgresql brian.cs.wisc.edu:40366
> ESTABLISHED
> [koczan(at)vero] ~ $ netstat | grep zim
> tcp 0 13032 vero.cs.wisc.edu:postgresql zim.cs.wisc.edu:32777
> ESTABLISHED
> tcp 0 0 vero.cs.wisc.edu:postgresql zim.cs.wisc.edu:32776
> ESTABLISHED
>
> A quick perusal of the other "notify interrupt" connections shows 13032 in
> the Send-Q column. They all got into this state at the same time.
>
> Peter
>
> P.S. Thanks for the help, I really appreciate it.
>
> On 8/2/07, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us > wrote:
> >
> > Peter Koczan <pjkoczan(at)gmail(dot)com > writes:
> > > Heikki Linnakangas wrote:
> > >> Does the client read the async notifies? The write in the server will
> > >> block if the client doesn't keep up with reading the data.
> > >>
> > > Well, the client updates it's GUI properly no matter whether the
> > > listening session is blocked or not (it's an ongoing tail of
> > requests).
> > > Overtly from the client side, it's completely transparent. Is there
> > any
> > > way I can tell definitively from the client side whether or not it's
> > > actually reading the async notifies?
> >
> > netstat's Recv-Q column would probably reflect it if the client is
> > failing to consume messages. The send queue on the server side would be
> > worth checking too.
> >
> > regards, tom lane
> >
>
>

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Heikki Linnakangas 2007-08-02 19:36:22 Re: BUG #3504: Some listening sessions never return from writing, problems ensue
Previous Message Heikki Linnakangas 2007-08-02 19:09:11 Re: BUG #3506: to_number silently ignore characters