Thread: Does my pg_xlog directory look right?
Hey all,
My pg_xlog directory looks kind of messed up. Specifically:
1) There's more segment files than I would expect;
2) Segment files appear to be out of order with respect to filename and timestamp
System info:
--------------
OS: Ubuntu 14.04 Linux 3.13.0-83-generic
PG Version: 9.3.11
- I have streaming replication set up to one remote, and am archiving to another remote.
postgresql.conf
--------------
wal_level = hot_standby
checkpoint_segments = 32
checkpoint_completion_target = 0.7
archive_mode = on
archive_command = 'rsync -a %p user@host:/dir/to/barman/main/incoming/%f'
wal_keep_segments = 32
Here is an `ls -l` of the xlog directory:
-rw------- 1 postgres postgres 43 Oct 10 2014 00000002.history
-rw------- 1 postgres postgres 43 Oct 10 2014 00000003.history
-rw------- 1 postgres postgres 43 Mar 9 2015 00000004.history
-rw------- 1 postgres postgres 87 Mar 10 2015 00000005.history
-rw------- 1 postgres postgres 131 Aug 16 2015 00000006.history
-rw------- 1 postgres postgres 175 Aug 17 2015 00000007.history
-rw------- 1 postgres postgres 220 Dec 20 09:17 00000008.history
-rw------- 1 postgres postgres 265 Dec 21 01:17 00000009.history
-rw------- 1 postgres postgres 310 Jan 19 01:49 0000000A.history
-rw------- 1 postgres postgres 356 Jan 19 02:37 0000000B.history
-rw------- 1 postgres postgres 402 Feb 22 01:59 0000000C.history
-rw------- 1 postgres postgres 448 Feb 22 02:51 0000000D.history
-rw------- 1 postgres postgres 494 Mar 27 04:10 0000000E.history
-rw------- 1 postgres postgres 540 Mar 27 08:20 0000000F.history
-rw------- 1 postgres postgres 586 Mar 27 22:32 00000010.history
-rw------- 1 postgres postgres 632 Apr 3 23:03 00000011.history
-rw------- 1 postgres postgres 327 May 20 02:21 000000120000037000000089.00000028.backup
-rw------- 1 postgres postgres 16777216 May 20 15:12 00000012000003720000002D
-rw------- 1 postgres postgres 16777216 May 20 15:15 00000012000003720000002E
-rw------- 1 postgres postgres 16777216 May 20 15:18 00000012000003720000002F
-rw------- 1 postgres postgres 16777216 May 20 15:21 000000120000037200000030
-rw------- 1 postgres postgres 16777216 May 20 15:22 000000120000037200000031
-rw------- 1 postgres postgres 16777216 May 20 15:24 000000120000037200000032
-rw------- 1 postgres postgres 16777216 May 20 15:26 000000120000037200000033
-rw------- 1 postgres postgres 16777216 May 20 15:28 000000120000037200000034
-rw------- 1 postgres postgres 16777216 May 20 15:32 000000120000037200000035
-rw------- 1 postgres postgres 16777216 May 20 15:33 000000120000037200000036
-rw------- 1 postgres postgres 16777216 May 20 15:35 000000120000037200000037
-rw------- 1 postgres postgres 16777216 May 20 15:37 000000120000037200000038
-rw------- 1 postgres postgres 16777216 May 20 15:38 000000120000037200000039
-rw------- 1 postgres postgres 16777216 May 20 15:39 00000012000003720000003A
-rw------- 1 postgres postgres 16777216 May 20 15:39 00000012000003720000003B
-rw------- 1 postgres postgres 16777216 May 20 15:39 00000012000003720000003C
-rw------- 1 postgres postgres 16777216 May 20 15:43 00000012000003720000003D
-rw------- 1 postgres postgres 16777216 May 20 15:45 00000012000003720000003E
-rw------- 1 postgres postgres 16777216 May 20 15:48 00000012000003720000003F
-rw------- 1 postgres postgres 16777216 May 20 15:50 000000120000037200000040
-rw------- 1 postgres postgres 16777216 May 20 15:52 000000120000037200000041
-rw------- 1 postgres postgres 16777216 May 20 15:52 000000120000037200000042
-rw------- 1 postgres postgres 16777216 May 20 15:53 000000120000037200000043
-rw------- 1 postgres postgres 16777216 May 20 15:54 000000120000037200000044
-rw------- 1 postgres postgres 16777216 May 20 15:55 000000120000037200000045
-rw------- 1 postgres postgres 16777216 May 20 15:56 000000120000037200000046
-rw------- 1 postgres postgres 16777216 May 20 15:58 000000120000037200000047
-rw------- 1 postgres postgres 16777216 May 20 16:01 000000120000037200000048
-rw------- 1 postgres postgres 16777216 May 20 16:02 000000120000037200000049
-rw------- 1 postgres postgres 16777216 May 20 16:02 00000012000003720000004A
-rw------- 1 postgres postgres 16777216 May 20 16:03 00000012000003720000004B
-rw------- 1 postgres postgres 16777216 May 20 16:03 00000012000003720000004C
-rw------- 1 postgres postgres 16777216 May 20 16:04 00000012000003720000004D
-rw------- 1 postgres postgres 16777216 May 20 16:04 00000012000003720000004E
-rw------- 1 postgres postgres 16777216 May 20 16:04 00000012000003720000004F
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000050
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000051
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000052
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000053
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000054
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000055
-rw------- 1 postgres postgres 16777216 May 20 16:04 000000120000037200000056
-rw------- 1 postgres postgres 16777216 May 20 16:05 000000120000037200000057
-rw------- 1 postgres postgres 16777216 May 20 16:06 000000120000037200000058
-rw------- 1 postgres postgres 16777216 May 20 16:06 000000120000037200000059
-rw------- 1 postgres postgres 16777216 May 20 16:06 00000012000003720000005A
-rw------- 1 postgres postgres 16777216 May 20 16:07 00000012000003720000005B
-rw------- 1 postgres postgres 16777216 May 20 16:07 00000012000003720000005C
-rw------- 1 postgres postgres 16777216 May 20 16:08 00000012000003720000005D
-rw------- 1 postgres postgres 16777216 May 20 14:12 00000012000003720000005E
-rw------- 1 postgres postgres 16777216 May 20 14:12 00000012000003720000005F
-rw------- 1 postgres postgres 16777216 May 20 14:12 000000120000037200000060
-rw------- 1 postgres postgres 16777216 May 20 14:12 000000120000037200000061
-rw------- 1 postgres postgres 16777216 May 20 14:13 000000120000037200000062
-rw------- 1 postgres postgres 16777216 May 20 14:15 000000120000037200000063
-rw------- 1 postgres postgres 16777216 May 20 14:12 000000120000037200000064
-rw------- 1 postgres postgres 16777216 May 20 14:12 000000120000037200000065
-rw------- 1 postgres postgres 16777216 May 20 14:12 000000120000037200000066
-rw------- 1 postgres postgres 16777216 May 20 14:19 000000120000037200000067
-rw------- 1 postgres postgres 16777216 May 20 14:17 000000120000037200000068
-rw------- 1 postgres postgres 16777216 May 20 14:19 000000120000037200000069
-rw------- 1 postgres postgres 16777216 May 20 14:19 00000012000003720000006A
-rw------- 1 postgres postgres 16777216 May 20 14:20 00000012000003720000006B
-rw------- 1 postgres postgres 16777216 May 20 14:20 00000012000003720000006C
-rw------- 1 postgres postgres 16777216 May 20 14:20 00000012000003720000006D
-rw------- 1 postgres postgres 16777216 May 20 14:21 00000012000003720000006E
-rw------- 1 postgres postgres 16777216 May 20 14:21 00000012000003720000006F
-rw------- 1 postgres postgres 16777216 May 20 14:21 000000120000037200000070
-rw------- 1 postgres postgres 16777216 May 20 14:21 000000120000037200000071
-rw------- 1 postgres postgres 16777216 May 20 14:22 000000120000037200000072
-rw------- 1 postgres postgres 16777216 May 20 14:24 000000120000037200000073
-rw------- 1 postgres postgres 16777216 May 20 14:27 000000120000037200000074
-rw------- 1 postgres postgres 16777216 May 20 14:25 000000120000037200000075
-rw------- 1 postgres postgres 16777216 May 20 14:25 000000120000037200000076
-rw------- 1 postgres postgres 16777216 May 20 14:30 000000120000037200000077
-rw------- 1 postgres postgres 16777216 May 20 14:32 000000120000037200000078
-rw------- 1 postgres postgres 16777216 May 20 14:34 000000120000037200000079
-rw------- 1 postgres postgres 16777216 May 20 14:36 00000012000003720000007A
-rw------- 1 postgres postgres 16777216 May 20 14:37 00000012000003720000007B
-rw------- 1 postgres postgres 16777216 May 20 14:40 00000012000003720000007C
-rw------- 1 postgres postgres 16777216 May 20 14:41 00000012000003720000007D
-rw------- 1 postgres postgres 16777216 May 20 14:43 00000012000003720000007E
-rw------- 1 postgres postgres 16777216 May 20 14:43 00000012000003720000007F
-rw------- 1 postgres postgres 16777216 May 20 14:43 000000120000037200000080
-rw------- 1 postgres postgres 16777216 May 20 14:44 000000120000037200000081
-rw------- 1 postgres postgres 16777216 May 20 14:45 000000120000037200000082
-rw------- 1 postgres postgres 16777216 May 20 14:45 000000120000037200000083
-rw------- 1 postgres postgres 16777216 May 20 14:45 000000120000037200000084
-rw------- 1 postgres postgres 16777216 May 20 14:45 000000120000037200000085
-rw------- 1 postgres postgres 16777216 May 20 14:50 000000120000037200000086
-rw------- 1 postgres postgres 16777216 May 20 14:51 000000120000037200000087
-rw------- 1 postgres postgres 16777216 May 20 14:55 000000120000037200000088
-rw------- 1 postgres postgres 16777216 May 20 14:49 000000120000037200000089
-rw------- 1 postgres postgres 16777216 May 20 15:06 00000012000003720000008A
-rw------- 1 postgres postgres 16777216 May 20 14:59 00000012000003720000008B
-rw------- 1 postgres postgres 16777216 May 20 15:10 00000012000003720000008C
-rw------- 1 postgres postgres 16777216 May 20 15:02 00000012000003720000008D
-rw------- 1 postgres postgres 16777216 May 20 15:08 00000012000003720000008E
-rw------- 1 postgres postgres 678 Apr 3 23:56 00000012.history
drwx------ 2 postgres postgres 4096 May 20 16:07 archive_status
There are 98 WAL segments in the directory currently.
From the documentation, I understand that the number of WAL files can go as high as (3 * checkpoint_segments + 1) segment files, which would be 97 in my case, but I seem to be consistently at this number or even higher (sometimes over 110 files) and I don't think I've ever seen the directory smaller than ~97 segment files.
Regarding the ordering of segments, my understanding is that segment 0000012000003720000008B would be written to after 00000012000003720000008A, but the timestamps (14:59 and 15:06, respectively) appear to show otherwise. There are several cases like this. Does this mean that 00000012000003720000008A has newer WAL records than 00000012000003720000008B??
It may be that there's nothing wrong here and this behaviour is natural. If that is the case, I'd still like to better understand this phenomena.
Thanks!
Dave Stibrany
Dave Stibrany <dstibrany@gmail.com> writes:
> There are 98 WAL segments in the directory currently.
> From the documentation, I understand that the number of WAL files can go as
> high as (3 * checkpoint_segments + 1) segment files, which would be 97 in
> my case, but I seem to be consistently at this number or even higher
> (sometimes over 110 files) and I don't think I've ever seen the directory
> smaller than ~97 segment files.
I don't believe there's any aggressive attempt to remove segment files
after transient peak usage (what happens to them instead is explained
below). If you had many times the expected number of segments, I'd be
worried, but these numbers sound pretty normal to me.
> Regarding the ordering of segments, my understanding is that segment
> 0000012000003720000008B would be written to after 00000012000003720000008A,
> but the timestamps (14:59 and 15:06, respectively) appear to show
> otherwise. There are several cases like this. Does this mean that
> 00000012000003720000008A has newer WAL records than
> 00000012000003720000008B??
No, it probably means that neither one has been written at all yet.
Typically, when a WAL segment is deemed no longer needed, the file isn't
physically removed but is merely renamed into place as a future segment.
The idea is to reduce unnecessary filesystem work as we create and delete
WAL segments. You could check this out if you have pg_xlogdump at hand,
by seeing whether the WAL file's first page header claims to belong to the
segment indicated by the file name, or to some much-older segment.
regards, tom lane
Tom Lane wrote: > No, it probably means that neither one has been written at all yet. > Typically, when a WAL segment is deemed no longer needed, the file isn't > physically removed but is merely renamed into place as a future segment. > The idea is to reduce unnecessary filesystem work as we create and delete > WAL segments. You could check this out if you have pg_xlogdump at hand, > by seeing whether the WAL file's first page header claims to belong to the > segment indicated by the file name, or to some much-older segment. This may be a good time to point out that pg_xlogdump fails completely when a file's contents does not match the file name, with no indication about what a better file name would be. In other words, if a file has been recycled and not written to yet under the new name, it doesn't tell you anything useful. This is pretty annoying. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Thanks for the response and the pg_xlogdump tip. Dave > On May 20, 2016, at 2:35 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > > Dave Stibrany <dstibrany@gmail.com> writes: >> There are 98 WAL segments in the directory currently. > >> From the documentation, I understand that the number of WAL files can go as >> high as (3 * checkpoint_segments + 1) segment files, which would be 97 in >> my case, but I seem to be consistently at this number or even higher >> (sometimes over 110 files) and I don't think I've ever seen the directory >> smaller than ~97 segment files. > > I don't believe there's any aggressive attempt to remove segment files > after transient peak usage (what happens to them instead is explained > below). If you had many times the expected number of segments, I'd be > worried, but these numbers sound pretty normal to me. > >> Regarding the ordering of segments, my understanding is that segment >> 0000012000003720000008B would be written to after 00000012000003720000008A, >> but the timestamps (14:59 and 15:06, respectively) appear to show >> otherwise. There are several cases like this. Does this mean that >> 00000012000003720000008A has newer WAL records than >> 00000012000003720000008B?? > > No, it probably means that neither one has been written at all yet. > Typically, when a WAL segment is deemed no longer needed, the file isn't > physically removed but is merely renamed into place as a future segment. > The idea is to reduce unnecessary filesystem work as we create and delete > WAL segments. You could check this out if you have pg_xlogdump at hand, > by seeing whether the WAL file's first page header claims to belong to the > segment indicated by the file name, or to some much-older segment. > > regards, tom lane