Thread: could not send data to client: Permission denied

could not send data to client: Permission denied

From

Daniel Jakots

Date:

27 August 2020, 18:28:46

Hi,

I run a flask rest api which use postgres to store data. I've been
using it for a few months and it worked flawlessly. I recently got an
error twice (58h10m apart). I added a lot more data a few days ago which
could be the reason I get this now, but the table is still quite small
with 69807 lines. This endpoint is called by a handful of machines
every 5 minutes and it works all the time except those two times.

The API runs in docker with gunicorn.
[2020-08-27 02:10:03,624] ERROR in app: Exception on /v1/pf [GET]
Traceback (most recent call last):
[...]
  File "/home/snek/app/api/tools.py", line 94, in ip_get
    cursor.execute("SELECT ip FROM pf_ip_ban;")
psycopg2.OperationalError: server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.

In postgresql log, it says:
Aug 27 02:10:02 db1 postgres[62464]: [7-1] 10.10.10.43(41816):[unknown]@[unknown]: LOG:  connection received:
host=10.10.10.43port=4181
 
Aug 27 02:10:02 db1 postgres[62464]: [8-1] 10.10.10.43(41816):api@api: LOG:  connection authorized: user=api
database=api
Aug 27 02:10:02 db1 postgres[62464]: [9-1] 10.10.10.43(41816):api@api: LOG:  could not send data to client: Permission
denied
Aug 27 02:10:02 db1 postgres[62464]: [9-2] 10.10.10.43(41816):api@api: STATEMENT:  SELECT ip FROM pf_ip_ban;
Aug 27 02:10:02 db1 postgres[62464]: [10-1] 10.10.10.43(41816):api@api: FATAL:  connection to client lost
Aug 27 02:10:02 db1 postgres[62464]: [10-2] 10.10.10.43(41816):api@api: STATEMENT:  SELECT ip FROM pf_ip_ban;

Postgresql and the python code runs on two different VM, but
they're both on the same hypervisor (kvm on ubuntu). Therefore I would
assume the network between them should be uneventful; but software
has bugs.

Postgresql is postgresql-server-12.3p0 running OpenBSD -current.

I searched the error on the web but I didn't find anything with this
exact error. Do you know what could cause it? Or how could I get more
information?

I tuned OpenBSD according to our README:
https://github.com/openbsd/ports/blob/master/databases/postgresql/pkg/README-server#L59-L68
could it be that the values are too low since the table growth?

Cheers,
Daniel

Re: could not send data to client: Permission denied

From

Adrian Klaver

Date:

27 August 2020, 19:04:25

On 8/27/20 8:28 AM, Daniel Jakots wrote:
> Hi,
> 
> I run a flask rest api which use postgres to store data. I've been
> using it for a few months and it worked flawlessly. I recently got an
> error twice (58h10m apart). I added a lot more data a few days ago which
> could be the reason I get this now, but the table is still quite small
> with 69807 lines. This endpoint is called by a handful of machines
> every 5 minutes and it works all the time except those two times.
> 
> The API runs in docker with gunicorn.
> [2020-08-27 02:10:03,624] ERROR in app: Exception on /v1/pf [GET]
> Traceback (most recent call last):
> [...]
>    File "/home/snek/app/api/tools.py", line 94, in ip_get
>      cursor.execute("SELECT ip FROM pf_ip_ban;")
> psycopg2.OperationalError: server closed the connection unexpectedly
>     This probably means the server terminated abnormally
>     before or while processing the request.
> 
> In postgresql log, it says:
> Aug 27 02:10:02 db1 postgres[62464]: [7-1] 10.10.10.43(41816):[unknown]@[unknown]: LOG:  connection received:
host=10.10.10.43port=4181
 
> Aug 27 02:10:02 db1 postgres[62464]: [8-1] 10.10.10.43(41816):api@api: LOG:  connection authorized: user=api
database=api
> Aug 27 02:10:02 db1 postgres[62464]: [9-1] 10.10.10.43(41816):api@api: LOG:  could not send data to client:
Permissiondenied
 

I would think it is the above.

Are you using some sort of authentication for the API?


> Aug 27 02:10:02 db1 postgres[62464]: [9-2] 10.10.10.43(41816):api@api: STATEMENT:  SELECT ip FROM pf_ip_ban;
> Aug 27 02:10:02 db1 postgres[62464]: [10-1] 10.10.10.43(41816):api@api: FATAL:  connection to client lost
> Aug 27 02:10:02 db1 postgres[62464]: [10-2] 10.10.10.43(41816):api@api: STATEMENT:  SELECT ip FROM pf_ip_ban;
> 
> Postgresql and the python code runs on two different VM, but
> they're both on the same hypervisor (kvm on ubuntu). Therefore I would
> assume the network between them should be uneventful; but software
> has bugs.
> 
> Postgresql is postgresql-server-12.3p0 running OpenBSD -current.
> 
> I searched the error on the web but I didn't find anything with this
> exact error. Do you know what could cause it? Or how could I get more
> information?
> 
> I tuned OpenBSD according to our README:
> https://github.com/openbsd/ports/blob/master/databases/postgresql/pkg/README-server#L59-L68
> could it be that the values are too low since the table growth?
> 
> Cheers,
> Daniel
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

Re: could not send data to client: Permission denied

From

Daniel Jakots

Date:

27 August 2020, 19:14:49

On Thu, 27 Aug 2020 09:04:25 -0700, Adrian Klaver
<adrian.klaver@aklaver.com> wrote:

> > In postgresql log, it says:
> > Aug 27 02:10:02 db1 postgres[62464]: [7-1]
> > 10.10.10.43(41816):[unknown]@[unknown]: LOG:  connection received:
> > host=10.10.10.43 port=4181 Aug 27 02:10:02 db1 postgres[62464]:
> > [8-1] 10.10.10.43(41816):api@api: LOG:  connection authorized:
> > user=api database=api Aug 27 02:10:02 db1 postgres[62464]: [9-1]
> > 10.10.10.43(41816):api@api: LOG:  could not send data to client:
> > Permission denied  
> 
> I would think it is the above.
> 
> Are you using some sort of authentication for the API?

Sorry I'm not sure what you mean?

Between the clients and the python code I use some "basic auth" (and IP
restrictions on the reverse proxy). But I can't see how it would cause
the problem.

Between the python code and postgresql, the relevant pg_hba.conf line
is
host    api       api    10.10.10.43/32     scram-sha-256
Since except these two times it always works, why would it fail
then?

Cheers,
Daniel

Re: could not send data to client: Permission denied

From

Tom Lane

Date:

27 August 2020, 19:44:11

Daniel Jakots <postgres@chown.me> writes:
> On Thu, 27 Aug 2020 09:04:25 -0700, Adrian Klaver
> <adrian.klaver@aklaver.com> wrote:
>> Are you using some sort of authentication for the API?

> Sorry I'm not sure what you mean?

> Between the clients and the python code I use some "basic auth" (and IP
> restrictions on the reverse proxy). But I can't see how it would cause
> the problem.

The error shows that you're already through authentication and executing a
normal query (since a query is cited in the log).  So whatever this is,
it doesn't seem like it could be an authentication issue.

It looks like send() itself is returning EACCES, which seems just
weird.  The send(2) man page does cite some possible causes of
EACCES, but none of them seem relevant here.  I think you might
need a kernel guru.

            regards, tom lane

Re: could not send data to client: Permission denied

From

Daniel Jakots

Date:

27 August 2020, 20:03:55

On Thu, 27 Aug 2020 12:44:11 -0400, Tom Lane <tgl@sss.pgh.pa.us> wrote:

> It looks like send() itself is returning EACCES, which seems just
> weird.  The send(2) man page does cite some possible causes of
> EACCES, but none of them seem relevant here. 

Oh, send(2) on OpenBSD [1] says that the firewall may cause such an
error. I guess no one ever hits* this since on Linux this is "very
unlikely" to happen.

I think the problem is my cron fiddles with the vm's firewall at the
same time. I'll look into that possibility. Thanks for the hint!

* according to my web search :p

[1]: https://man.openbsd.org/send.2#EACCES

Daniel