Thread: BUG #18507: See C include file "ntstatus.h" for a description of the hexadecimal value.

The following bug has been logged on the website:

Bug reference:      18507
Logged by:          Surya Prakash
Email address:      suryasp1010@gmail.com
PostgreSQL version: 14.1
Operating system:   windows server 2016
Description:

As per the logs, the first issue started here at this timestamp:

2024-06-12 19:04:51.427 CST [19908] STATEMENT:  select

"ID","IncNo","IncSource","AlarmType","IsNeedCalcDT","Customer","Area","Project","RouterStep","Line","Station","Shift","UrgentLevel","OccurTime","ExpectFinishTime","IncStatus","Department","RespPerson","IssueDesc","IssueCategory","RootCause","RTCategory","ActionDesc","ActionCategory","ClosedTime","DownTimeMinutes"
from "AT_IncidentDownTime_V" 
2024-06-12 19:05:14.871 CST [16044] LOG:  could not open file
"base/16510/701219.2": sharing violation
2024-06-12 19:05:14.871 CST [16044] DETAIL:  Continuing to retry for 30
seconds.
2024-06-12 19:05:14.871 CST [16044] HINT:  You might have antivirus, backup,
or similar software interfering with the database system.
2024-06-12 19:05:14.871 CST [16044] CONTEXT:  writing block 279962 of
relation base/16510/701219
2024-06-12 19:05:21.452 CST [19260] ERROR:  column "Project" does not exist
at character 78
2024-06-12 19:05:21.452 CST [19260] HINT:  Perhaps you meant to reference
the column "AT_IncidentDownTime_V.Project_ID".
2024-06-12 19:05:21.452 CST [19260] STATEMENT:  select

"ID","IncNo","IncSource","AlarmType","IsNeedCalcDT","Customer","Area","Project","RouterStep","Line","Station","Shift","UrgentLevel","OccurTime","ExpectFinishTime","IncStatus","Department","RespPerson","IssueDesc","IssueCategory","RootCause","RTCategory","ActionDesc","ActionCategory","ClosedTime","DownTimeMinutes"
from "AT_IncidentDownTime_V" 
2024-06-12 19:05:39.703 CST [16044] ERROR:  could not open file
"base/16510/701219.2" (target block 279962): Permission denied
2024-06-12 19:05:39.703 CST [16044] CONTEXT:  writing block 279962 of
relation base/16510/701219
2024-06-12 19:05:51.806 CST [2864] ERROR:  column "Project" does not exist
at character 78
2024-06-12 19:05:51.806 CST [2864] HINT:  Perhaps you meant to reference the
column "AT_IncidentDownTime_V.Project_ID".
2024-06-12 19:05:51.806 CST [2864] STATEMENT:  select

"ID","IncNo","IncSource","AlarmType","IsNeedCalcDT","Customer","Area","Project","RouterStep","Line","Station","Shift","UrgentLevel","OccurTime","ExpectFinishTime","IncStatus","Department","RespPerson","IssueDesc","IssueCategory","RootCause","RTCategory","ActionDesc","ActionCategory","ClosedTime","DownTimeMinutes"
from "AT_IncidentDownTime_V" 
2024-06-12 19:06:14.005 CST [20012] LOG:  could not open file
"pg_tblspc/8927048/PG_14_202107181/5409897/125698122": sharing violation
2024-06-12 19:06:14.005 CST [20012] DETAIL:  Continuing to retry for 30
seconds.
2024-06-12 19:06:14.005 CST [20012] HINT:  You might have antivirus, backup,
or similar software interfering with the database system.

Later on, the database went into recovery mode:

2024-06-12 19:31:33.785 CST [3452] LOG:  could not receive data from client:
An established connection was aborted by the software in your host
machine.

    
2024-06-12 19:31:55.194 CST [16044] PANIC:  could not fsync file
"base/16510/692021.1": Permission denied
2024-06-12 19:31:59.133 CST [15384] ERROR:  column "Project" does not exist
at character 78
2024-06-12 19:31:59.133 CST [15384] HINT:  Perhaps you meant to reference
the column "AT_IncidentDownTime_V.Project_ID".
2024-06-12 19:31:59.133 CST [15384] STATEMENT:  select

"ID","IncNo","IncSource","AlarmType","IsNeedCalcDT","Customer","Area","Project","RouterStep","Line","Station","Shift","UrgentLevel","OccurTime","ExpectFinishTime","IncStatus","Department","RespPerson","IssueDesc","IssueCategory","RootCause","RTCategory","ActionDesc","ActionCategory","ClosedTime","DownTimeMinutes"
from "AT_IncidentDownTime_V" 
2024-06-12 19:32:04.846 CST [2160] LOG:  could not signal for checkpoint: No
such process
2024-06-12 19:32:09.278 CST [6560] LOG:  could not signal for checkpoint: No
such process
2024-06-12 19:32:10.135 CST [10440] LOG:  could not signal for checkpoint:
No such process
2024-06-12 19:32:11.615 CST [2160] LOG:  could not signal for checkpoint: No
such process
2024-06-12 19:32:12.312 CST [21708] LOG:  checkpointer process (PID 16044)
was terminated by exception 0xC0000409
2024-06-12 19:32:12.312 CST [21708] HINT:  See C include file "ntstatus.h"
for a description of the hexadecimal value.
2024-06-12 19:32:12.312 CST [21708] LOG:  terminating any other active
server processes
2024-06-12 19:32:12.452 CST [20800] FATAL:  the database system is in
recovery mode
2024-06-12 19:32:12.467 CST [7272] FATAL:  the database system is in
recovery mode
2024-06-12 19:32:12.484 CST [13796] FATAL:  the database system is in
recovery mode
2024-06-12 19:32:12.505 CST [20844] FATAL:  the database system is in
recovery mode


after sometime of same messages

2024-06-12 19:46:36.002 CST [7148] FATAL:  the database system is in
recovery mode
2024-06-12 19:46:37.778 CST [8548] FATAL:  could not open file
"base/20846/24818.12" (target block 1572864): Permission denied
2024-06-12 19:46:37.778 CST [8548] CONTEXT:  WAL redo at DFFA/F30FA990 for
Heap/INSERT: off 49 flags 0x00; blkref #0: rel 1663/20846/24818, blk 7975034
FPW
2024-06-12 19:46:39.007 CST [2428] FATAL:  the database system is in
recovery mode
2024-06-12 19:46:40.816 CST [21708] LOG:  startup process (PID 8548) exited
with exit code 1
2024-06-12 19:46:40.816 CST [21708] LOG:  aborting startup due to startup
process failure
2024-06-12 19:46:43.565 CST [21708] LOG:  database system is shut down

Later when we startup the database manually it started very slow. frequent
connectivity issues are there now.

2024-06-13 10:36:13.261 CST [6608] LOG:  starting PostgreSQL 14.1, compiled
by Visual C++ build 1914, 64-bit
2024-06-13 10:36:13.264 CST [6608] LOG:  listening on IPv6 address "::",
port 5432
2024-06-13 10:36:13.264 CST [6608] LOG:  listening on IPv4 address
"0.0.0.0", port 5432
2024-06-13 10:36:13.362 CST [11440] LOG:  database system was interrupted
while in recovery at 2024-06-12 19:35:03 CST
2024-06-13 10:36:13.362 CST [11440] HINT:  This probably means that some
data is corrupted and you will have to use the last backup for recovery.
2024-06-13 10:36:13.371 CST [17744] FATAL:  the database system is starting
up
2024-06-13 10:36:13.440 CST [16920] FATAL:  the database system is starting
up

Hi, sorry for replying to such an old thread, but I see there are no
other replies.

On 2024-Jun-13, PG Bug reporting form wrote:

> 2024-06-12 19:31:55.194 CST [16044] PANIC:  could not fsync file "base/16510/692021.1": Permission denied
> [...]
> 2024-06-12 19:32:12.312 CST [21708] LOG:  terminating any other active server processes

According to these lines, it took 17 seconds since raising the PANIC
until postmaster managed to process the signal and started to take
processes down.  This isn't the highest I've seen, but it's high enough
to be concerning.  You're likely overloading the machine.  This isn't
the actual cause of the problem you're reporting, but it seems a rather
bad idea and will give you a bad experience.  You should have a
connection pooler and limit the number of maximum connections you allow
in the database directly.  Also, consider giving it more CPU power, more
storage bandwidth, maybe more memory (though extra RAM by itself is
unlikely to achieve much in this case).

> 2024-06-12 19:46:37.778 CST [8548] FATAL:  could not open file "base/20846/24818.12" (target block 1572864):
Permissiondenied
 
> 2024-06-12 19:46:37.778 CST [8548] CONTEXT:  WAL redo at DFFA/F30FA990 for Heap/INSERT: off 49 flags 0x00; blkref #0:
rel1663/20846/24818, blk 7975034 FPW
 

So do you have an antivirus?  Maybe you can configure it to skip the
Postgres data files.  Otherwise this kind of problem is going to bite
you hard.

> Later when we startup the database manually it started very slow. frequent
> connectivity issues are there now.

Probably it had way too much recovery to perform, which suggests your
checkpoint settings need tightening so that they occur more frequently.
Again, this could be caused by overload.

> 
> 2024-06-13 10:36:13.261 CST [6608] LOG:  starting PostgreSQL 14.1, compiled
> by Visual C++ build 1914, 64-bit

14.1 is about 3 years out of date.  There are bugs, and you're not going
to like them.  Perhaps bugs about inability to open files that the
antivirus is scanning (I didn't actually check the git log, but we do
have fixes about that).  You need to upgrade to 14.13 with haste.

Regards

-- 
Álvaro Herrera         PostgreSQL Developer  —  https://www.EnterpriseDB.com/
"I'm impressed how quickly you are fixing this obscure issue. I came from 
MS SQL and it would be hard for me to put into words how much of a better job
you all are doing on [PostgreSQL]."
 Steve Midgley, http://archives.postgresql.org/pgsql-sql/2008-08/msg00000.php