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(at)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(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

"notify interrupt" connections:
[koczan(at)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(at)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(at)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(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

"notify interrupt" connections:
[koczan(at)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(at)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(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
>