ruby-on-rails 保留作业时出错:PG::连接错误:PQconsumeInput()服务器意外关闭连接

wooyq4lh  于 2023-01-22  发布在  Ruby
关注(0)|答案(2)|浏览(103)

延迟作业服务将在其启动后不到1小时停止,日志如下:

I, [2018-02-26T06:00:26.580458 #11439]  INFO -- : 2018-02-26T06:00:26+0400: [Worker(delayed_job host:myhost pid:11439)] Starting job worker
I, [2018-02-26T06:00:26.664929 #11439]  INFO -- : 2018-02-26T06:00:26+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41019) RUNNING
I, [2018-02-26T06:00:27.342994 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41019) COMPLETED after 0.6779
I, [2018-02-26T06:00:27.346526 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41020) RUNNING
I, [2018-02-26T06:00:27.470858 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41020) COMPLETED after 0.1242
I, [2018-02-26T06:00:27.474937 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41024) RUNNING
I, [2018-02-26T06:00:27.603043 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41024) COMPLETED after 0.1280
I, [2018-02-26T06:00:27.606702 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41025) RUNNING
I, [2018-02-26T06:00:27.725715 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41025) COMPLETED after 0.1189
I, [2018-02-26T06:00:27.728021 #11439]  INFO -- : 2018-02-26T06:00:27+0400: [Worker(delayed_job host:myhost pid:11439)] 4 jobs processed at 3.4871 j/s, 0 failed
I, [2018-02-26T06:14:48.287220 #11439]  INFO -- : 2018-02-26T06:14:48+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41027) RUNNING
I, [2018-02-26T06:14:48.414079 #11439]  INFO -- : 2018-02-26T06:14:48+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41027) COMPLETED after 0.1267
I, [2018-02-26T06:14:48.416335 #11439]  INFO -- : 2018-02-26T06:14:48+0400: [Worker(delayed_job host:myhost pid:11439)] 1 jobs processed at 7.3771 j/s, 0 failed
I, [2018-02-26T06:16:33.492435 #11439]  INFO -- : 2018-02-26T06:16:33+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41028) RUNNING
I, [2018-02-26T06:16:33.613684 #11439]  INFO -- : 2018-02-26T06:16:33+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41028) COMPLETED after 0.1211
I, [2018-02-26T06:16:33.615953 #11439]  INFO -- : 2018-02-26T06:16:33+0400: [Worker(delayed_job host:myhost pid:11439)] 1 jobs processed at 7.8121 j/s, 0 failed
I, [2018-02-26T06:22:33.853678 #11439]  INFO -- : 2018-02-26T06:22:33+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41030) RUNNING
I, [2018-02-26T06:22:33.967338 #11439]  INFO -- : 2018-02-26T06:22:33+0400: [Worker(delayed_job host:myhost pid:11439)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=41030) COMPLETED after 0.1136
I, [2018-02-26T06:22:33.970307 #11439]  INFO -- : 2018-02-26T06:22:33+0400: [Worker(delayed_job host:myhost pid:11439)] 1 jobs processed at 8.2735 j/s, 0 failed
I, [2018-02-26T06:38:24.595215 #11439]  INFO -- : 2018-02-26T06:38:24+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQconsumeInput() server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:24.593926', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:24.593351' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:24.593398') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:29.597026 #11439]  INFO -- : 2018-02-26T06:38:29+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:29.596061', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:29.595477' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:29.595524') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:34.598775 #11439]  INFO -- : 2018-02-26T06:38:34+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:34.597856', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:34.597278' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:34.597325') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:39.600772 #11439]  INFO -- : 2018-02-26T06:38:39+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:39.599713', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:39.599063' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:39.599110') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:44.602546 #11439]  INFO -- : 2018-02-26T06:38:44+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:44.601568', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:44.601024' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:44.601072') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:49.604286 #11439]  INFO -- : 2018-02-26T06:38:49+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:49.603369', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:49.602808' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:49.602863') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:54.606189 #11439]  INFO -- : 2018-02-26T06:38:54+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:54.605111', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:54.604563' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:54.604613') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:38:59.608610 #11439]  INFO -- : 2018-02-26T06:38:59+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:38:59.607243', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:38:59.606483' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:38:59.606539') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:39:04.610465 #11439]  INFO -- : 2018-02-26T06:39:04+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:39:04.609457', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:39:04.608876' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:39:04.608926') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
I, [2018-02-26T06:39:09.612201 #11439]  INFO -- : 2018-02-26T06:39:09+0400: [Worker(delayed_job host:myhost pid:11439)] Error while reserving job: PG::ConnectionBad: PQsocket() can't get socket descriptor: UPDATE "delayed_jobs" SET locked_at = '2018-02-26 02:39:09.611263', locked_by = 'delayed_job host:myhost pid:11439' WHERE id IN (SELECT  "delayed_jobs"."id" FROM "delayed_jobs" WHERE ((run_at <= '2018-02-26 02:39:09.610721' AND (locked_at IS NULL OR locked_at < '2018-02-25 22:39:09.610770') OR locked_by = 'delayed_job host:myhost pid:11439') AND failed_at IS NULL)  ORDER BY priority ASC, run_at ASC LIMIT 1 FOR UPDATE) RETURNING *
    • 数据库. yml**
production:
 adapter: postgresql
 encoding: unicode
 database: myapp
 port: 5432
 pool: 5
 username: username
 password: password
 reconnect: true

请任何人只是解释这个错误的原因,以及如何避免它:

Error while reserving job: PG::ConnectionBad: PQconsumeInput() server closed the connection unexpectedly
    • 更新日期:**

我相信这个问题与延迟作业无关,因为我在做一些正常的数据库查询时也遇到了同样的错误。所以数据库由于某种原因重新启动,这就是延迟作业服务停止的原因。
根据@LaurenzAlbe的评论,以下是/var/log/postgresql/postgresql-9.3-main.log中发现的一些问题:

LOG:  connection received: host=10.10.10.15 port=57322
LOG:  replication connection authorized: user=MyDBUser
FATAL:  must be superuser or replication role to start walsender
LOG:  could not receive data from client: Connection reset by peer
LOG:  disconnection: session time: 0:06:18.911 user=MyDBUser database=MyDB host=127.0.0.1 port=34040
./systemd: 36: kill: Operation not permitted
WARNING:  skipping "delayed_jobs" --- only table or database owner can analyze it
s3fp2yjn

s3fp2yjn1#

经过一番研究,我认为延迟的作业存在内存泄漏问题,这可以通过使用config.cache_classes = true来解决,因为延迟的作业不时地重新加载类。
我遇到了同样的问题,延迟的作业进程使用了超过90%+的内存,并因相同的错误而崩溃,即使我缓存了类,但我运行延迟的作业时没有使用RAILS_ENV,这导致它们在开发中加载并忽略其他环境设置。

7hiiyaii

7hiiyaii2#

此问题也可能由以下原因引起:

  1. Rails的数据库idle_timeout设置,默认为300秒,这意味着如果连接空闲超过300秒,服务器将关闭它。
  2. PgBouncer client_idle_timeout设置。此设置控制连接在PgBouncer关闭之前可以空闲多长时间。如果此设置太低,可能会导致与Rails的idle_timeout相同的错误。
  3. PostgreSQL idle_session_timeout设置(来自PostgreSQL 14)和idle_in_transaction_session_timeout(用于事务中空闲的会话)。
  4. TCP或其他网络或防火墙超时(例如,Azure Cloud中存在超时的情况)
    而要解决这个问题,有几个可能的解决方案:
    1.加快慢速处理
    1.将idle_timeout(或其他错误超时)设置增加到更高的值,以防止服务器过早关闭空闲连接。
    1.添加名为reaping_frequency的数据库设置:10,这将更频繁地清除和恢复连接,以防止它们变得空闲。
    1.添加手动重新连接,如下面的代码片段所示,在将记录保存到数据库之前释放连接并重新建立连接。
ActiveRecord::Base.connection_pool.release_connection
    ActiveRecord::Base.connection_pool.with_connection do
      # save record in database
    end

链接:
(3)(4)关于reaping_frequency的信息
(5)(6)关于Rails的idle_timeout的信息
(7)(8)(9)手动重新连接的解决方案

相关问题