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

I found something pretty interesting when running netstat's:

Before a series of 3 async notifies (second column is Recv-Q):

OK connections:
[koczan@ator] koczan $ netstat | grep vero
tcp      180      0 ator.cs.wisc.edu:32785
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp        0      0 ator.cs.wisc.edu:32784
vero.cs.wisc.edu:postgresqlESTABLISHED
[koczan@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

"notify interrupt" connections:
[koczan@ator] koczan $ ssh brian netstat | grep vero
tcp        0      0 brian.cs.wisc.edu:40365
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp    77800      0 brian.cs.wisc.edu:40366
vero.cs.wisc.edu:postgresqlESTABLISHED
[koczan@ator] koczan $ ssh zim netstat | grep vero
tcp    73402      0 zim.cs.wisc.edu:32777
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp        0      0 zim.cs.wisc.edu:32776
vero.cs.wisc.edu:postgresqlESTABLISHED

and after said notifies:

OK connections:
[koczan@ator] koczan $ netstat | grep vero
tcp      450      0 ator.cs.wisc.edu:32785
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp        0      0 ator.cs.wisc.edu:32784
vero.cs.wisc.edu:postgresqlESTABLISHED
[koczan@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

"notify interrupt" connections:
[koczan@ator] koczan $ ssh brian netstat | grep vero
tcp        0      0 brian.cs.wisc.edu:40365
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp    77800      0 brian.cs.wisc.edu:40366
vero.cs.wisc.edu:postgresqlESTABLISHED
[koczan@ator] koczan $ ssh zim netstat | grep vero
tcp    73402      0 zim.cs.wisc.edu:32777
vero.cs.wisc.edu:postgresqlESTABLISHED
tcp        0      0 zim.cs.wisc.edu:32776
vero.cs.wisc.edu:postgresqlESTABLISHED

And on the server side things get a little more interesting (Send-Q is the
3rd column)...

OK:
[koczan@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@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@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@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@sss.pgh.pa.us> wrote:
>
> Peter Koczan <pjkoczan@gmail.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
>