Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[David Steele]

On 6/3/16 4:13 PM, Robert Haas wrote:
> On Fri, Jun 3, 2016 at 2:12 PM, Andres Freund  wrote:
>> On 2016-06-03 14:00:00 -0400, Robert Haas wrote:
>>> On Fri, May 27, 2016 at 8:44 PM, Andres Freund  wrote:
 I'm not convinced of that.  Hiding unexpected issues for longer, just to
 continue kind-of-operating, can make the impact of problems a lot worse,
 and it makes it very hard to actually learn about the issues.
>>>
>>> So if we made this a WARNING rather than an ERROR, it wouldn't hiding
>>> the issue, but it would be less likely to break things that worked
>>> before.  No?
>>
>> Except that we're then accepting the (proven!) potential for data
>> loss. We're talking about a single report of an restore_command setting
>> odd permissions. Which can easily be fixed.
> 
> Well, I think that having restore_command start failing after a minor
> release update can cause data loss, too.  Or even an outage.

I'm mostly with Andres on this but you do make a good point, Robert.

Andres, what if on EPERM you set write privs on the file and retry?
Maybe only back patch that change and for 9.6 expect restore_command
scripts to set sane permissions.

-- 
-David
da...@pgmasters.net


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Robert Haas]

On Fri, Jun 3, 2016 at 2:12 PM, Andres Freund  wrote:
> On 2016-06-03 14:00:00 -0400, Robert Haas wrote:
>> On Fri, May 27, 2016 at 8:44 PM, Andres Freund  wrote:
>> > I'm not convinced of that.  Hiding unexpected issues for longer, just to
>> > continue kind-of-operating, can make the impact of problems a lot worse,
>> > and it makes it very hard to actually learn about the issues.
>>
>> So if we made this a WARNING rather than an ERROR, it wouldn't hiding
>> the issue, but it would be less likely to break things that worked
>> before.  No?
>
> Except that we're then accepting the (proven!) potential for data
> loss. We're talking about a single report of an restore_command setting
> odd permissions. Which can easily be fixed.

Well, I think that having restore_command start failing after a minor
release update can cause data loss, too.  Or even an outage.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Andres Freund]

On 2016-06-03 14:00:00 -0400, Robert Haas wrote:
> On Fri, May 27, 2016 at 8:44 PM, Andres Freund  wrote:
> > I'm not convinced of that.  Hiding unexpected issues for longer, just to
> > continue kind-of-operating, can make the impact of problems a lot worse,
> > and it makes it very hard to actually learn about the issues.
> 
> So if we made this a WARNING rather than an ERROR, it wouldn't hiding
> the issue, but it would be less likely to break things that worked
> before.  No?

Except that we're then accepting the (proven!) potential for data
loss. We're talking about a single report of an restore_command setting
odd permissions. Which can easily be fixed.  And the permission setting
already has downsides, e.g. for the switch between archive and streaming
recovery (which would fail).

Andres


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Robert Haas]

On Fri, May 27, 2016 at 8:44 PM, Andres Freund  wrote:
> I'm not convinced of that.  Hiding unexpected issues for longer, just to
> continue kind-of-operating, can make the impact of problems a lot worse,
> and it makes it very hard to actually learn about the issues.

So if we made this a WARNING rather than an ERROR, it wouldn't hiding
the issue, but it would be less likely to break things that worked
before.  No?

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Jeffrey.Marshall]

ccount which produces an error under 9.2.16).

Below are various strace outputs that were captured performing the database 
restores.  The exact same source files are used in both of the 9.2.X restores.  
I have 'grepped' out the rows for the RECOVERYXLOG file.  Going through the 
output, the open modes are different (0444 versus 0600) between 9.2 and 9.5 

9.2
open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0444) = 7

9.5
open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0600) = 4





9.2.15 backup/9.2.15 restore - successful

29262 stat("pg_xlog/RECOVERYXLOG", 0x7ffd91fc90b0) = -1 ENOENT (No such file or 
directory)
29263 execve("/bin/cp", ["cp", "/pgdata/postXX_walarchive/00"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
29263 stat("pg_xlog/RECOVERYXLOG", 0x7ffd8697d490) = -1 ENOENT (No such file or 
directory)
29263 stat("pg_xlog/RECOVERYXLOG", 0x7ffd8697d2b0) = -1 ENOENT (No such file or 
directory)
29263 open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0444) = 7
29262 stat("pg_xlog/RECOVERYXLOG", {st_mode=S_IFREG|0400, st_size=16777216, 
...}) = 0
29262 rename("pg_xlog/RECOVERYXLOG", "pg_xlog/000100050022" 

29262 stat("pg_xlog/RECOVERYXLOG", 0x7ffd91fc90e0) = -1 ENOENT (No such file or 
directory)
29266 execve("/bin/cp", ["cp", "/pgdata/postXX_walarchive/00"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
29266 stat("pg_xlog/RECOVERYXLOG", 0x7fff9ad125e0) = -1 ENOENT (No such file or 
directory)
29262 stat("pg_xlog/RECOVERYXLOG", 0x7ffd91fc90e0) = -1 ENOENT (No such file or 
directory)
29267 execve("/bin/cp", ["cp", "/pgdata/postXX_walarchive/00"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
29267 stat("pg_xlog/RECOVERYXLOG", 0x7fffca6281b0) = -1 ENOENT (No such file or 
directory)
29267 stat("pg_xlog/RECOVERYXLOG", 0x7fffca627fd0) = -1 ENOENT (No such file or 
directory)
29267 open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0444) = 13
29262 stat("pg_xlog/RECOVERYXLOG", {st_mode=S_IFREG|0400, st_size=16777216, 
...}) = 0
29262 rename("pg_xlog/RECOVERYXLOG", "pg_xlog/000100050022") = 0
29262 unlink("pg_xlog/RECOVERYXLOG")= -1 ENOENT (No such file or directory)


9.2.15 backup/9.2.16 restore - NOT successful


30153 stat("pg_xlog/RECOVERYXLOG", 0x7fff732488c0) = -1 ENOENT (No such file or 
directory)
30154 execve("/bin/cp", ["cp", "/pgdata/postXX_walarchive/00"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
30154 stat("pg_xlog/RECOVERYXLOG", 0x7ffd3c7a96b0) = -1 ENOENT (No such file or 
directory)
30154 stat("pg_xlog/RECOVERYXLOG", 0x7ffd3c7a94d0) = -1 ENOENT (No such file or 
directory)
30154 open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0444) = 7
30153 stat("pg_xlog/RECOVERYXLOG", {st_mode=S_IFREG|0400, st_size=16777216, 
...}) = 0
30153 open("pg_xlog/RECOVERYXLOG", O_RDWR) = -1 EACCES (Permission denied)



9.5.1 backup/9.5.2 restore - successful

24615 stat("pg_xlog/RECOVERYXLOG", 0x7fff3e2f8e60) = -1 ENOENT (No such file or 
directory)
24619 execve("/bin/cp", ["cp", "/pgdata/postXX_95_orig_wal/0"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
24619 stat("pg_xlog/RECOVERYXLOG", 0x7fffb2383ea0) = -1 ENOENT (No such file or 
directory)
24619 stat("pg_xlog/RECOVERYXLOG", 0x7fffb2383cc0) = -1 ENOENT (No such file or 
directory)
24619 open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0600) = 4
24615 stat("pg_xlog/RECOVERYXLOG", {st_mode=S_IFREG|0600, st_size=16777216, 
...}) = 0
24615 open("pg_xlog/RECOVERYXLOG", O_RDWR) = 3
24615 rename("pg_xlog/RECOVERYXLOG", "pg_xlog/00010049009A") = 0
24615 stat("pg_xlog/RECOVERYXLOG", 0x7fff3e2f8e80) = -1 ENOENT (No such file or 
directory)
24622 execve("/bin/cp", ["cp", "/pgdata/postXX_95_orig_wal/0"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
24622 stat("pg_xlog/RECOVERYXLOG", 0x7fffb1f62350) = -1 ENOENT (No such file or 
directory)
24615 stat("pg_xlog/RECOVERYXLOG", 0x7fff3e2f8e80) = -1 ENOENT (No such file or 
directory)
24623 execve("/bin/cp", ["cp", "/pgdata/postXX_95_orig_wal/0"..., 
"pg_xlog/RECOVERYXLOG"], [/* 60 vars */]) = 0
24623 stat("pg_xlog/RECOVERYXLOG", 0x7ffd4a373c40) = -1 ENOENT (No such file or 
directory)
24623 stat("pg_xlog/RECOVERYXLOG", 0x7ffd4a373a60) = -1 ENOENT (No such file or 
directory)
24623 open("pg_xlog/RECOVERYXLOG", O_WRONLY|O_CREAT|O_EXCL, 0600) = 7
24615 stat("pg_xlo

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Andres Freund]

On 2016-05-30 12:51:17 +0900, Michael Paquier wrote:
> On Sat, May 28, 2016 at 9:57 AM, Andres Freund  wrote:
> > On 2016-05-27 20:54:43 -0400, Tom Lane wrote:
> >> Andres Freund  writes:
> >> > On 2016-05-26 12:44:51 -0400, Tom Lane wrote:
> >> > 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  
> >> > 42501:
> >> > could not open file "pg_xlog/RECOVERYXLOG": Permission denied
> >>
> >> > So, what's the permission of RECOVERYXLOG at that point?  It's pretty
> >> > weird that directly after running reason_command it's not readable.
> >>
> >> s/not readable/not writable/.  I doubt that it's a good idea for that
> >> code to think that it can fail hard on non-writable files.
> >
> > But we actually sometimes write to files we've recovered; if they're the
> > end of the WAL after archive recovery and/or promotion. If a
> > restore_command restores files in a non-writable way it's buggy; I don't
> > see why it's worthwhile to work around that.
> 
> Not exactly, startup process does not write directly to the files of
> pg_xlog while in recovery.

It does at the end of crash recovery. And the wal receiver does so at
the end of archive recovery (which can repeatedly be reached).

- Andres


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Michael Paquier]

On Sat, May 28, 2016 at 9:57 AM, Andres Freund  wrote:
> On 2016-05-27 20:54:43 -0400, Tom Lane wrote:
>> Andres Freund  writes:
>> > On 2016-05-26 12:44:51 -0400, Tom Lane wrote:
>> > 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  
>> > 42501:
>> > could not open file "pg_xlog/RECOVERYXLOG": Permission denied
>>
>> > So, what's the permission of RECOVERYXLOG at that point?  It's pretty
>> > weird that directly after running reason_command it's not readable.
>>
>> s/not readable/not writable/.  I doubt that it's a good idea for that
>> code to think that it can fail hard on non-writable files.
>
> But we actually sometimes write to files we've recovered; if they're the
> end of the WAL after archive recovery and/or promotion. If a
> restore_command restores files in a non-writable way it's buggy; I don't
> see why it's worthwhile to work around that.

Not exactly, startup process does not write directly to the files of
pg_xlog while in recovery. Even with the current code, the first file
that needs to be writable is the first WAL segment of the new
timeline, which is made as a copy of the last partial segment of the
old timeline.

Anyway, I agree with Andres here. We had definitely better be sure
that durable_rename does fsync correctly the old and new entries when
doing a rename meaning that failing on EPERM is adapted, or we may
lose the rename in case of a crash, and data would be lost if the
rename was not seen as effective. And personally I am more worrying
about data losses than strangely designed restore_command scripts,
which is likely using sudo.
-- 
Michael


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Andres Freund]

On 2016-05-27 20:54:43 -0400, Tom Lane wrote:
> Andres Freund  writes:
> > On 2016-05-26 12:44:51 -0400, Tom Lane wrote:
> > 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  42501:
> > could not open file "pg_xlog/RECOVERYXLOG": Permission denied
> 
> > So, what's the permission of RECOVERYXLOG at that point?  It's pretty
> > weird that directly after running reason_command it's not readable.
> 
> s/not readable/not writable/.  I doubt that it's a good idea for that
> code to think that it can fail hard on non-writable files.

But we actually sometimes write to files we've recovered; if they're the
end of the WAL after archive recovery and/or promotion. If a
restore_command restores files in a non-writable way it's buggy; I don't
see why it's worthwhile to work around that.

Andres


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Tom Lane]

Andres Freund  writes:
> On 2016-05-26 12:44:51 -0400, Tom Lane wrote:
> 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  42501:
> could not open file "pg_xlog/RECOVERYXLOG": Permission denied

> So, what's the permission of RECOVERYXLOG at that point?  It's pretty
> weird that directly after running reason_command it's not readable.

s/not readable/not writable/.  I doubt that it's a good idea for that
code to think that it can fail hard on non-writable files.

regards, tom lane


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Andres Freund]

On 2016-05-26 12:44:51 -0400, Tom Lane wrote:
> > 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  42501:
> > could not open file "pg_xlog/RECOVERYXLOG": Permission denied

So, what's the permission of RECOVERYXLOG at that point?  It's pretty
weird that directly after running reason_command it's not readable. Are
you doing something involving sudo or such in restore_command?


> The proximate cause of this might just be that the "ignore_perm" exception
> is only for EACCES and not EPERM (why?).

I essentially just copied your logic from d8179b001ae574da00c8 ff.


> In general, though, it seems to
> me that the durable_rename patch has introduced a whole lot of new failure
> conditions that were not there before, for IMO very little reason.

Uh. Like provably loosing data after crashes?


> I think we would be better off fixing those functions so that there is
> *no* case other than failure of the rename() or link() call itself that
> will be treated as a hard error.  Blowing up completely is not an
> improvement over not fsyncing.

I'm not convinced of that.  Hiding unexpected issues for longer, just to
continue kind-of-operating, can make the impact of problems a lot worse,
and it makes it very hard to actually learn about the issues.

Andres


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] [GENERAL] Permission Denied Error on pg_xlog/RECOVERYXLOG file

[Tom Lane]

[ redirecting to -hackers ]

 writes:
> When performing a vanilla database restore using either the 9.2.16 or 9.2.17 
> executables (i.e. just restoring the database files from a 'tar' backup and 
> reading the WAL files created during the 'tar' backup - no specific PIT given 
> in recovery.conf) the database server will abort with a permission denied 
> error on the pg_xlog/RECOVERYXLOG file.  The error occurred restoring both 
> backups that were made under the current version (9.2.16 and 9.2.17) as well 
> as backups made under prior versions (9.2.15 at least).  The exact same 
> restore process/backup files can be used to successfully restore the database 
> using the 9.2.15 executables, but fail when using either 9.2.16 or 9.2.17 
> with the permission denied error.

There were not very many changes between 9.2.15 and 9.2.16.  Between that
and the location of the error:

> 2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL:  42501:
> could not open file "pg_xlog/RECOVERYXLOG": Permission denied
> 2016-04-27 17:02:06 EDT 572128cd.1811 [8-1] user=,db=,remote= LOCATION:
> fsync_fname_ext, fd.c:2654

I feel pretty confident in blaming this on the "durable_rename" patch.

The proximate cause of this might just be that the "ignore_perm" exception
is only for EACCES and not EPERM (why?).  In general, though, it seems to
me that the durable_rename patch has introduced a whole lot of new failure
conditions that were not there before, for IMO very little reason.
I think we would be better off fixing those functions so that there is
*no* case other than failure of the rename() or link() call itself that
will be treated as a hard error.  Blowing up completely is not an
improvement over not fsyncing.

regards, tom lane


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers