Thread: [ADMIN] Strange times in WAL files in archive directory (9.3)
Hello, we are running PostgreSQL 9.3 on a new VM running Linux 3.16.0-4-amd64 #1 SMP, Debian 8.6, and we setup WAL archiving yesterday.We were planing to keep a window of 15 days worth of WAL files, so we thought of writing a script to delete files older than 15 days. The settings used were rather common : archive_mode = on archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' archive_timeout=240 However, this morning, to my surprise I saw this by doing ls on the archive directory : # ls -l /smadb/pgsql/pitr/ | less total 12680296 -rw------- 1 postgres postgres 16777216 Jan 24 03:44 000000020000070100000000 -rw------- 1 postgres postgres 16777216 Jan 24 03:50 000000020000070100000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:54 000000020000070100000002 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000003 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000004 -rw------- 1 postgres postgres 16777216 Jan 24 04:04 000000020000070100000005 -rw------- 1 postgres postgres 16777216 Jan 24 04:09 000000020000070100000006 -rw------- 1 postgres postgres 16777216 Jan 24 04:14 000000020000070100000007 -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000008 -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000009 -rw------- 1 postgres postgres 16777216 Jan 24 04:25 00000002000007010000000A -rw------- 1 postgres postgres 16777216 Jan 24 04:29 00000002000007010000000B -rw------- 1 postgres postgres 16777216 Jan 24 04:34 00000002000007010000000C -rw------- 1 postgres postgres 16777216 Jan 24 04:39 00000002000007010000000D -rw------- 1 postgres postgres 16777216 Jan 24 04:39 00000002000007010000000E -rw------- 1 postgres postgres 16777216 Jan 24 04:44 00000002000007010000000F ........... -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F1 <------ -rw------- 1 postgres postgres 16777216 Jan 23 13:04 0000000200000701000000F2 <------ time jumps -rw------- 1 postgres postgres 16777216 Jan 23 13:05 0000000200000701000000F3 -rw------- 1 postgres postgres 16777216 Jan 23 13:06 0000000200000701000000F4 So IMHO either the naming of the WAL filename got damaged somehow or the one of the servers got wrong time or something Imiss. "Jan 23 13:04" is indeed the time that we started the server for WAL archiving. By sorting by time I get : ls -ltr /smadb/pgsql/pitr/ | less -rw------- 1 postgres postgres 16777216 Jan 23 13:04 0000000200000701000000F2 -rw------- 1 postgres postgres 16777216 Jan 23 13:05 0000000200000701000000F3 -rw------- 1 postgres postgres 16777216 Jan 23 13:06 0000000200000701000000F4 -rw------- 1 postgres postgres 16777216 Jan 23 13:07 0000000200000701000000F5 -rw------- 1 postgres postgres 16777216 Jan 23 13:08 0000000200000701000000F6 -rw------- 1 postgres postgres 16777216 Jan 23 13:09 0000000200000701000000F7 -rw------- 1 postgres postgres 16777216 Jan 23 13:09 0000000200000701000000F8 -rw------- 1 postgres postgres 16777216 Jan 23 13:10 0000000200000701000000F9 -rw------- 1 postgres postgres 16777216 Jan 23 13:11 0000000200000701000000FA -rw------- 1 postgres postgres 16777216 Jan 23 13:12 0000000200000701000000FB -rw------- 1 postgres postgres 16777216 Jan 23 13:13 0000000200000701000000FC ........ -rw------- 1 postgres postgres 16777216 Jan 24 03:15 0000000200000702000000F9 -rw------- 1 postgres postgres 16777216 Jan 24 03:19 0000000200000702000000FA -rw------- 1 postgres postgres 16777216 Jan 24 03:23 0000000200000702000000FB -rw------- 1 postgres postgres 16777216 Jan 24 03:27 0000000200000702000000FC -rw------- 1 postgres postgres 16777216 Jan 24 03:31 0000000200000702000000FD -rw------- 1 postgres postgres 16777216 Jan 24 03:35 0000000200000702000000FE -rw------- 1 postgres postgres 16777216 Jan 24 03:39 0000000200000702000000FF -rw------- 1 postgres postgres 16777216 Jan 24 03:43 000000020000070300000000 -rw------- 1 postgres postgres 16777216 Jan 24 03:44 000000020000070100000000 <----- problem begins -rw------- 1 postgres postgres 16777216 Jan 24 03:47 000000020000070300000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:50 000000020000070100000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:51 000000020000070300000002 -rw------- 1 postgres postgres 16777216 Jan 24 03:54 000000020000070100000002 ........ (same pattern goes on 0000000200000703 mixing with 0000000200000701 ) -rw------- 1 postgres postgres 16777216 Jan 24 09:42 0000000200000701000000EE -rw------- 1 postgres postgres 16777216 Jan 24 09:45 0000000200000703000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:47 0000000200000703000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000703000000F1 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F1 <----- problem ends -rw------- 1 postgres postgres 16777216 Jan 24 09:50 0000000200000703000000F2 -rw------- 1 postgres postgres 16777216 Jan 24 09:52 0000000200000703000000F3 -rw------- 1 postgres postgres 16777216 Jan 24 09:56 0000000200000703000000F4 Any thoughts about any explanation on this? -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
On 24/01/2017 11:12, Achilleas Mantzios wrote: > Hello, > we are running PostgreSQL 9.3 on a new VM running Linux 3.16.0-4-amd64 #1 SMP, Debian 8.6, and we setup WAL archiving yesterday.We were planing to keep a window of 15 days worth of WAL files, so we > thought of writing a script to delete files older than 15 days. The settings used were rather common : > archive_mode = on > archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' > archive_timeout=240 > However, this morning, to my surprise I saw this by doing ls on the archive directory : > # ls -l /smadb/pgsql/pitr/ | less > total 12680296 > -rw------- 1 postgres postgres 16777216 Jan 24 03:44 000000020000070100000000 > -rw------- 1 postgres postgres 16777216 Jan 24 03:50 000000020000070100000001 > -rw------- 1 postgres postgres 16777216 Jan 24 03:54 000000020000070100000002 > -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000003 > -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000004 > -rw------- 1 postgres postgres 16777216 Jan 24 04:04 000000020000070100000005 > -rw------- 1 postgres postgres 16777216 Jan 24 04:09 000000020000070100000006 > -rw------- 1 postgres postgres 16777216 Jan 24 04:14 000000020000070100000007 > -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000008 > -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000009 > -rw------- 1 postgres postgres 16777216 Jan 24 04:25 00000002000007010000000A > -rw------- 1 postgres postgres 16777216 Jan 24 04:29 00000002000007010000000B > -rw------- 1 postgres postgres 16777216 Jan 24 04:34 00000002000007010000000C > -rw------- 1 postgres postgres 16777216 Jan 24 04:39 00000002000007010000000D > -rw------- 1 postgres postgres 16777216 Jan 24 04:39 00000002000007010000000E > -rw------- 1 postgres postgres 16777216 Jan 24 04:44 00000002000007010000000F > ........... > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000EF > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F0 > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F1 <------ > -rw------- 1 postgres postgres 16777216 Jan 23 13:04 0000000200000701000000F2 <------ time jumps > -rw------- 1 postgres postgres 16777216 Jan 23 13:05 0000000200000701000000F3 > -rw------- 1 postgres postgres 16777216 Jan 23 13:06 0000000200000701000000F4 > > So IMHO either the naming of the WAL filename got damaged somehow or the one of the servers got wrong time or somethingI miss. "Jan 23 13:04" is indeed the time that we started the server for WAL > archiving. > By sorting by time I get : > ls -ltr /smadb/pgsql/pitr/ | less > -rw------- 1 postgres postgres 16777216 Jan 23 13:04 0000000200000701000000F2 > -rw------- 1 postgres postgres 16777216 Jan 23 13:05 0000000200000701000000F3 > -rw------- 1 postgres postgres 16777216 Jan 23 13:06 0000000200000701000000F4 > -rw------- 1 postgres postgres 16777216 Jan 23 13:07 0000000200000701000000F5 > -rw------- 1 postgres postgres 16777216 Jan 23 13:08 0000000200000701000000F6 > -rw------- 1 postgres postgres 16777216 Jan 23 13:09 0000000200000701000000F7 > -rw------- 1 postgres postgres 16777216 Jan 23 13:09 0000000200000701000000F8 > -rw------- 1 postgres postgres 16777216 Jan 23 13:10 0000000200000701000000F9 > -rw------- 1 postgres postgres 16777216 Jan 23 13:11 0000000200000701000000FA > -rw------- 1 postgres postgres 16777216 Jan 23 13:12 0000000200000701000000FB > -rw------- 1 postgres postgres 16777216 Jan 23 13:13 0000000200000701000000FC > ........ > -rw------- 1 postgres postgres 16777216 Jan 24 03:15 0000000200000702000000F9 > -rw------- 1 postgres postgres 16777216 Jan 24 03:19 0000000200000702000000FA > -rw------- 1 postgres postgres 16777216 Jan 24 03:23 0000000200000702000000FB > -rw------- 1 postgres postgres 16777216 Jan 24 03:27 0000000200000702000000FC > -rw------- 1 postgres postgres 16777216 Jan 24 03:31 0000000200000702000000FD > -rw------- 1 postgres postgres 16777216 Jan 24 03:35 0000000200000702000000FE > -rw------- 1 postgres postgres 16777216 Jan 24 03:39 0000000200000702000000FF > -rw------- 1 postgres postgres 16777216 Jan 24 03:43 000000020000070300000000 > -rw------- 1 postgres postgres 16777216 Jan 24 03:44 000000020000070100000000 <----- problem begins > -rw------- 1 postgres postgres 16777216 Jan 24 03:47 000000020000070300000001 > -rw------- 1 postgres postgres 16777216 Jan 24 03:50 000000020000070100000001 > -rw------- 1 postgres postgres 16777216 Jan 24 03:51 000000020000070300000002 > -rw------- 1 postgres postgres 16777216 Jan 24 03:54 000000020000070100000002 > ........ (same pattern goes on 0000000200000703 mixing with 0000000200000701 ) > -rw------- 1 postgres postgres 16777216 Jan 24 09:42 0000000200000701000000EE > -rw------- 1 postgres postgres 16777216 Jan 24 09:45 0000000200000703000000EF > -rw------- 1 postgres postgres 16777216 Jan 24 09:47 0000000200000703000000F0 > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000703000000F1 > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000EF > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F0 > -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F1 <----- problem ends > -rw------- 1 postgres postgres 16777216 Jan 24 09:50 0000000200000703000000F2 > -rw------- 1 postgres postgres 16777216 Jan 24 09:52 0000000200000703000000F3 > -rw------- 1 postgres postgres 16777216 Jan 24 09:56 0000000200000703000000F4 > > Any thoughts about any explanation on this? > By scrolling up the terminal on the database server (cause the said file is gone now from pg_xlog) I saw this : $ ls -ltr ~/data/pg_xlog/0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 23 13:01 /var/lib/pgsql/data/pg_xlog/0000000200000701000000F0 $ md5sum ~/data/pg_xlog/0000000200000701000000F0 8ce1917c86d3c9e41455ec13659c2689 /var/lib/pgsql/data/pg_xlog/0000000200000701000000F0 In the archive's host I see this : # ls -ltr /smadb/pgsql/pitr/0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 /smadb/pgsql/pitr/0000000200000701000000F0 # md5sum /smadb/pgsql/pitr/0000000200000701000000F0 8ce1917c86d3c9e41455ec13659c2689 /smadb/pgsql/pitr/0000000200000701000000F0 Same file, different mod times, so, this makes me think that maybe there was some flushing that the postgresql server did,prior to deleting or recycling some old WAL files. Also I see this : # ls -ltr /smadb/pgsql/pitr/0000000200000701000000* -rw------- 1 postgres postgres 16777216 Jan 23 13:04 /smadb/pgsql/pitr/0000000200000701000000F2 -rw------- 1 postgres postgres 16777216 Jan 23 13:05 /smadb/pgsql/pitr/0000000200000701000000F3 -rw------- 1 postgres postgres 16777216 Jan 23 13:06 /smadb/pgsql/pitr/0000000200000701000000F4 -rw------- 1 postgres postgres 16777216 Jan 23 13:07 /smadb/pgsql/pitr/0000000200000701000000F5 -rw------- 1 postgres postgres 16777216 Jan 23 13:08 /smadb/pgsql/pitr/0000000200000701000000F6 -rw------- 1 postgres postgres 16777216 Jan 23 13:09 /smadb/pgsql/pitr/0000000200000701000000F7 -rw------- 1 postgres postgres 16777216 Jan 23 13:09 /smadb/pgsql/pitr/0000000200000701000000F8 -rw------- 1 postgres postgres 16777216 Jan 23 13:10 /smadb/pgsql/pitr/0000000200000701000000F9 -rw------- 1 postgres postgres 16777216 Jan 23 13:11 /smadb/pgsql/pitr/0000000200000701000000FA -rw------- 1 postgres postgres 16777216 Jan 23 13:12 /smadb/pgsql/pitr/0000000200000701000000FB -rw------- 1 postgres postgres 16777216 Jan 23 13:13 /smadb/pgsql/pitr/0000000200000701000000FC -rw------- 1 postgres postgres 16777216 Jan 23 13:14 /smadb/pgsql/pitr/0000000200000701000000FD -rw------- 1 postgres postgres 16777216 Jan 23 13:15 /smadb/pgsql/pitr/0000000200000701000000FE -rw------- 1 postgres postgres 16777216 Jan 23 13:16 /smadb/pgsql/pitr/0000000200000701000000FF -rw------- 1 postgres postgres 16777216 Jan 24 03:44 /smadb/pgsql/pitr/000000020000070100000000 <---- time jump -rw------- 1 postgres postgres 16777216 Jan 24 03:50 /smadb/pgsql/pitr/000000020000070100000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:54 /smadb/pgsql/pitr/000000020000070100000002 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 /smadb/pgsql/pitr/000000020000070100000003 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 /smadb/pgsql/pitr/000000020000070100000004 ...... -rw------- 1 postgres postgres 16777216 Jan 24 09:42 /smadb/pgsql/pitr/0000000200000701000000EE -rw------- 1 postgres postgres 16777216 Jan 24 09:48 /smadb/pgsql/pitr/0000000200000701000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:48 /smadb/pgsql/pitr/0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 /smadb/pgsql/pitr/0000000200000701000000F1 So this makes me believe that all the files before 0000000200000701000000F2 were present before WAL archiving was setup.So I want to ask : 1) Do you find this behavior normal? 2) From now on, can we assume a monotonic relation between file names and creation times in order to base our maintenancescripts on this? -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
Achilleas Mantzios <achill@matrix.gatewaynet.com> writes:
> 1) Do you find this behavior normal?
It's normal operation. Once a WAL file is not needed anymore, it's
typically renamed into place to be a future WAL file; that's cheaper
than deleting the file and creating/filling a new one. So those ones
that have older timestamps do not contain useful data right this instant,
but they're ready to accept data once the write pointer advances to them.
> 2) From now on, can we assume a monotonic relation between file names and creation times in order to base our
maintenancescripts on this?
I wouldn't. You risk deleting a file just as it starts to be used.
You could possibly look into pg_control to see the current LSN and
avoid touching any files >= that point, but of course this complicates
the maintenance logic quite a bit.
The larger issue here is that you're confusing the function of an archive
area with that of the active WAL directory. The server will prune what is
in the active WAL directory and does not want your help. In an archive
directory, I'd expect the files to have monotonic timestamps corresponding
to the times you copied them over to the archive, so you could rely on
the timestamp sequence there.
regards, tom lane
Hi Achilleas, On 1/24/17 8:29 AM, Tom Lane wrote: > Achilleas Mantzios <achill@matrix.gatewaynet.com> writes: > >> 2) From now on, can we assume a monotonic relation between file names and creation times in order to base our maintenancescripts on this? > > I wouldn't. You risk deleting a file just as it starts to be used. > You could possibly look into pg_control to see the current LSN and > avoid touching any files >= that point, but of course this complicates > the maintenance logic quite a bit. > > The larger issue here is that you're confusing the function of an archive > area with that of the active WAL directory. The server will prune what is > in the active WAL directory and does not want your help. In an archive > directory, I'd expect the files to have monotonic timestamps corresponding > to the times you copied them over to the archive, so you could rely on > the timestamp sequence there. Agreed, that should work. However, this just the beginning of the complexities you will encounter when dealing with WAL archiving and expiration. You should consider using a mature third-party solution like pgBackRest or Barman. -- -David david@pgmasters.net
Hi Tom, On 24/01/2017 15:29, Tom Lane wrote: > The larger issue here is that you're confusing the function of an archive area with that of the active WAL directory. Theserver will prune what is in the active WAL directory and does not want your > help. In an archive directory, I'd expect the files to have monotonic timestamps corresponding to the times you copiedthem over to the archive, so you could rely on the timestamp sequence there. > regards, tom lane I would be silly to mess around with pg_xlog. I was talking about the archive directory. *There* is where I noticed the inconsistencies.In my second post in this thread I used pg_xlog to show the difference in timestamp of the same md5-wise files between the two systems (pg_xlog vs archive dir). -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
Achilleas Mantzios <achill@matrix.gatewaynet.com> writes:
> On 24/01/2017 15:29, Tom Lane wrote:
>> The larger issue here is that you're confusing the function of an archive area with that of the active WAL
directory.The server will prune what is in the active WAL directory and does not want your
>> help. In an archive directory, I'd expect the files to have monotonic timestamps corresponding to the times you
copiedthem over to the archive, so you could rely on the timestamp sequence there.
> I would be silly to mess around with pg_xlog. I was talking about the
> archive directory. *There* is where I noticed the inconsistencies.
If you copied the files to the archive directory when the server told you
they were ready, it should be impossible for them to have non-sequential
timestamps. I'm wondering if you tried to short-circuit that, perhaps
by hard-linking them instead of copying. That won't work at all, since
the server will reuse (overwrite) the files once it thinks you've
copied them.
regards, tom lane
On 24/01/2017 16:14, Tom Lane wrote:
I provided the archive_command in the 1st post. The copy is against another host (called sma in the command) :Achilleas Mantzios <achill@matrix.gatewaynet.com> writes:On 24/01/2017 15:29, Tom Lane wrote:The larger issue here is that you're confusing the function of an archive area with that of the active WAL directory. The server will prune what is in the active WAL directory and does not want your help. In an archive directory, I'd expect the files to have monotonic timestamps corresponding to the times you copied them over to the archive, so you could rely on the timestamp sequence there.I would be silly to mess around with pg_xlog. I was talking about the archive directory. *There* is where I noticed the inconsistencies.If you copied the files to the archive directory when the server told you they were ready, it should be impossible for them to have non-sequential timestamps. I'm wondering if you tried to short-circuit that, perhaps by hard-linking them instead of copying. That won't work at all, since the server will reuse (overwrite) the files once it thinks you've copied them.
archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f'
I didn't do any scp by hand. My suspicion is that PostreSQL (before recycling them) just flushed via the archive command those files which were created before PITR was setup, i.e. before the server was restarted to begin WAL archiving. The timestamps observed on the sequence of files make me believe so.
First thing this morning, by seeing that, made me skeptical of whether the obvious assumption on the monotonicity between filenames/tiemstamps is valid. However for the last 7 hours (after the last file with the *oldish* filenames was written) I have not witnessed anything weird.
regards, tom lane
-- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
Greetings, * Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: > I provided the archive_command in the 1st post. The copy is against another host (called sma in the command) : > archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' Note that this is not a recommended archive command- there is no guarantee that the copied WAL files are sync'd to disk on the 'sma' host and you could end up losing, potentially, a significant amount of your WAL on a failure. It's also, sadly, quite slow, with no way to be parallelized (PG will not start a new archive_command until the prior one completes, meaning that you could end up with a large backlog of un-archived WAL if the archive_command can't keep up, potentially leading to an out-of-space situation on your WAL filesystem, leading to a PANIC and crash). There's also no compression with the proposed approach (in transit or at rest). Some of this is fixable with SSH (using ControlMaster, adding compression options, though that would only compress in transit, not on disk; if you wanted on-disk compression then you'd have to re-compress it again), but not all of it (you aren't going to get scp to fsync the WAL on the remote side, at least not by itself), but as noted by David already, using a third-party solution which has addressed all of these issues is really a better option than hand-rolling your own system. Thanks! Stephen
Attachment
On 24/01/2017 16:55, Stephen Frost wrote: > Greetings, > > * Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: >> I provided the archive_command in the 1st post. The copy is against another host (called sma in the command) : >> archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' > Note that this is not a recommended archive command- there is no > guarantee that the copied WAL files are sync'd to disk on the 'sma' host > and you could end up losing, potentially, a significant amount of your > WAL on a failure. I had changed that already to /usr/bin/rsync -a --ignore-existing %p sma:/smadb/pgsql/pitr/%f So you say that scp does not perform a sync on the destination file? So that in case of a remote crash it might return 0while the file isn't written? > > It's also, sadly, quite slow, with no way to be parallelized (PG will > not start a new archive_command until the prior one completes, meaning > that you could end up with a large backlog of un-archived WAL if the > archive_command can't keep up, potentially leading to an out-of-space > situation on your WAL filesystem, leading to a PANIC and crash). > > There's also no compression with the proposed approach (in transit or at > rest). > > Some of this is fixable with SSH (using ControlMaster, adding > compression options, though that would only compress in transit, not on > disk; if you wanted on-disk compression then you'd have to re-compress > it again), but not all of it (you aren't going to get scp to fsync the > WAL on the remote side, at least not by itself), but as noted by David > already, using a third-party solution which has addressed all of these > issues is really a better option than hand-rolling your own system. Thanks for the suggestions. We have been using a wal archiving + base backups + streaming replication combination for years,so I guess we'll be alright for the time being. Point is that we recently moved to a cloud environment and we have to "port" our traditional operations to the utilities/tools provided by the cloudprovider. Anyway, if there is any theory or confirmation on my assumptions for the main question of this thread? > Thanks! > > Stephen -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
Greetings, * Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: > On 24/01/2017 16:55, Stephen Frost wrote: > >* Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: > >>I provided the archive_command in the 1st post. The copy is against another host (called sma in the command) : > >>archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' > >Note that this is not a recommended archive command- there is no > >guarantee that the copied WAL files are sync'd to disk on the 'sma' host > >and you could end up losing, potentially, a significant amount of your > >WAL on a failure. > I had changed that already to > /usr/bin/rsync -a --ignore-existing %p sma:/smadb/pgsql/pitr/%f --ignore-existing is actually a *bad* idea, really. There can be cases where PG will end up calling archive_command on the same file, but in those cases you should really be checking that the two WAL files are IDENTICAL, otherwise you may have a misconfigured system and are pushing the WAL for two different PG systems to the same directory. > So you say that scp does not perform a sync on the destination file? So that in case of a remote crash it might return0 while the file isn't written? Yes, if the remote system crashes right after rsync (or scp) has returned, the WAL file may not have been sync'd to reliable storage and will be lost. > Thanks for the suggestions. We have been using a wal archiving + > base backups + streaming replication combination for years, so I > guess we'll be alright for the time being. Point is that we recently > moved to a cloud environment and we have to "port" our traditional > operations to the utilities/tools provided by the cloud provider. I would not go on the assumption that since it's been working that it won't ever fail in an unfortunate way. Also, always, always, always test your backups. All of them, ideally, otherwise they may not work when you need them most. > Anyway, if there is any theory or confirmation on my assumptions for the main question of this thread? At first blush, I'd guess that someone else put those files there or that the time changed on one of the systems involved. Thanks! Stephen
Attachment
On 24/01/2017 17:55, Stephen Frost wrote: > Greetings, > > * Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: >> On 24/01/2017 16:55, Stephen Frost wrote: >>> * Achilleas Mantzios (achill@matrix.gatewaynet.com) wrote: >>>> I provided the archive_command in the 1st post. The copy is against another host (called sma in the command) : >>>> archive_command = '/usr/bin/scp %p sma:/smadb/pgsql/pitr/%f' >>> Note that this is not a recommended archive command- there is no >>> guarantee that the copied WAL files are sync'd to disk on the 'sma' host >>> and you could end up losing, potentially, a significant amount of your >>> WAL on a failure. >> I had changed that already to >> /usr/bin/rsync -a --ignore-existing %p sma:/smadb/pgsql/pitr/%f > --ignore-existing is actually a *bad* idea, really. There can be cases > where PG will end up calling archive_command on the same file, but in > those cases you should really be checking that the two WAL files are > IDENTICAL, otherwise you may have a misconfigured system and are pushing > the WAL for two different PG systems to the same directory. > >> So you say that scp does not perform a sync on the destination file? So that in case of a remote crash it might return0 while the file isn't written? > Yes, if the remote system crashes right after rsync (or scp) has > returned, the WAL file may not have been sync'd to reliable storage and > will be lost. > >> Thanks for the suggestions. We have been using a wal archiving + >> base backups + streaming replication combination for years, so I >> guess we'll be alright for the time being. Point is that we recently >> moved to a cloud environment and we have to "port" our traditional >> operations to the utilities/tools provided by the cloud provider. > I would not go on the assumption that since it's been working that it > won't ever fail in an unfortunate way. > > Also, always, always, always test your backups. All of them, ideally, > otherwise they may not work when you need them most. > >> Anyway, if there is any theory or confirmation on my assumptions for the main question of this thread? > At first blush, I'd guess that someone else put those files there or > that the time changed on one of the systems involved. No one else worked on this, and ntp has been running correctly for both systems. This was my first guess as well but no. I guess PostgreSQL just flushed them to the archive before deleting/renaming them. Does it make any sense? > > Thanks! > > Stephen -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt
Just an observation on this. By looking at the timestamps of the files I see a pattern : -rw------- 1 postgres postgres 16777216 Jan 23 13:04 0000000200000701000000F2 -rw------- 1 postgres postgres 16777216 Jan 23 13:05 0000000200000701000000F3 -rw------- 1 postgres postgres 16777216 Jan 23 13:06 0000000200000701000000F4 -rw------- 1 postgres postgres 16777216 Jan 23 13:07 0000000200000701000000F5 -rw------- 1 postgres postgres 16777216 Jan 23 13:08 0000000200000701000000F6 -rw------- 1 postgres postgres 16777216 Jan 23 13:09 0000000200000701000000F7 ..... -rw------- 1 postgres postgres 16777216 Jan 24 03:07 0000000200000702000000F7 -rw------- 1 postgres postgres 16777216 Jan 24 03:11 0000000200000702000000F8 -rw------- 1 postgres postgres 16777216 Jan 24 03:15 0000000200000702000000F9 -rw------- 1 postgres postgres 16777216 Jan 24 03:19 0000000200000702000000FA -rw------- 1 postgres postgres 16777216 Jan 24 03:23 0000000200000702000000FB -rw------- 1 postgres postgres 16777216 Jan 24 03:27 0000000200000702000000FC -rw------- 1 postgres postgres 16777216 Jan 24 03:31 0000000200000702000000FD -rw------- 1 postgres postgres 16777216 Jan 24 03:35 0000000200000702000000FE -rw------- 1 postgres postgres 16777216 Jan 24 03:39 0000000200000702000000FF -rw------- 1 postgres postgres 16777216 Jan 24 03:43 000000020000070300000000 -rw------- 1 postgres postgres 16777216 Jan 24 03:44 000000020000070100000000 <---- logno >> 32 == 701 file appears, nowstarts the pattern -rw------- 1 postgres postgres 16777216 Jan 24 03:47 000000020000070300000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:50 000000020000070100000001 -rw------- 1 postgres postgres 16777216 Jan 24 03:51 000000020000070300000002 -rw------- 1 postgres postgres 16777216 Jan 24 03:54 000000020000070100000002 -rw------- 1 postgres postgres 16777216 Jan 24 03:55 000000020000070300000003 -rw------- 1 postgres postgres 16777216 Jan 24 03:59 000000020000070300000004 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000003 -rw------- 1 postgres postgres 16777216 Jan 24 04:00 000000020000070100000004 -rw------- 1 postgres postgres 16777216 Jan 24 04:03 000000020000070300000005 -rw------- 1 postgres postgres 16777216 Jan 24 04:04 000000020000070100000005 -rw------- 1 postgres postgres 16777216 Jan 24 04:07 000000020000070300000006 -rw------- 1 postgres postgres 16777216 Jan 24 04:09 000000020000070100000006 -rw------- 1 postgres postgres 16777216 Jan 24 04:11 000000020000070300000007 -rw------- 1 postgres postgres 16777216 Jan 24 04:14 000000020000070100000007 -rw------- 1 postgres postgres 16777216 Jan 24 04:15 000000020000070300000008 -rw------- 1 postgres postgres 16777216 Jan 24 04:19 000000020000070300000009 -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000008 -rw------- 1 postgres postgres 16777216 Jan 24 04:20 000000020000070100000009 -rw------- 1 postgres postgres 16777216 Jan 24 04:23 00000002000007030000000A ...... -rw------- 1 postgres postgres 16777216 Jan 24 04:43 00000002000007030000000F -rw------- 1 postgres postgres 16777216 Jan 24 04:44 00000002000007010000000F -rw------- 1 postgres postgres 16777216 Jan 24 04:47 000000020000070300000010 -rw------- 1 postgres postgres 16777216 Jan 24 04:50 000000020000070100000010 -rw------- 1 postgres postgres 16777216 Jan 24 04:51 000000020000070300000011 -rw------- 1 postgres postgres 16777216 Jan 24 04:55 000000020000070300000012 -rw------- 1 postgres postgres 16777216 Jan 24 04:56 000000020000070100000011 -rw------- 1 postgres postgres 16777216 Jan 24 04:56 000000020000070100000012 -rw------- 1 postgres postgres 16777216 Jan 24 04:59 000000020000070300000013 -rw------- 1 postgres postgres 16777216 Jan 24 04:59 000000020000070100000013 -rw------- 1 postgres postgres 16777216 Jan 24 05:01 000000020000070300000014 -rw------- 1 postgres postgres 16777216 Jan 24 05:02 000000020000070300000015 -rw------- 1 postgres postgres 16777216 Jan 24 05:04 000000020000070300000016 -rw------- 1 postgres postgres 16777216 Jan 24 05:05 000000020000070300000017 -rw------- 1 postgres postgres 16777216 Jan 24 05:07 000000020000070300000018 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070300000019 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000015 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000014 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000016 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000017 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000018 -rw------- 1 postgres postgres 16777216 Jan 24 05:08 000000020000070100000019 -rw------- 1 postgres postgres 16777216 Jan 24 05:09 00000002000007030000001A -rw------- 1 postgres postgres 16777216 Jan 24 05:09 00000002000007030000001B -rw------- 1 postgres postgres 16777216 Jan 24 05:10 00000002000007030000001C -rw------- 1 postgres postgres 16777216 Jan 24 05:10 00000002000007030000001D -rw------- 1 postgres postgres 16777216 Jan 24 05:10 00000002000007030000001E -rw------- 1 postgres postgres 16777216 Jan 24 05:11 00000002000007030000001F -rw------- 1 postgres postgres 16777216 Jan 24 05:11 000000020000070300000020 -rw------- 1 postgres postgres 16777216 Jan 24 05:12 000000020000070300000021 -rw------- 1 postgres postgres 16777216 Jan 24 05:12 000000020000070300000022 -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001E -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001A -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001B -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001C -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001D -rw------- 1 postgres postgres 16777216 Jan 24 05:12 00000002000007010000001F -rw------- 1 postgres postgres 16777216 Jan 24 05:12 000000020000070100000020 -rw------- 1 postgres postgres 16777216 Jan 24 05:12 000000020000070100000021 -rw------- 1 postgres postgres 16777216 Jan 24 05:12 000000020000070100000022 it is pretty obvious that the current logno % (2^32) = 703, and for every 703-named file that is archived, wal archiver triesto also archive all the unarchived files with filename of logno % (2^32) - 2 = 701. I should have kept a snapshot of data/pg_xlog/archive_status/ as well, unfortunately I didn't. I didn't have time to lookthoroughly into the sources or even try to reproduce via gdb. Hope this helps a little bit. I want to clarify once more than the pattern stopped after the last unarchived 701-file :0000000200000701000000F1 was archived. 0000000200000701000000F2 was already archived, actually was the very first file to be archived as shown at the top of this mail. : -rw------- 1 postgres postgres 16777216 Jan 24 09:45 0000000200000703000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:47 0000000200000703000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000703000000F1 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000EF -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F0 -rw------- 1 postgres postgres 16777216 Jan 24 09:48 0000000200000701000000F1 <-- here -rw------- 1 postgres postgres 16777216 Jan 24 09:50 0000000200000703000000F2 -rw------- 1 postgres postgres 16777216 Jan 24 09:52 0000000200000703000000F3 -rw------- 1 postgres postgres 16777216 Jan 24 09:56 0000000200000703000000F4 -rw------- 1 postgres postgres 16777216 Jan 24 09:59 0000000200000703000000F5 -rw------- 1 postgres postgres 16777216 Jan 24 10:03 0000000200000703000000F6 -rw------- 1 postgres postgres 16777216 Jan 24 10:07 0000000200000703000000F7 -rw------- 1 postgres postgres 16777216 Jan 24 10:11 0000000200000703000000F8 -rw------- 1 postgres postgres 16777216 Jan 24 10:14 0000000200000703000000F9 -rw------- 1 postgres postgres 16777216 Jan 24 10:17 0000000200000703000000FA -rw------- 1 postgres postgres 16777216 Jan 24 10:20 0000000200000703000000FB -- Achilleas Mantzios IT DEV Lead IT DEPT Dynacom Tankers Mgmt