Re: Log files polluted with permission denied error messages after every 10 seconds

Andrus <kobruleht2@hot.ee>

From: Andrus <kobruleht2@hot.ee>
To: Michael Paquier <michael@paquier.xyz>
Cc: Laurenz Albe <laurenz.albe@cybertec.at>, pgsql-general <pgsql-general@postgresql.org>
Date: 2021-03-06T08:47:00Z
Lists: pgsql-general
Hi!

 > On which files are those complaints?

log contains file names:

...

2021-03-06 10:27:51.468 EET [4580] LOG:  could not rename file 
"pg_wal/000000010000000600000092": Permission denied
2021-03-06 10:28:01.526 EET [4580] LOG:  could not rename file 
"pg_wal/000000010000000600000098": Permission denied
2021-03-06 10:28:11.582 EET [4580] LOG:  could not rename file 
"pg_wal/000000010000000600000099": Permission denied
2021-03-06 10:28:21.637 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000E8": Permission denied
2021-03-06 10:28:31.692 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000EA": Permission denied
2021-03-06 10:28:41.750 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000EB": Permission denied
2021-03-06 10:28:51.807 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000EC": Permission denied
2021-03-06 10:29:01.864 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000ED": Permission denied
2021-03-06 10:29:11.920 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000EE": Permission denied
2021-03-06 10:29:21.976 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000EF": Permission denied
2021-03-06 10:29:32.033 EET [4580] LOG:  could not rename file 
"pg_wal/0000000100000006000000F0": Permission denied

Server was installed some days ago. Numbers in end of file names are 
small. So it looks like almost every wal file in timeline causes entry.

> It seems to me that you may have
> more going on in this system that interacts with your data folder than
> you think.

There is Windows server backup utility client from 
https://www.r1soft.com/  . It looks like it performs block-level 
realtime backup of HDD .

Its about box shows last year 2015 , but Windows Server 2019 is used. 
Maybe it is outdated and causes the issue. It is maintained by by ISP 
and I cannot stop it easily.

I havent found an option in its config to susped or configure it.

Config contains

max_wal_size = 1GB

There are 67 files in pg_wal. Earlier have have similar errors in my app 
if windows temporary directory contains  200000 files by mistake. 
Cleaning temp directory and adding random number to temporary file names 
seems to fix this.

Should max_wal or or other param size decrased or increased to avoid 
file access conflict.


> pg_wal also contains files with .deleted extension like
>> 0000000100000005000000B2.deleted
> These are generated on Windows when removing a past WAL segment, where
> the process involves a rename followed by durable_unlink() that would
> generate some LOG entries in the logs if the internal unlink() failed
> (see RemoveXlogFile() in xlog.c).

.deleted files have dates ealier dates (yesterday and 4th or March). 
Almost all regular wal files have todays date.

There are about 30 .deleted files from totel 67 files in pg_wal. Will 
postgres remove .deleted files automatically or should I create windows 
task which deletes them periodically ?

Andrus.


Commits

Same data as JSON: GET /api/v1/messages/:b64id/commits the thread's linked commits as JSON, with link sources. API reference →
  1. Fix concurrency issues with WAL segment recycling on Windows