Thread: What to look for when excessively long commits
Hi all,
If I'm seeing instances like this in our logs, what should I look for:
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8124,"10.122.45.33:46386",60e4d5e6.1fbc,222,"COMMIT",2021-07-06 22:15:02 UTC,37/0,0,LOG,00000,"duration: 7128.250 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8483,"10.122.45.33:47274",60e4d5fc.2123,58,"COMMIT",2021-07-06 22:15:24 UTC,3/0,0,LOG,00000,"duration: 8419.856 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",7665,"10.122.37.247:37530",60e4d5ca.1df1,286,"COMMIT",2021-07-06 22:14:34 UTC,26/0,0,LOG,00000,"duration: 8114.358 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",6431,"10.122.45.33:42568",60e4d57f.191f,1828,"COMMIT",2021-07-06 22:13:19 UTC,40/0,0,LOG,00000,"duration: 8839.643 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8484,"10.122.45.33:47276",60e4d5fc.2124,126,"COMMIT",2021-07-06 22:15:24 UTC,7/0,0,LOG,00000,"duration: 8606.898 ms",,,,,,,,,""
2021-07-06 22:15:34.703 UTC,"bcaas_api","bcaas",8516,"10.122.37.247:41372",60e4d5fe.2144,94,"COMMIT",2021-07-06 22:15:26 UTC,16/0,0,LOG,00000,"duration: 7877.650 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8483,"10.122.45.33:47274",60e4d5fc.2123,58,"COMMIT",2021-07-06 22:15:24 UTC,3/0,0,LOG,00000,"duration: 8419.856 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",7665,"10.122.37.247:37530",60e4d5ca.1df1,286,"COMMIT",2021-07-06 22:14:34 UTC,26/0,0,LOG,00000,"duration: 8114.358 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",6431,"10.122.45.33:42568",60e4d57f.191f,1828,"COMMIT",2021-07-06 22:13:19 UTC,40/0,0,LOG,00000,"duration: 8839.643 ms",,,,,,,,,""
2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8484,"10.122.45.33:47276",60e4d5fc.2124,126,"COMMIT",2021-07-06 22:15:24 UTC,7/0,0,LOG,00000,"duration: 8606.898 ms",,,,,,,,,""
2021-07-06 22:15:34.703 UTC,"bcaas_api","bcaas",8516,"10.122.37.247:41372",60e4d5fe.2144,94,"COMMIT",2021-07-06 22:15:26 UTC,16/0,0,LOG,00000,"duration: 7877.650 ms",,,,,,,,,""
The instance is in AWS RDS. It is a multi-az db.t3.xlarge machine class running 10.6. It also has a read replica if that could be relevant.
Thanks for any suggestions.
Steve
On Fri, 2021-07-09 at 06:35 +1000, Steve Baldwin wrote: > Hi all, > > If I'm seeing instances like this in our logs, what should I look for: > > 2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8124,"10.122.45.33:46386",60e4d5e6.1fbc,222,"COMMIT",2021-07-06 22:15:02UTC,37/0,0,LOG,00000,"duration: 7128.250 ms",,,,,,,,,"" > 2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8483,"10.122.45.33:47274",60e4d5fc.2123,58,"COMMIT",2021-07-06 22:15:24UTC,3/0,0,LOG,00000,"duration: 8419.856 ms",,,,,,,,,"" > 2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",7665,"10.122.37.247:37530",60e4d5ca.1df1,286,"COMMIT",2021-07-06 22:14:34UTC,26/0,0,LOG,00000,"duration: 8114.358 ms",,,,,,,,,"" > 2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",6431,"10.122.45.33:42568",60e4d57f.191f,1828,"COMMIT",2021-07-06 22:13:19UTC,40/0,0,LOG,00000,"duration: 8839.643 ms",,,,,,,,,"" > 2021-07-06 22:15:34.702 UTC,"bcaas_api","bcaas",8484,"10.122.45.33:47276",60e4d5fc.2124,126,"COMMIT",2021-07-06 22:15:24UTC,7/0,0,LOG,00000,"duration: 8606.898 ms",,,,,,,,,"" > 2021-07-06 22:15:34.703 UTC,"bcaas_api","bcaas",8516,"10.122.37.247:41372",60e4d5fe.2144,94,"COMMIT",2021-07-06 22:15:26UTC,16/0,0,LOG,00000,"duration: 7877.650 ms",,,,,,,,,"" > > The instance is in AWS RDS. It is a multi-az db.t3.xlarge machine class running 10.6. It also has a read replica if thatcould be relevant. > > Thanks for any suggestions. Possible causes in decreasing order of likelihood: - I/O overload (look at I/O wait % in the CPU time). - large WITH HOLD cursors Yours, Laurenz Albe -- Cybertec | https://www.cybertec-postgresql.com