From: | "ldh(at)laurent-hasson(dot)com" <ldh(at)laurent-hasson(dot)com> |
---|---|
To: | "ldh(at)laurent-hasson(dot)com" <ldh(at)laurent-hasson(dot)com>, Justin Pryzby <pryzby(at)telsasoft(dot)com> |
Cc: | "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org> |
Subject: | RE: An I/O error occurred while sending to the backend (PG 13.4) |
Date: | 2022-02-24 00:47:42 |
Message-ID: | MN2PR15MB256034941F279136BA555236853D9@MN2PR15MB2560.namprd15.prod.outlook.com |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-performance |
> -----Original Message-----
> From: ldh(at)laurent-hasson(dot)com <ldh(at)laurent-hasson(dot)com>
> Sent: Saturday, December 4, 2021 14:18
> To: Justin Pryzby <pryzby(at)telsasoft(dot)com>
> Cc: pgsql-performance(at)postgresql(dot)org
> Subject: RE: An I/O error occurred while sending to the backend (PG 13.4)
>
>
> > -----Original Message-----
> > From: Justin Pryzby <pryzby(at)telsasoft(dot)com>
> > Sent: Saturday, December 4, 2021 12:59
> > To: ldh(at)laurent-hasson(dot)com
> > Cc: pgsql-performance(at)postgresql(dot)org
> > Subject: Re: An I/O error occurred while sending to the backend (PG
> > 13.4)
> >
> > On Sat, Dec 04, 2021 at 05:32:10PM +0000, ldh(at)laurent-hasson(dot)com
> > wrote:
> > > I have a data warehouse with a fairly complex ETL process that has
> > been running for years now across PG 9.6, 11.2 and now 13.4 for the
> > past couple of months. I have been getting the error "An I/O error
> > occurred while sending to the backend" quite often under load in 13.4
> > which I never used to get on 11.2. I have applied some tricks,
> particularly
> > with the socketTimeout JDBC configuration.
> > >
> > > So my first question is whether anyone has any idea why this is
> > happening? My hardware and general PG configuration have not
> > changed between 11.2 and 13.4 and I NEVER experienced this on 11.2
> in
> > about 2y of production.
> > >
> > > Second, I have one stored procedure that takes a very long time to
> run
> > (40mn more or less), so obviously, I'd need to set socketTimeout to
> > something like 1h in order to call it and not timeout. That doesn't seem
> > reasonable?
> >
> > Is the DB server local or remote (TCP/IP) to the client?
> >
> > Could you collect the corresponding postgres query logs when this
> > happens ?
> >
> > It'd be nice to see a network trace for this too. Using tcpdump or
> > wireshark.
> > Preferably from the client side.
> >
> > FWIW, I suspect the JDBC socketTimeout is a bad workaround.
> >
> > --
> > Justin
>
> It's a remote server, but all on a local network. Network performance is I
> am sure not the issue. Also, the system is on Windows Server. What are you
> expecting to see out of a tcpdump? I'll try to get PG logs on the failing query.
>
> Thank you,
> Laurent.
>
>
>
>
Hello Justin,
It has been ages! The issue has been happening a bit more often recently, as much as once every 10 days or so. As a reminder, the set up is Postgres 13.4 on Windows Server with 16cores and 64GB memory. The scenario where this occurs is an ETL tool called Pentaho Kettle (V7) connecting to the DB for DataWarehouse workloads. The tool is Java-based and connects via JDBC using postgresql-42.2.5.jar. There are no particular settings besides the socketTimeout setting mentioned above.
The workload has some steps being lots of quick transactions for dimension tables for example, but some fact table calculations, especially large pivots, can make queries run for 40mn up to over an hour (a few of those).
I caught these in the logs at the time of a failure but unsure what to make of that:
2022-02-21 02:08:16.214 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:29.347 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.371 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.463 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.596 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.687 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.786 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.873 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:30.976 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:31.050 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:31.131 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:31.240 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:31.906 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:31.988 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:33.068 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:08:34.850 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:10:43.596 EST [836] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2022-02-21 02:10:43.598 EST [8616] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2022-02-21 02:10:43.598 EST [8616] LOG: unexpected EOF on client connection with an open transaction
2022-02-21 02:10:43.605 EST [7000] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2022-02-21 02:10:43.605 EST [7000] LOG: unexpected EOF on client connection with an open transaction
2022-02-21 02:10:43.605 EST [1368] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2022-02-21 02:10:43.605 EST [1368] LOG: unexpected EOF on client connection with an open transaction
2022-02-21 02:10:43.605 EST [3304] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2022-02-21 02:10:43.605 EST [3304] LOG: unexpected EOF on client connection with an open transaction
2022-02-21 02:31:38.808 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:31:38.817 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:31:38.825 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:31:38.834 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:31:38.845 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
2022-02-21 02:34:32.112 EST [1704] LOG: setsockopt(TCP_USER_TIMEOUT) not supported
Thank you,
Laurent.
From | Date | Subject | |
---|---|---|---|
Next Message | Justin Pryzby | 2022-02-24 01:04:15 | Re: An I/O error occurred while sending to the backend (PG 13.4) |
Previous Message | Justin Pryzby | 2022-02-22 21:27:10 | Re: Slow Running Queries in Azure PostgreSQL |