could not send data to client: Permission denied

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.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?

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

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

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

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]https://man.openbsd.org/send.2#EACCES 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