没有错误，无限加载：我应该在哪里搜索？

Question

这是上下文，今天刚发生：

Ubuntu 16.04，PostgreSQL 9.5
查询任何使用 PostgreSQL 的页面时无限加载（无消息）
当运行任何带有 psql 的查询（没有消息）
/var/log/postgresql/postgresql-9.5-main.log
/var/log/syslog
服务器负载正常（每个处理器约 1%，内存几乎未使用，磁盘 space 正常）

然后，在运行 sudo service postgresql restart.

之后一切正常

这种情况应该去哪里找呢？是 "common" 问题吗？没有日志，我不知道该怎么办。我怎么能相对"sure"就不会再随机发生了？

旁注：这是我重新启动后 postgreSQL 日志的详细信息：

2017-03-16 12:20:52 CET [857-2] LOG:  received fast shutdown request
2017-03-16 12:20:52 CET [857-3] LOG:  aborting any active transactions
2017-03-16 12:20:52 CET [6829-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6829-2] XXXXX@YYYY STATEMENT:  select * from "users" where "users"."id" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [6644-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6644-2] XXXXX@YYYY STATEMENT:  select * from "users" where "users"."id" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [6649-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6649-2] XXXXX@YYYY STATEMENT:  select * from "users" where "users"."id" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [6580-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6580-2] XXXXX@YYYY STATEMENT:  select * from "users" where "users"."id" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [6768-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6768-2] XXXXX@YYYY STATEMENT:  select * from "users" where "email" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [6253-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command
2017-03-16 12:20:52 CET [6253-2] XXXXX@YYYY STATEMENT:  alter table "users" add column "email_confirmed" boolean not null default '1'
2017-03-16 12:20:52 CET [8465-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command
2017-03-16 12:20:52 CET [913-2] LOG:  autovacuum launcher shutting down
2017-03-16 12:20:52 CET [6586-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command at character 15
2017-03-16 12:20:52 CET [6586-2] XXXXX@YYYY STATEMENT:  select * from "users" where "users"."id" =  and "users"."deleted_at" is null limit 1
2017-03-16 12:20:52 CET [31969-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command
2017-03-16 12:20:52 CET [6300-1] XXXXX@YYYY FATAL:  terminating connection due to administrator command
2017-03-16 12:20:52 CET [6974-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [906-1] LOG:  shutting down
2017-03-16 12:20:52 CET [6980-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6978-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6975-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6977-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6976-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6983-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6979-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6982-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6981-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6985-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [6984-1] XXXXX@YYYY FATAL:  the database system is shutting down
2017-03-16 12:20:52 CET [906-2] LOG:  database system is shut down
2017-03-16 12:20:53 CET [7002-1] LOG:  database system was shut down at 2017-03-16 12:20:52 CET

Answer 1

这是导致您遇到问题的语句：

alter table "users" add column "email_confirmed" boolean not null default '1'

这样的 ALTER TABLE 需要对 table 的 ACCESS EXCLUSIVE 锁定，这甚至与读访问冲突。

现在 table users 似乎很忙 table，这通常没有问题（除非两个事务试图写入同一行）因为 table 他们需要的锁不会相互冲突。

现在出现了 ALTER TABLE，必须等到 table 上的所有早期交易（至少持有 table 上的 ACCESS SHARE 锁）完成. 在之后对 table 的所有查询都必须在 ALTER TABLE 之后排队，因为它们需要的锁与 ALTER TABLE 的锁冲突需要。

一旦 ALTER TABLE 获得它的 ACCESS EXCLUSIVE 锁，它应该很快完成，然后一切恢复正常。

现在还有一个谜题：您日志中所有其他中断的查询看起来都是很短的查询，所以您为什么要等那么久并不明显——它们应该在一两个小时内完成微秒。

为了解释这一点，请记住锁不会在查询完成时释放，而是一直持有到事务结束。因此，如果您运行事务中的一个简短查询然后让事务保持打开状态，则此空闲数据库会话将也阻塞 ALTER TABLE。在正常情况下您可能不会注意到，特别是如果所有事务都是只读的，但在这种情况下它会证明是有害的。

顺便说一句，保持开放的交易还有其他负面影响，特别是 VACUUM 无法完成它的工作，并且您的 table 和索引会变得臃肿。

您可以通过从 pg_stat_activity 系统视图检查 state 来检查您的应用程序是否存在该问题。如果您可以经常看到 idle in transaction 的会话并保持这种状态一段时间，那么您正在寻找问题的根本原因。这应该是固定的！

您也可以中断 ALTER TABLE 语句而不是重新启动服务器。

如果您再次运行遇到这样的问题，请查询pg_locks系统视图。您会看到会话运行宁 ALTER TABLE 有一个锁 granted = FALSE，因为它正在等待 table 锁。您还可以查看哪些其他会话正在锁定 table。

没有错误，无限加载：我应该在哪里搜索？

No errors, infinite loading: where should I search?

postgresql

ubuntu

logging

postgresql-9.5

ubuntu-16.04