Postgres 13 in my Windows 10 machine is extremely slow. Even with Postgres shell, every single command needs 22 seconds to be executed. Either it is a single query in a nearly zero-rows DB, or a simple switch to another DB.
I have switched my listen_addresses
from '*'
to '127.0.0.1,::1'
in postgresql.conf
, without any effect.
Please, I need some help. Thank you in advance.
EDIT:
I checked the logs (postgresql-<date&time>.log
), but I can't read them. One repeated line every few seconds from the start till the pc shuts down, is the following:
2021-10-16 16:11:28.683 EEST [8032] LOG: using stale statistics instead of current ones because stats collector is not responding
(under many codes within the brackets, not only the 8032 as in the example)
The same line is repeated between the statements, after any command/query it gets. Is there something more I can do with the logs to get more specific information (if this isn't enough to define the problem)?
EDIT 2: I post the first lines of the last log.
2021-10-16 13:30:44.137 EEST [7080] LOG: starting PostgreSQL 13.2, compiled by Visual C++ build 1914, 64-bit
2021-10-16 13:30:44.138 EEST [7080] LOG: listening on IPv4 address "127.0.0.1", port 5432
2021-10-16 13:30:44.151 EEST [7080] LOG: listening on IPv6 address "::1", port 5432
2021-10-16 13:30:44.201 EEST [7228] LOG: database system was shut down at 2021-10-16 13:29:31 EEST
2021-10-16 13:30:44.219 EEST [7080] LOG: database system is ready to accept connections
2021-10-16 13:34:00.068 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:15.722 EEST [2604] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:19.822 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:35.401 EEST [16868] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:39.787 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:55.317 EEST [18328] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:34:59.954 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:35:15.939 EEST [17868] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:35:20.225 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:35:36.235 EEST [14804] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:35:40.224 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:35:56.214 EEST [7588] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:00.282 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:16.264 EEST [7740] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:20.222 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:36.196 EEST [9784] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:40.194 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:36:56.190 EEST [9476] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:00.319 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:16.321 EEST [4064] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:20.190 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:36.182 EEST [1400] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:40.227 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:37:56.226 EEST [18304] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:00.327 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:16.302 EEST [16724] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:20.210 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:36.180 EEST [16356] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:40.206 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:38:56.208 EEST [16536] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:00.333 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:16.314 EEST [8628] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:20.237 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:36.236 EEST [17824] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:40.235 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:55.870 EEST [13752] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:39:59.790 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:10.496 EEST [15540] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:10.496 EEST [15540] STATEMENT: /*pga4dash*/
SELECT 'session_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT count(*) FROM pg_catalog.pg_stat_activity) AS "Total",
(SELECT count(*) FROM pg_catalog.pg_stat_activity WHERE state = 'active') AS "Active",
(SELECT count(*) FROM pg_catalog.pg_stat_activity WHERE state = 'idle') AS "Idle"
) t
UNION ALL
SELECT 'tps_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(xact_commit) + sum(xact_rollback) FROM pg_catalog.pg_stat_database) AS "Transactions",
(SELECT sum(xact_commit) FROM pg_catalog.pg_stat_database) AS "Commits",
(SELECT sum(xact_rollback) FROM pg_catalog.pg_stat_database) AS "Rollbacks"
) t
UNION ALL
SELECT 'ti_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(tup_inserted) FROM pg_catalog.pg_stat_database) AS "Inserts",
(SELECT sum(tup_updated) FROM pg_catalog.pg_stat_database) AS "Updates",
(SELECT sum(tup_deleted) FROM pg_catalog.pg_stat_database) AS "Deletes"
) t
UNION ALL
SELECT 'to_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(tup_fetched) FROM pg_catalog.pg_stat_database) AS "Fetched",
(SELECT sum(tup_returned) FROM pg_catalog.pg_stat_database) AS "Returned"
) t
UNION ALL
SELECT 'bio_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(blks_read) FROM pg_catalog.pg_stat_database) AS "Reads",
(SELECT sum(blks_hit) FROM pg_catalog.pg_stat_database) AS "Hits"
) t
2021-10-16 13:40:15.019 EEST [13644] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:19.527 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:25.797 EEST [15540] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:25.797 EEST [15540] STATEMENT: /*pga4dash*/
SELECT 'session_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT count(*) FROM pg_catalog.pg_stat_activity) AS "Total",
(SELECT count(*) FROM pg_catalog.pg_stat_activity WHERE state = 'active') AS "Active",
(SELECT count(*) FROM pg_catalog.pg_stat_activity WHERE state = 'idle') AS "Idle"
) t
UNION ALL
SELECT 'tps_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(xact_commit) + sum(xact_rollback) FROM pg_catalog.pg_stat_database) AS "Transactions",
(SELECT sum(xact_commit) FROM pg_catalog.pg_stat_database) AS "Commits",
(SELECT sum(xact_rollback) FROM pg_catalog.pg_stat_database) AS "Rollbacks"
) t
UNION ALL
SELECT 'ti_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(tup_inserted) FROM pg_catalog.pg_stat_database) AS "Inserts",
(SELECT sum(tup_updated) FROM pg_catalog.pg_stat_database) AS "Updates",
(SELECT sum(tup_deleted) FROM pg_catalog.pg_stat_database) AS "Deletes"
) t
UNION ALL
SELECT 'to_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(tup_fetched) FROM pg_catalog.pg_stat_database) AS "Fetched",
(SELECT sum(tup_returned) FROM pg_catalog.pg_stat_database) AS "Returned"
) t
UNION ALL
SELECT 'bio_stats' AS chart_name, pg_catalog.row_to_json(t) AS chart_data
FROM (SELECT
(SELECT sum(blks_read) FROM pg_catalog.pg_stat_database) AS "Reads",
(SELECT sum(blks_hit) FROM pg_catalog.pg_stat_database) AS "Hits"
) t
2021-10-16 13:40:34.869 EEST [6848] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-10-16 13:40:39.566 EEST [7300] LOG: using stale statistics instead of current ones because stats collector is not responding
EDIT 3: Trying to define whether Stats Collector
is running or not, this is the only I got:
With the help of google I found that:
--forkavworker
& --forkavlauncher
are AutoVacuum
, --forkboot
is WalWriter
& BgWriter
, --forkcol
is PgStat
and --forklog
is SysLogger
. For --forkbackend
didn't find which process it is, though it doesn't seem to be the Stats Collector
. And if it isn't, it mustn't be running.
EDIT 4: Now here is the log after killing stats collector in task manager.
2021-10-18 01:37:20.049 EEST [1448] LOG: starting PostgreSQL 13.2, compiled by Visual C++ build 1914, 64-bit
2021-10-18 01:37:20.052 EEST [1448] LOG: listening on IPv4 address "127.0.0.1", port 5432
2021-10-18 01:37:20.057 EEST [1448] LOG: listening on IPv6 address "::1", port 5432
2021-10-18 01:37:20.576 EEST [1448] LOG: test message did not get through on socket for statistics collector
2021-10-18 01:37:20.577 EEST [1448] LOG: trying another address for the statistics collector
2021-10-18 01:37:20.651 EEST [21840] LOG: database system was shut down at 2021-10-18 01:37:17 EEST
2021-10-18 01:37:20.737 EEST [1448] LOG: database system is ready to accept connections
2021-10-18 01:45:51.416 EEST [1448] LOG: statistics collector process (PID 21848) exited with exit code 1
2021-10-18 01:48:55.326 EEST [1448] LOG: received fast shutdown request
2021-10-18 01:48:55.336 EEST [1448] LOG: aborting any active transactions
2021-10-18 01:48:55.346 EEST [1448] LOG: background worker "logical replication launcher" (PID 9420) exited with exit code 1
2021-10-18 01:48:55.353 EEST [19076] FATAL: terminating connection due to administrator command
2021-10-18 01:48:55.354 EEST [6124] FATAL: terminating connection due to administrator command
2021-10-18 01:48:55.374 EEST [5116] LOG: shutting down
2021-10-18 01:48:55.419 EEST [1448] LOG: database system is shut down
Right after that and before the restart I used psql, and didn't see any improvement in query times. That was something expected, or it means that stats collector isn't the real cause of the problems?
EDIT 5: All of sudden, at about 14:15 local time according to the log, it started working properly. I realized that many hours later, and until now it is working fine. As I checked in the logs, the problem exists since few hours after the installation. I post that first log lines, if someone could make out what may be the reason of the problem. According to the logs, only for about 2 weeks on the last July worked properly, and some other times for small intervals of about 2-3 days. Thank you all for your help. When the problem will return, I will know what I have to try to do.
2021-04-03 22:51:51.945 EEST [17448] LOG: starting PostgreSQL 13.2, compiled by Visual C++ build 1914, 64-bit
2021-04-03 22:51:51.947 EEST [17448] LOG: listening on IPv6 address "::", port 5432
2021-04-03 22:51:51.949 EEST [17448] LOG: listening on IPv4 address "0.0.0.0", port 5432
2021-04-03 22:51:52.471 EEST [17448] LOG: test message did not get through on socket for statistics collector
2021-04-03 22:51:52.472 EEST [17448] LOG: trying another address for the statistics collector
2021-04-03 22:51:52.544 EEST [2900] LOG: database system was shut down at 2021-04-03 22:51:45 EEST
2021-04-03 22:51:52.691 EEST [17448] LOG: database system is ready to accept connections
2021-04-03 23:31:12.289 EEST [16900] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
------------------------------ next log file --------------------------------
2021-04-04 03:03:40.484 EEST [8412] LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.
2021-04-04 03:06:45.054 EEST [7820] ERROR: canceling statement due to user request
2021-04-04 03:06:45.056 EEST [17448] LOG: received fast shutdown request
2021-04-04 03:06:45.059 EEST [17448] LOG: aborting any active transactions
2021-04-04 03:06:45.060 EEST [17448] LOG: background worker "logical replication launcher" (PID 7820) exited with exit code 1
2021-04-04 03:06:45.069 EEST [12732] LOG: shutting down
2021-04-04 03:06:45.108 EEST [17448] LOG: database system is shut down
------------------------------ next log file --------------------------------
2021-04-04 11:27:51.395 EEST [6028] LOG: starting PostgreSQL 13.2, compiled by Visual C++ build 1914, 64-bit
2021-04-04 11:27:51.396 EEST [6028] LOG: listening on IPv6 address "::", port 5432
2021-04-04 11:27:51.397 EEST [6028] LOG: listening on IPv4 address "0.0.0.0", port 5432
2021-04-04 11:27:51.535 EEST [5248] LOG: database system was shut down at 2021-04-04 03:06:45 EEST
2021-04-04 11:27:51.550 EEST [6028] LOG: database system is ready to accept connections
2021-04-04 11:30:07.850 EEST [6308] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:30:24.218 EEST [14904] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:31:08.689 EEST [6308] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:31:25.669 EEST [9412] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:32:08.688 EEST [6308] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:32:25.809 EEST [17736] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:33:09.198 EEST [6308] LOG: using stale statistics instead of current ones because stats collector is not responding
2021-04-04 11:33:26.774 EEST [4460] LOG: using stale statistics instead of current ones because stats collector is not responding