Как отследить падение postgresql

Рейтинг: 0Ответов: 0Опубликовано: 09.05.2023

Postgres запущен на удаленном linux серевере. Бэк Spring Boot обращается к этой БД. Бэк пока крутится в докере и обращается к postgres развернутой на сервере с публичным доступом по паролю. База периодически падает, не понимаю как отследить из-за чего она падает. Пробовал добавлять логирование в бэк и постгрес.

После рестарта postgres всё снова работает. введите сюда описание изображения

Логи postgres'a:

2023-05-08 09:40:43.513 CEST [2287947] postgres@spot_map LOG:  duration: 18.641 ms
2023-05-08 09:40:48.528 CEST [2287947] postgres@spot_map LOG:  duration: 7.177 ms
2023-05-08 09:40:49.932 CEST [2287891] LOG:  received fast shutdown request
2023-05-08 09:40:49.934 CEST [2287891] LOG:  aborting any active transactions
2023-05-08 09:40:49.935 CEST [2288934] postgres@postgres FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.936 CEST [2288640] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.936 CEST [2288934] postgres@postgres LOG:  disconnection: session time: 0:03:55.596 user=postgres database=postgres host=78.139.198.206 port=30708
2023-05-08 09:40:49.936 CEST [2288640] postgres@spot_map LOG:  disconnection: session time: 0:07:18.333 user=postgres database=spot_map host=172.17.0.2 port=38548
2023-05-08 09:40:49.937 CEST [2288913] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.937 CEST [2288945] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.938 CEST [2288945] postgres@spot_map LOG:  disconnection: session time: 0:03:44.432 user=postgres database=spot_map host=78.139.198.206 port=30782
2023-05-08 09:40:49.938 CEST [2288913] postgres@spot_map LOG:  disconnection: session time: 0:04:02.333 user=postgres database=spot_map host=78.139.198.206 port=30652
2023-05-08 09:40:49.939 CEST [2288935] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.940 CEST [2288935] postgres@spot_map LOG:  disconnection: session time: 0:03:54.297 user=postgres database=spot_map host=78.139.198.206 port=30717
2023-05-08 09:40:49.945 CEST [2288894] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.946 CEST [2288894] postgres@spot_map LOG:  disconnection: session time: 0:04:22.930 user=postgres database=spot_map host=78.139.198.206 port=30505
2023-05-08 09:40:49.954 CEST [2288625] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.955 CEST [2288625] postgres@spot_map LOG:  disconnection: session time: 0:07:24.284 user=postgres database=spot_map host=172.17.0.2 port=43260
2023-05-08 09:40:49.957 CEST [2288626] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.957 CEST [2288626] postgres@spot_map LOG:  disconnection: session time: 0:07:20.458 user=postgres database=spot_map host=172.17.0.2 port=38542
2023-05-08 09:40:49.958 CEST [2288621] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.958 CEST [2288621] postgres@spot_map LOG:  disconnection: session time: 0:07:30.524 user=postgres database=spot_map host=172.17.0.2 port=43258
2023-05-08 09:40:49.961 CEST [2288597] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:49.962 CEST [2288597] postgres@spot_map LOG:  disconnection: session time: 0:07:36.147 user=postgres database=spot_map host=172.17.0.2 port=45146
2023-05-08 09:40:50.040 CEST [2288566] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.041 CEST [2288566] postgres@spot_map LOG:  disconnection: session time: 0:07:51.815 user=postgres database=spot_map host=172.17.0.2 port=51912
2023-05-08 09:40:50.044 CEST [2288565] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.044 CEST [2288565] postgres@spot_map LOG:  disconnection: session time: 0:07:52.596 user=postgres database=spot_map host=172.17.0.2 port=51898
2023-05-08 09:40:50.047 CEST [2288542] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.048 CEST [2288593] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.048 CEST [2288542] postgres@spot_map LOG:  disconnection: session time: 0:08:01.942 user=postgres database=spot_map host=172.17.0.2 port=35978
2023-05-08 09:40:50.048 CEST [2288593] postgres@spot_map LOG:  disconnection: session time: 0:07:42.267 user=postgres database=spot_map host=172.17.0.2 port=45138
2023-05-08 09:40:50.053 CEST [2287947] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.053 CEST [2287947] postgres@spot_map LOG:  disconnection: session time: 0:14:05.391 user=postgres database=spot_map host=78.139.198.206 port=28286
2023-05-08 09:40:50.124 CEST [2288567] postgres@spot_map FATAL:  terminating connection due to administrator command
2023-05-08 09:40:50.125 CEST [2288567] postgres@spot_map LOG:  disconnection: session time: 0:07:49.487 user=postgres database=spot_map host=172.17.0.2 port=51920
2023-05-08 09:40:50.218 CEST [2287891] LOG:  background worker "logical replication launcher" (PID 2287898) exited with exit code 1
2023-05-08 09:40:50.228 CEST [2287893] LOG:  shutting down
2023-05-08 09:40:50.232 CEST [2287893] LOG:  checkpoint starting: shutdown immediate
2023-05-08 09:40:50.439 CEST [2287893] LOG:  checkpoint complete: wrote 120 buffers (0.7%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.186 s, sync=0.004 s, total=0.212 s; sync files=55, longest=0.001 >
2023-05-08 09:40:50.447 CEST [2287891] LOG:  database system is shut down

Логи Spring Boot:

2023-05-09T07:37:16.629Z  INFO 1 --- [nio-8080-exec-7] com.shulpov.spots_app.config.JWTFilter   : filter authHeader=null
2023-05-09T07:37:16.668Z  INFO 1 --- [nio-8080-exec-7] com.shulpov.spots_app.config.JWTFilter   : to next filters
2023-05-09T09:00:55.443Z  INFO 1 --- [nio-8080-exec-8] o.apache.coyote.http11.Http11Processor   : Error parsing HTTP request header
 Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.

java.lang.IllegalArgumentException: Invalid character found in method name [{D79E94C5-70F0-46BD-965B-E17497CCB598}...]. HTTP method names must be tokens
        at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:419) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:272) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:859) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1734) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-10.1.5.jar!/:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2023-05-09T09:05:26.508Z  INFO 1 --- [nio-8080-exec-9] com.shulpov.spots_app.config.JWTFilter   : filter authHeader=null
2023-05-09T09:05:26.513Z  INFO 1 --- [nio-8080-exec-9] com.shulpov.spots_app.config.JWTFilter   : to next filters
2023-05-09T09:05:26.720Z  INFO 1 --- [nio-8080-exec-9] c.s.s.controllers.AuthController         : /auth/register userDto.name=user1_name
Hibernate: select r1_0.id,r1_0.name,r1_0.code_name from roles r1_0 where r1_0.code_name=?
2023-05-09T09:05:57.048Z  WARN 1 --- [nio-8080-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 08001
2023-05-09T09:05:57.050Z ERROR 1 --- [nio-8080-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : HikariPool-1 - Connection is not available, request timed out after 30022ms.
2023-05-09T09:05:57.051Z ERROR 1 --- [nio-8080-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : Connection to 185.249.227.104:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
2023-05-09T09:05:57.515Z ERROR 1 --- [nio-8080-exec-9] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection] with root cause

java.net.ConnectException: Connection refused
        at java.base/sun.nio.ch.Net.pollConnect(Native Method) ~[na:na]
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597) ~[na:na]
        at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327) ~[na:na]
        at java.base/java.net.Socket.connect(Socket.java:633) ~[na:na]
        at org.postgresql.core.PGStream.createSocket(PGStream.java:243) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.core.PGStream.<init>(PGStream.java:98) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:132) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:258) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:253) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.Driver.makeConnection(Driver.java:434) ~[postgresql-42.5.4.jar!/:42.5.4]
        at org.postgresql.Driver.connect(Driver.java:291) ~[postgresql-42.5.4.jar!/:42.5.4]
        at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) ~[HikariCP-5.0.1.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359) ~[HikariCP-5.0.1.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201) ~[HikariCP-5.0.1.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470) ~[HikariCP-5.0.1.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:733) ~[HikariCP-5.0.1.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:712) ~[HikariCP-5.0.1.jar!/:na]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

Вот такие методы Rest API выполняются (CRUD операции с базой). Ничего не падает.

введите сюда описание изображения

p.s. картинки в базе не храню, только информацию о них.

Вопрос: Как отследить причину падения базы? Она выключается как будто в случайный момент.

Ответы

Ответов пока нет.