Обсуждение: Re: [GENERAL] pg_xlog on a hot_standby slave filling up
[moving to -bugs] Re: Xavier 12 2015-06-16 <CAMOV8iB3oRzC4f7UTzOwC2wT08do3voi+PGN07uJq+ayo9E= =3DcQ@mail.gmail.com> > Hi everyone, >=20 > Questions about pg_xlogs again... > I have two Postgresql 9.1 servers in a master/slave stream replication > (hot_standby). >=20 > Psql01 (master) is backuped with Barman and pg_xlogs is correctly > purged (archive_command is used). >=20 > Hower, Psql02 (slave) has a huge pg_xlog (951 files, 15G for 7 days > only, it keeps growing up until disk space is full). I have found > documentation and tutorials, mailing list, but I don't know what is > suitable for a Slave. Leads I've found : Hi, I have the same problem here. Master/slave running on 9.3.current. On the master everything is normal, but on the slave server, files in pg_xlog and archive_status pile up. Interestingly, the filenames are mostly 0x20 apart. (IRC user Kassandry is reporting the same issue on 9.4 as well, including the 0x20 spacing.) [0] root@synthesis:/var/lib/postgresql/9.3/ircservices/pg_xlog # l insgesamt 2099744 drwx------ 3 postgres postgres 12288 Jun 15 22:29 ./ drwx------ 15 postgres postgres 4096 Jun 15 22:29 ../ -rw------- 1 postgres postgres 16777216 M=E4r 9 04:25 0000000100000017000= 00057 -rw------- 1 postgres postgres 16777216 M=E4r 9 19:06 0000000100000017000= 00083 -rw------- 1 postgres postgres 16777216 M=E4r 10 05:46 0000000100000017000= 000A3 -rw------- 1 postgres postgres 16777216 M=E4r 10 16:26 0000000100000017000= 000C3 -rw------- 1 postgres postgres 16777216 M=E4r 12 06:26 0000000100000018000= 00035 -rw------- 1 postgres postgres 16777216 M=E4r 13 01:06 0000000100000018000= 0006D -rw------- 1 postgres postgres 16777216 M=E4r 13 11:46 0000000100000018000= 0008D -rw------- 1 postgres postgres 16777216 M=E4r 13 22:26 0000000100000018000= 000AD -rw------- 1 postgres postgres 16777216 M=E4r 14 09:06 0000000100000018000= 000CD -rw------- 1 postgres postgres 16777216 M=E4r 14 19:46 0000000100000018000= 000ED -rw------- 1 postgres postgres 16777216 M=E4r 15 05:52 0000000100000019000= 0000D -rw------- 1 postgres postgres 16777216 M=E4r 15 16:32 0000000100000019000= 0002D -rw------- 1 postgres postgres 16777216 M=E4r 16 03:12 0000000100000019000= 0004D -rw------- 1 postgres postgres 16777216 M=E4r 16 13:52 0000000100000019000= 0006D -rw------- 1 postgres postgres 16777216 M=E4r 17 00:32 0000000100000019000= 0008D -rw------- 1 postgres postgres 16777216 M=E4r 17 11:12 0000000100000019000= 000AD -rw------- 1 postgres postgres 16777216 M=E4r 17 21:52 0000000100000019000= 000CD -rw------- 1 postgres postgres 16777216 M=E4r 18 08:32 0000000100000019000= 000ED -rw------- 1 postgres postgres 16777216 M=E4r 18 19:12 000000010000001A000= 0000D -rw------- 1 postgres postgres 16777216 M=E4r 19 05:53 000000010000001A000= 0002D -rw------- 1 postgres postgres 16777216 M=E4r 19 16:52 000000010000001A000= 0004D -rw------- 1 postgres postgres 16777216 M=E4r 20 03:32 000000010000001A000= 0006D -rw------- 1 postgres postgres 16777216 M=E4r 21 00:52 000000010000001A000= 000AD -rw------- 1 postgres postgres 16777216 M=E4r 21 11:33 000000010000001A000= 000CD -rw------- 1 postgres postgres 16777216 M=E4r 21 22:13 000000010000001A000= 000ED -rw------- 1 postgres postgres 16777216 M=E4r 22 08:32 000000010000001B000= 0000D -rw------- 1 postgres postgres 16777216 M=E4r 22 19:12 000000010000001B000= 0002D -rw------- 1 postgres postgres 16777216 M=E4r 23 05:52 000000010000001B000= 0004D -rw------- 1 postgres postgres 16777216 M=E4r 23 16:32 000000010000001B000= 0006D -rw------- 1 postgres postgres 16777216 M=E4r 24 03:12 000000010000001B000= 0008D -rw------- 1 postgres postgres 16777216 M=E4r 24 13:52 000000010000001B000= 000AD -rw------- 1 postgres postgres 16777216 M=E4r 26 10:52 000000010000001C000= 00025 -rw------- 1 postgres postgres 16777216 M=E4r 26 21:32 000000010000001C000= 00045 -rw------- 1 postgres postgres 16777216 M=E4r 27 08:12 000000010000001C000= 00065 -rw------- 1 postgres postgres 16777216 M=E4r 27 18:52 000000010000001C000= 00085 -rw------- 1 postgres postgres 16777216 M=E4r 28 16:13 000000010000001C000= 000C5 -rw------- 1 postgres postgres 16777216 M=E4r 29 03:53 000000010000001C000= 000E5 -rw------- 1 postgres postgres 16777216 M=E4r 29 17:52 000000010000001D000= 00010 -rw------- 1 postgres postgres 16777216 M=E4r 30 04:32 000000010000001D000= 00030 -rw------- 1 postgres postgres 16777216 M=E4r 30 15:12 000000010000001D000= 00050 -rw------- 1 postgres postgres 16777216 M=E4r 31 01:52 000000010000001D000= 00070 -rw------- 1 postgres postgres 16777216 M=E4r 31 12:32 000000010000001D000= 00090 -rw------- 1 postgres postgres 16777216 M=E4r 31 23:12 000000010000001D000= 000B0 -rw------- 1 postgres postgres 16777216 Apr 11 15:32 000000010000002000000= 0B2 -rw------- 1 postgres postgres 16777216 Apr 12 02:12 000000010000002000000= 0D2 -rw------- 1 postgres postgres 16777216 Apr 12 12:32 000000010000002000000= 0F2 -rw------- 1 postgres postgres 16777216 Apr 12 23:12 000000010000002100000= 012 -rw------- 1 postgres postgres 16777216 Apr 13 09:52 000000010000002100000= 032 -rw------- 1 postgres postgres 16777216 Apr 13 20:32 000000010000002100000= 052 -rw------- 1 postgres postgres 16777216 Apr 14 07:12 000000010000002100000= 072 -rw------- 1 postgres postgres 16777216 Apr 14 17:52 000000010000002100000= 092 -rw------- 1 postgres postgres 16777216 Apr 15 04:32 000000010000002100000= 0B2 -rw------- 1 postgres postgres 16777216 Apr 15 15:12 000000010000002100000= 0D2 -rw------- 1 postgres postgres 16777216 Apr 21 17:32 000000010000002300000= 08A -rw------- 1 postgres postgres 16777216 Apr 22 04:12 000000010000002300000= 0AA -rw------- 1 postgres postgres 16777216 Apr 22 20:32 000000010000002300000= 0DB -rw------- 1 postgres postgres 16777216 Apr 23 07:12 000000010000002300000= 0FB -rw------- 1 postgres postgres 16777216 Apr 23 17:52 000000010000002400000= 01B -rw------- 1 postgres postgres 16777216 Apr 24 04:32 000000010000002400000= 03B -rw------- 1 postgres postgres 16777216 Apr 24 19:52 000000010000002400000= 069 -rw------- 1 postgres postgres 16777216 Apr 25 06:32 000000010000002400000= 089 -rw------- 1 postgres postgres 16777216 Apr 27 10:52 000000010000002500000= 027 -rw------- 1 postgres postgres 16777216 Apr 28 00:52 000000010000002500000= 051 -rw------- 1 postgres postgres 16777216 Apr 28 03:33 000000010000002500000= 059 -rw------- 1 postgres postgres 16777216 Apr 29 00:53 000000010000002500000= 099 -rw------- 1 postgres postgres 16777216 Apr 29 11:33 000000010000002500000= 0B9 -rw------- 1 postgres postgres 16777216 Apr 29 22:13 000000010000002500000= 0D9 -rw------- 1 postgres postgres 16777216 Apr 30 08:53 000000010000002500000= 0F9 -rw------- 1 postgres postgres 16777216 Apr 30 19:33 000000010000002600000= 019 -rw------- 1 postgres postgres 16777216 Mai 1 06:13 000000010000002600000= 039 -rw------- 1 postgres postgres 16777216 Mai 1 16:53 000000010000002600000= 059 -rw------- 1 postgres postgres 16777216 Mai 2 14:13 000000010000002600000= 099 -rw------- 1 postgres postgres 16777216 Mai 3 00:53 000000010000002600000= 0B9 -rw------- 1 postgres postgres 16777216 Mai 4 00:52 000000010000002700000= 002 -rw------- 1 postgres postgres 16777216 Mai 4 11:32 000000010000002700000= 022 -rw------- 1 postgres postgres 16777216 Mai 4 22:12 000000010000002700000= 042 -rw------- 1 postgres postgres 16777216 Mai 6 00:52 000000010000002700000= 092 -rw------- 1 postgres postgres 16777216 Mai 6 11:32 000000010000002700000= 0B2 -rw------- 1 postgres postgres 16777216 Mai 6 22:12 000000010000002700000= 0D2 -rw------- 1 postgres postgres 16777216 Mai 7 08:53 000000010000002700000= 0F2 -rw------- 1 postgres postgres 16777216 Mai 7 19:33 000000010000002800000= 012 -rw------- 1 postgres postgres 16777216 Mai 8 06:13 000000010000002800000= 032 -rw------- 1 postgres postgres 16777216 Mai 8 16:53 000000010000002800000= 052 -rw------- 1 postgres postgres 16777216 Mai 10 09:52 000000010000002800000= 0CF -rw------- 1 postgres postgres 16777216 Mai 10 20:00 000000010000002800000= 0EF -rw------- 1 postgres postgres 16777216 Mai 11 06:40 000000010000002900000= 00F -rw------- 1 postgres postgres 16777216 Mai 11 17:20 000000010000002900000= 02F -rw------- 1 postgres postgres 16777216 Mai 12 04:00 000000010000002900000= 04F -rw------- 1 postgres postgres 16777216 Mai 12 14:40 000000010000002900000= 06F -rw------- 1 postgres postgres 16777216 Mai 13 01:20 000000010000002900000= 08F -rw------- 1 postgres postgres 16777216 Mai 13 12:01 000000010000002900000= 0AF -rw------- 1 postgres postgres 16777216 Mai 13 22:38 000000010000002900000= 0CF -rw------- 1 postgres postgres 16777216 Mai 14 09:18 000000010000002900000= 0EF -rw------- 1 postgres postgres 16777216 Mai 14 19:58 000000010000002A00000= 00F -rw------- 1 postgres postgres 16777216 Mai 15 06:38 000000010000002A00000= 02F -rw------- 1 postgres postgres 16777216 Mai 15 17:18 000000010000002A00000= 04F -rw------- 1 postgres postgres 16777216 Mai 16 03:58 000000010000002A00000= 06F -rw------- 1 postgres postgres 16777216 Mai 17 01:19 000000010000002A00000= 0AF -rw------- 1 postgres postgres 16777216 Mai 18 00:32 000000010000002A00000= 0F6 -rw------- 1 postgres postgres 16777216 Mai 18 11:12 000000010000002B00000= 016 -rw------- 1 postgres postgres 16777216 Mai 18 21:52 000000010000002B00000= 036 -rw------- 1 postgres postgres 16777216 Mai 19 08:32 000000010000002B00000= 056 -rw------- 1 postgres postgres 16777216 Mai 19 19:12 000000010000002B00000= 076 -rw------- 1 postgres postgres 16777216 Mai 20 05:52 000000010000002B00000= 096 -rw------- 1 postgres postgres 16777216 Mai 20 16:33 000000010000002B00000= 0B6 -rw------- 1 postgres postgres 16777216 Mai 21 03:12 000000010000002B00000= 0D6 -rw------- 1 postgres postgres 16777216 Jun 7 19:51 000000010000003000000= 0D5 -rw------- 1 postgres postgres 16777216 Jun 8 06:31 000000010000003000000= 0F5 -rw------- 1 postgres postgres 16777216 Jun 8 17:11 000000010000003100000= 015 -rw------- 1 postgres postgres 16777216 Jun 9 03:51 000000010000003100000= 035 -rw------- 1 postgres postgres 16777216 Jun 9 14:31 000000010000003100000= 055 -rw------- 1 postgres postgres 16777216 Jun 10 08:51 000000010000003100000= 08C -rw------- 1 postgres postgres 16777216 Jun 10 19:31 000000010000003100000= 0AC -rw------- 1 postgres postgres 16777216 Jun 11 06:11 000000010000003100000= 0CC -rw------- 1 postgres postgres 16777216 Jun 11 16:51 000000010000003100000= 0EC -rw------- 1 postgres postgres 16777216 Jun 12 03:31 000000010000003200000= 00C -rw------- 1 postgres postgres 16777216 Jun 12 14:11 000000010000003200000= 02C -rw------- 1 postgres postgres 16777216 Jun 13 00:52 000000010000003200000= 04C -rw------- 1 postgres postgres 16777216 Jun 13 11:32 000000010000003200000= 06C -rw------- 1 postgres postgres 16777216 Jun 13 22:12 000000010000003200000= 08C -rw------- 1 postgres postgres 16777216 Jun 15 07:14 000000010000003200000= 0F1 -rw------- 1 postgres postgres 16777216 Jun 15 20:55 000000010000003300000= 01A -rw------- 1 postgres postgres 16777216 Jun 15 21:14 000000010000003300000= 01B -rw------- 1 postgres postgres 16777216 Jun 15 21:34 000000010000003300000= 01C -rw------- 1 postgres postgres 16777216 Jun 15 22:29 000000010000003300000= 01D -rw------- 1 postgres postgres 16777216 Jun 15 22:29 000000010000003300000= 01E -rw------- 1 postgres postgres 16777216 Jun 15 22:29 000000010000003300000= 01F -rw------- 1 postgres postgres 16777216 Jun 15 20:35 000000010000003300000= 020 drwx------ 2 postgres postgres 16384 Jun 15 22:15 archive_status/ [0] root@synthesis:/var/lib/postgresql/9.3/ircservices/pg_xlog # l archive_= status/ insgesamt 28 drwx------ 2 postgres postgres 16384 Jun 15 22:15 ./ drwx------ 3 postgres postgres 12288 Jun 15 22:29 ../ -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= 7.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= 8.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= 9.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= A.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= B.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= C.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= D.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= E.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000001= F.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 0.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 1.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 2.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 3.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 4.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 5.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 6.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 7.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 8.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= 9.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= A.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= B.ready -rw------- 1 postgres postgres 0 M=E4r 8 16:48 00000001000000150000002= C.ready -rw------- 1 postgres postgres 0 M=E4r 9 05:47 00000001000000170000005= 7.ready -rw------- 1 postgres postgres 0 M=E4r 9 20:06 00000001000000170000008= 3.ready -rw------- 1 postgres postgres 0 M=E4r 10 06:46 0000000100000017000000A= 3.ready -rw------- 1 postgres postgres 0 M=E4r 10 17:47 0000000100000017000000C= 3.ready -rw------- 1 postgres postgres 0 M=E4r 12 08:06 00000001000000180000003= 5.ready -rw------- 1 postgres postgres 0 M=E4r 13 02:27 00000001000000180000006= D.ready -rw------- 1 postgres postgres 0 M=E4r 13 13:07 00000001000000180000008= D.ready -rw------- 1 postgres postgres 0 M=E4r 14 00:07 0000000100000018000000A= D.ready -rw------- 1 postgres postgres 0 M=E4r 14 10:07 0000000100000018000000C= D.ready -rw------- 1 postgres postgres 0 M=E4r 14 20:49 0000000100000018000000E= D.ready -rw------- 1 postgres postgres 0 M=E4r 15 06:52 00000001000000190000000= D.ready -rw------- 1 postgres postgres 0 M=E4r 15 17:53 00000001000000190000002= D.ready -rw------- 1 postgres postgres 0 M=E4r 16 04:32 00000001000000190000004= D.ready -rw------- 1 postgres postgres 0 M=E4r 16 15:33 00000001000000190000006= D.ready -rw------- 1 postgres postgres 0 M=E4r 17 01:33 00000001000000190000008= D.ready -rw------- 1 postgres postgres 0 M=E4r 17 12:12 0000000100000019000000A= D.ready -rw------- 1 postgres postgres 0 M=E4r 17 23:13 0000000100000019000000C= D.ready -rw------- 1 postgres postgres 0 M=E4r 18 09:53 0000000100000019000000E= D.ready -rw------- 1 postgres postgres 0 M=E4r 18 20:53 000000010000001A0000000= D.ready -rw------- 1 postgres postgres 0 M=E4r 19 06:53 000000010000001A0000002= D.ready -rw------- 1 postgres postgres 0 M=E4r 19 18:33 000000010000001A0000004= D.ready -rw------- 1 postgres postgres 0 M=E4r 20 04:34 000000010000001A0000006= D.ready -rw------- 1 postgres postgres 0 M=E4r 21 02:13 000000010000001A000000A= D.ready -rw------- 1 postgres postgres 0 M=E4r 21 12:53 000000010000001A000000C= D.ready -rw------- 1 postgres postgres 0 M=E4r 21 23:54 000000010000001A000000E= D.ready -rw------- 1 postgres postgres 0 M=E4r 22 09:32 000000010000001B0000000= D.ready -rw------- 1 postgres postgres 0 M=E4r 22 20:12 000000010000001B0000002= D.ready -rw------- 1 postgres postgres 0 M=E4r 23 07:12 000000010000001B0000004= D.ready -rw------- 1 postgres postgres 0 M=E4r 23 17:53 000000010000001B0000006= D.ready -rw------- 1 postgres postgres 0 M=E4r 24 04:53 000000010000001B0000008= D.ready -rw------- 1 postgres postgres 0 M=E4r 24 14:53 000000010000001B000000A= D.ready -rw------- 1 postgres postgres 0 M=E4r 26 12:15 000000010000001C0000002= 5.ready -rw------- 1 postgres postgres 0 M=E4r 26 22:53 000000010000001C0000004= 5.ready -rw------- 1 postgres postgres 0 M=E4r 27 09:53 000000010000001C0000006= 5.ready -rw------- 1 postgres postgres 0 M=E4r 27 19:53 000000010000001C0000008= 5.ready -rw------- 1 postgres postgres 0 M=E4r 28 17:34 000000010000001C000000C= 5.ready -rw------- 1 postgres postgres 0 M=E4r 29 05:13 000000010000001C000000E= 5.ready -rw------- 1 postgres postgres 0 M=E4r 29 18:53 000000010000001D0000001= 0.ready -rw------- 1 postgres postgres 0 M=E4r 30 05:32 000000010000001D0000003= 0.ready -rw------- 1 postgres postgres 0 M=E4r 30 16:32 000000010000001D0000005= 0.ready -rw------- 1 postgres postgres 0 M=E4r 31 03:12 000000010000001D0000007= 0.ready -rw------- 1 postgres postgres 0 M=E4r 31 14:13 000000010000001D0000009= 0.ready -rw------- 1 postgres postgres 0 Apr 1 00:13 000000010000001D000000B0.= ready -rw------- 1 postgres postgres 0 Apr 11 16:33 0000000100000020000000B2.= ready -rw------- 1 postgres postgres 0 Apr 12 03:13 0000000100000020000000D2.= ready -rw------- 1 postgres postgres 0 Apr 12 13:52 0000000100000020000000F2.= ready -rw------- 1 postgres postgres 0 Apr 13 00:33 000000010000002100000012.= ready -rw------- 1 postgres postgres 0 Apr 13 11:32 000000010000002100000032.= ready -rw------- 1 postgres postgres 0 Apr 13 21:32 000000010000002100000052.= ready -rw------- 1 postgres postgres 0 Apr 14 08:13 000000010000002100000072.= ready -rw------- 1 postgres postgres 0 Apr 14 19:13 000000010000002100000092.= ready -rw------- 1 postgres postgres 0 Apr 15 05:52 0000000100000021000000B2.= ready -rw------- 1 postgres postgres 0 Apr 15 16:53 0000000100000021000000D2.= ready -rw------- 1 postgres postgres 0 Apr 21 19:13 00000001000000230000008A.= ready -rw------- 1 postgres postgres 0 Apr 22 05:12 0000000100000023000000AA.= ready -rw------- 1 postgres postgres 0 Apr 22 21:53 0000000100000023000000DB.= ready -rw------- 1 postgres postgres 0 Apr 23 08:33 0000000100000023000000FB.= ready -rw------- 1 postgres postgres 0 Apr 23 19:33 00000001000000240000001B.= ready -rw------- 1 postgres postgres 0 Apr 24 05:33 00000001000000240000003B.= ready -rw------- 1 postgres postgres 0 Apr 24 21:13 000000010000002400000069.= ready -rw------- 1 postgres postgres 0 Apr 25 08:13 000000010000002400000089.= ready -rw------- 1 postgres postgres 0 Apr 27 12:13 000000010000002500000027.= ready -rw------- 1 postgres postgres 0 Apr 28 02:33 000000010000002500000051.= ready -rw------- 1 postgres postgres 0 Apr 28 04:53 000000010000002500000059.= ready -rw------- 1 postgres postgres 0 Apr 29 01:53 000000010000002500000099.= ready -rw------- 1 postgres postgres 0 Apr 29 12:34 0000000100000025000000B9.= ready -rw------- 1 postgres postgres 0 Apr 29 23:33 0000000100000025000000D9.= ready -rw------- 1 postgres postgres 0 Apr 30 10:14 0000000100000025000000F9.= ready -rw------- 1 postgres postgres 0 Apr 30 21:13 000000010000002600000019.= ready -rw------- 1 postgres postgres 0 Mai 1 07:14 000000010000002600000039.= ready -rw------- 1 postgres postgres 0 Mai 1 17:54 000000010000002600000059.= ready -rw------- 1 postgres postgres 0 Mai 2 15:34 000000010000002600000099.= ready -rw------- 1 postgres postgres 0 Mai 3 02:34 0000000100000026000000B9.= ready -rw------- 1 postgres postgres 0 Mai 4 02:12 000000010000002700000002.= ready -rw------- 1 postgres postgres 0 Mai 4 13:13 000000010000002700000022.= ready -rw------- 1 postgres postgres 0 Mai 4 23:14 000000010000002700000042.= ready -rw------- 1 postgres postgres 0 Mai 6 01:53 000000010000002700000092.= ready -rw------- 1 postgres postgres 0 Mai 6 12:34 0000000100000027000000B2.= ready -rw------- 1 postgres postgres 0 Mai 6 23:33 0000000100000027000000D2.= ready -rw------- 1 postgres postgres 0 Mai 7 10:13 0000000100000027000000F2.= ready -rw------- 1 postgres postgres 0 Mai 7 21:13 000000010000002800000012.= ready -rw------- 1 postgres postgres 0 Mai 8 07:14 000000010000002800000032.= ready -rw------- 1 postgres postgres 0 Mai 8 17:53 000000010000002800000052.= ready -rw------- 1 postgres postgres 0 Mai 10 11:13 0000000100000028000000CF.= ready -rw------- 1 postgres postgres 0 Mai 10 21:21 0000000100000028000000EF.= ready -rw------- 1 postgres postgres 0 Mai 11 08:01 00000001000000290000000F.= ready -rw------- 1 postgres postgres 0 Mai 11 19:02 00000001000000290000002F.= ready -rw------- 1 postgres postgres 0 Mai 12 05:01 00000001000000290000004F.= ready -rw------- 1 postgres postgres 0 Mai 12 15:41 00000001000000290000006F.= ready -rw------- 1 postgres postgres 0 Mai 13 02:41 00000001000000290000008F.= ready -rw------- 1 postgres postgres 0 Mai 13 13:39 0000000100000029000000AF.= ready -rw------- 1 postgres postgres 0 Mai 13 23:39 0000000100000029000000CF.= ready -rw------- 1 postgres postgres 0 Mai 14 10:21 0000000100000029000000EF.= ready -rw------- 1 postgres postgres 0 Mai 14 21:19 000000010000002A0000000F.= ready -rw------- 1 postgres postgres 0 Mai 15 07:59 000000010000002A0000002F.= ready -rw------- 1 postgres postgres 0 Mai 15 19:00 000000010000002A0000004F.= ready -rw------- 1 postgres postgres 0 Mai 16 04:59 000000010000002A0000006F.= ready -rw------- 1 postgres postgres 0 Mai 17 02:39 000000010000002A000000AF.= ready -rw------- 1 postgres postgres 0 Mai 18 01:32 000000010000002A000000F6.= ready -rw------- 1 postgres postgres 0 Mai 18 12:12 000000010000002B00000016.= ready -rw------- 1 postgres postgres 0 Mai 18 23:13 000000010000002B00000036.= ready -rw------- 1 postgres postgres 0 Mai 19 09:53 000000010000002B00000056.= ready -rw------- 1 postgres postgres 0 Mai 19 20:53 000000010000002B00000076.= ready -rw------- 1 postgres postgres 0 Mai 20 06:53 000000010000002B00000096.= ready -rw------- 1 postgres postgres 0 Mai 20 17:33 000000010000002B000000B6.= ready -rw------- 1 postgres postgres 0 Mai 21 04:33 000000010000002B000000D6.= ready -rw------- 1 postgres postgres 0 Jun 7 21:11 0000000100000030000000D5.= ready -rw------- 1 postgres postgres 0 Jun 8 08:12 0000000100000030000000F5.= ready -rw------- 1 postgres postgres 0 Jun 8 18:12 000000010000003100000015.= ready -rw------- 1 postgres postgres 0 Jun 9 04:52 000000010000003100000035.= ready -rw------- 1 postgres postgres 0 Jun 9 15:52 000000010000003100000055.= ready -rw------- 1 postgres postgres 0 Jun 10 10:12 00000001000000310000008C.= ready -rw------- 1 postgres postgres 0 Jun 10 20:52 0000000100000031000000AC.= ready -rw------- 1 postgres postgres 0 Jun 11 07:52 0000000100000031000000CC.= ready -rw------- 1 postgres postgres 0 Jun 11 17:52 0000000100000031000000EC.= ready -rw------- 1 postgres postgres 0 Jun 12 04:32 00000001000000320000000C.= ready -rw------- 1 postgres postgres 0 Jun 12 15:32 00000001000000320000002C.= ready -rw------- 1 postgres postgres 0 Jun 13 02:12 00000001000000320000004C.= ready -rw------- 1 postgres postgres 0 Jun 13 13:13 00000001000000320000006C.= ready -rw------- 1 postgres postgres 0 Jun 13 23:12 00000001000000320000008C.= ready -rw------- 1 postgres postgres 0 Jun 15 08:15 0000000100000032000000F1.= ready -rw------- 1 postgres postgres 0 Jun 15 20:55 00000001000000330000001A.= done -rw------- 1 postgres postgres 0 Jun 15 21:15 00000001000000330000001B.= done -rw------- 1 postgres postgres 0 Jun 15 21:35 00000001000000330000001C.= done -rw------- 1 postgres postgres 0 Jun 15 21:55 00000001000000330000001D.= done -rw------- 1 postgres postgres 0 Jun 15 22:15 00000001000000330000001E.= done [0] root@synthesis:/var/lib/postgresql/9.3/ircservices/pg_xlog # pg_conftoo= l 9.3 ircservices show all archive_command =3D ':' archive_mode =3D yes archive_timeout =3D 20min autovacuum =3D yes checkpoint_timeout =3D 1h data_directory =3D '/var/lib/postgresql/9.3/ircservices' datestyle =3D 'iso, mdy' external_pid_file =3D '/var/run/postgresql/9.3-ircservices.pid' hba_file =3D '/etc/postgresql/9.3/ircservices/pg_hba.conf' hot_standby =3D on ident_file =3D '/etc/postgresql/9.3/ircservices/pg_ident.conf' lc_messages =3D C lc_monetary =3D C lc_numeric =3D C lc_time =3D C listen_addresses =3D '*' log_destination =3D syslog log_line_prefix =3D '%t ' max_connections =3D 100 port =3D 5433 shared_buffers =3D 24MB ssl =3D true ssl_ca_file =3D '/etc/ssl/certs/ca-oftc.pem' ssl_cert_file =3D '/etc/ssl/certs/thishost.pem' ssl_key_file =3D '/etc/ssl/private/thishost.key' track_counts =3D yes unix_socket_directories =3D '/var/run/postgresql' wal_level =3D hot_standby Jun 15 20:29:29 synthesis postgres[27944]: [5-1] 2015-06-15 20:29:29 GMT LO= G: redo starts at 33/1D000024 Jun 15 20:29:33 synthesis postgres[27944]: [6-1] 2015-06-15 20:29:33 GMT LO= G: restored log file "00000001000000330000001E" from archive Jun 15 20:29:34 synthesis postgres[27944]: [7-1] 2015-06-15 20:29:34 GMT LO= G: consistent recovery state reached at 33/1F0848B8 Jun 15 20:29:34 synthesis postgres[27943]: [2-1] 2015-06-15 20:29:34 GMT LO= G: database system is ready to accept read only connections Jun 15 20:29:34 synthesis postgres[27944]: [8-1] 2015-06-15 20:29:34 GMT LO= G: invalid record length at 33/1F0848B8 Jun 15 20:29:34 synthesis postgres[28045]: [3-1] 2015-06-15 20:29:34 GMT LO= G: started streaming WAL from primary at 33/1F000000 on timeline 1 In the meantime, I've manually removed the .ready files that do not have a corresponding xlog files, but the files do not get cleaned up. Since I gathered the data for the past yesterday evening, a new file (00000001000000330000003F) has appeared, but now there's even a gap in the .done files: [0] root@synthesis:/var/lib/postgresql/9.3/ircservices/pg_xlog # l | tail -rw------- 1 postgres postgres 16777216 Jun 15 07:14 000000010000003200000= 0F1 -rw------- 1 postgres postgres 16777216 Jun 16 09:14 000000010000003300000= 03F -rw------- 1 postgres postgres 16777216 Jun 16 19:35 000000010000003300000= 05E -rw------- 1 postgres postgres 16777216 Jun 16 19:55 000000010000003300000= 05F -rw------- 1 postgres postgres 16777216 Jun 16 20:14 000000010000003300000= 060 -rw------- 1 postgres postgres 16777216 Jun 16 20:31 000000010000003300000= 061 -rw------- 1 postgres postgres 16777216 Jun 16 18:35 000000010000003300000= 062 -rw------- 1 postgres postgres 16777216 Jun 16 18:55 000000010000003300000= 063 -rw------- 1 postgres postgres 16777216 Jun 16 19:15 000000010000003300000= 064 drwx------ 2 postgres postgres 16384 Jun 16 20:15 archive_status/ [0] root@synthesis:/var/lib/postgresql/9.3/ircservices/pg_xlog # l archive_= status/ |tail -rw------- 1 postgres postgres 0 Jun 11 17:52 0000000100000031000000EC.= ready -rw------- 1 postgres postgres 0 Jun 12 04:32 00000001000000320000000C.= ready -rw------- 1 postgres postgres 0 Jun 12 15:32 00000001000000320000002C.= ready -rw------- 1 postgres postgres 0 Jun 13 02:12 00000001000000320000004C.= ready -rw------- 1 postgres postgres 0 Jun 13 13:13 00000001000000320000006C.= ready -rw------- 1 postgres postgres 0 Jun 13 23:12 00000001000000320000008C.= ready -rw------- 1 postgres postgres 0 Jun 15 08:15 0000000100000032000000F1.= ready -rw------- 1 postgres postgres 0 Jun 16 10:15 00000001000000330000003F.= ready -rw------- 1 postgres postgres 0 Jun 16 19:35 00000001000000330000005E.= done -rw------- 1 postgres postgres 0 Jun 16 20:15 000000010000003300000060.= done Christoph --=20 cb@df7cb.de | http://www.df7cb.de/
> On Jun 16, 2015, at 11:35 AM, Christoph Berg <cb@df7cb.de> wrote: >=20 > [moving to -bugs] >=20 > Re: Xavier 12 2015-06-16 = <CAMOV8iB3oRzC4f7UTzOwC2wT08do3voi+PGN07uJq+ayo9E=3DcQ@mail.gmail.com> >> Hi everyone, >>=20 >> Questions about pg_xlogs again... >> I have two Postgresql 9.1 servers in a master/slave stream = replication >> (hot_standby). >>=20 >> Psql01 (master) is backuped with Barman and pg_xlogs is correctly >> purged (archive_command is used). >>=20 >> Hower, Psql02 (slave) has a huge pg_xlog (951 files, 15G for 7 days >> only, it keeps growing up until disk space is full). I have found >> documentation and tutorials, mailing list, but I don't know what is >> suitable for a Slave. Leads I've found : >=20 > Hi, >=20 > I have the same problem here. Master/slave running on 9.3.current. On > the master everything is normal, but on the slave server, files in > pg_xlog and archive_status pile up. Interestingly, the filenames are > mostly 0x20 apart. (IRC user Kassandry is reporting the same issue on > 9.4 as well, including the 0x20 spacing.) I=92ve seen this before, but haven=92t been able to make a reproducible = test case yet. Are you by chance using SSL to talk to the primary server? Is the = ssl_renegotiation_limit the default of 512MB? 32 WAL files at 16MB each = =3D 512MB. I found that it would always leave the WAL file from before = the invalid record length message. Does that seem to be the case for = you as well?
On 06/16/2015 01:16 PM, Jeff Frost wrote: >> On Jun 16, 2015, at 11:35 AM, Christoph Berg <cb@df7cb.de> wrote: >> >> [moving to -bugs] >> >> Re: Xavier 12 2015-06-16 <CAMOV8iB3oRzC4f7UTzOwC2wT08do3voi+PGN07uJq+ayo9E=cQ@mail.gmail.com> >>> Hi everyone, >>> >>> Questions about pg_xlogs again... >>> I have two Postgresql 9.1 servers in a master/slave stream replication >>> (hot_standby). >>> >>> Psql01 (master) is backuped with Barman and pg_xlogs is correctly >>> purged (archive_command is used). >>> >>> Hower, Psql02 (slave) has a huge pg_xlog (951 files, 15G for 7 days >>> only, it keeps growing up until disk space is full). I have found >>> documentation and tutorials, mailing list, but I don't know what is >>> suitable for a Slave. Leads I've found : >> Hi, >> >> I have the same problem here. Master/slave running on 9.3.current. On >> the master everything is normal, but on the slave server, files in >> pg_xlog and archive_status pile up. Interestingly, the filenames are >> mostly 0x20 apart. (IRC user Kassandry is reporting the same issue on >> 9.4 as well, including the 0x20 spacing.) > Ive seen this before, but havent been able to make a reproducible test case yet. > > Are you by chance using SSL to talk to the primary server? Is the ssl_renegotiation_limit the default of 512MB? 32 WALfiles at 16MB each = 512MB. I found that it would always leave the WAL file from before the invalid record length message. Does that seem to be the case for you as well? > > > Hello Jeff, To add to this on PostgreSQL 9.4 ( Kassandry from IRC ), yes, I see SSL errors in my logs. I turned off the archive_command I had running on one of my three replicas, which recycled all of the .ready files and all of the outstanding xlogs. I re-enabled the archive_command and waited. I got this in my logs: < @[] LOG: restartpoint complete: wrote 15437 buffers (2.9%); 0 transaction log file(s) added, 0 removed, 5 recycled; write=269.358 s, sync=0.035 s, total=269.397 s; sync files=202, longest=0.008 s, average=0.000 s < @[] LOG: recovery restart point at 650/4D01CCA0 < @[] DETAIL: last completed transaction was at log time 2015-06-16 21:41:41.990409+00 < @[] LOG: restartpoint starting: time < @[] LOG: restartpoint complete: wrote 115 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 12 recycled; write=11.446 s, sync=0.005 s, total=11.455 s; sync files=29, longest=0.001 s, average=0.000 s < @[] LOG: recovery restart point at 650/5204B6C8 < @[] DETAIL: last completed transaction was at log time 2015-06-16 21:42:24.524081+00 < @[] FATAL: could not send data to WAL stream: SSL error: unexpected record < @[] LOG: unexpected pageaddr 650/18000000 in log segment 00000001000006500000005A, offset 0 And a ready file appeared and stayed for 000000010000065000000059 : -rw------- 1 postgres postgres 0 Jun 16 21:57 000000010000065000000059.ready On my other streaming replica, there are lots of these log messages, and it looks like there is also a ready file for each of the segments previous to the segment mentioned in the unexpected pageaddr message. Hope this helps. Please let me know if I can gather further data to help fix this. =) Regards, Lacey
Re: Jeff Frost 2015-06-16 <67E2F20A-6A2E-484E-BF97-544F1FC66566@pgexperts.com> > Iâve seen this before, but havenât been able to make a reproducible test case yet. > > Are you by chance using SSL to talk to the primary server? Is the ssl_renegotiation_limit the default of 512MB? 32 WALfiles at 16MB each = 512MB. I found that it would always leave the WAL file from before the invalid record length message. Does that seem to be the case for you as well? Yes, SSL, with default settings. I can confirm your wal-file-from-before analysis: Jun 16 07:14:59 synthesis postgres[32525]: [8-1] 2015-06-16 07:14:59 GMT LOG: unexpected pageaddr 33/39000000 in log segment000000010000003300000040, offset 0 Jun 16 07:15:00 synthesis postgres[11514]: [3-1] 2015-06-16 07:15:00 GMT LOG: started streaming WAL from primary at 33/40000000on timeline 1 -rw------- 1 postgres postgres 16777216 Jun 16 09:14 00000001000000330000003F Jun 16 17:55:01 synthesis postgres[32525]: [9-1] 2015-06-16 17:55:01 GMT LOG: unexpected pageaddr 33/5A000000 in log segment000000010000003300000060, offset 0 Jun 16 17:55:02 synthesis postgres[24337]: [3-1] 2015-06-16 17:55:02 GMT LOG: started streaming WAL from primary at 33/60000000on timeline 1 -rw------- 1 postgres postgres 16777216 Jun 16 19:55 00000001000000330000005F Jun 17 04:35:02 synthesis postgres[24337]: [4-1] 2015-06-17 04:35:02 GMT FATAL: could not send data to WAL stream: serverclosed the connection unexpectedly Jun 17 04:35:02 synthesis postgres[24337]: [4-2] This probably means the server terminated abnormally Jun 17 04:35:02 synthesis postgres[24337]: [4-3] before or while processing the request. Jun 17 04:35:02 synthesis postgres[24337]: [4-4] Jun 17 04:35:04 synthesis postgres[32525]: [10-1] 2015-06-17 04:35:04 GMT LOG: unexpected pageaddr 33/7B000000 in log segment000000010000003300000080, offset 0 Jun 17 04:35:05 synthesis postgres[4756]: [5-1] 2015-06-17 04:35:05 GMT LOG: started streaming WAL from primary at 33/80000000on timeline 1 -rw------- 1 postgres postgres 16777216 Jun 17 06:35 00000001000000330000007F There's a 1:1 correspondence with log and leaked files. Christoph -- cb@df7cb.de | http://www.df7cb.de/
Sent from my iPhone > On Jun 17, 2015, at 03:22, Christoph Berg <cb@df7cb.de> wrote: >=20 > Re: Jeff Frost 2015-06-16 <67E2F20A-6A2E-484E-BF97-544F1FC66566@pgexperts.= com> >=20 > Yes, SSL, with default settings. I can confirm your > wal-file-from-before analysis: >=20 > Jun 16 07:14:59 synthesis postgres[32525]: [8-1] 2015-06-16 07:14:59 GMT L= OG: unexpected pageaddr 33/39000000 in log segment 000000010000003300000040= , offset 0 > Jun 16 07:15:00 synthesis postgres[11514]: [3-1] 2015-06-16 07:15:00 GMT L= OG: started streaming WAL from primary at 33/40000000 on timeline 1 >=20 > -rw------- 1 postgres postgres 16777216 Jun 16 09:14 00000001000000330000= 003F >=20 > Jun 16 17:55:01 synthesis postgres[32525]: [9-1] 2015-06-16 17:55:01 GMT L= OG: unexpected pageaddr 33/5A000000 in log segment 000000010000003300000060= , offset 0 > Jun 16 17:55:02 synthesis postgres[24337]: [3-1] 2015-06-16 17:55:02 GMT L= OG: started streaming WAL from primary at 33/60000000 on timeline 1 >=20 > -rw------- 1 postgres postgres 16777216 Jun 16 19:55 00000001000000330000= 005F >=20 > Jun 17 04:35:02 synthesis postgres[24337]: [4-1] 2015-06-17 04:35:02 GMT FA= TAL: could not send data to WAL stream: server closed the connection unexpe= ctedly > Jun 17 04:35:02 synthesis postgres[24337]: [4-2] This probably mea= ns the server terminated abnormally > Jun 17 04:35:02 synthesis postgres[24337]: [4-3] before or while p= rocessing the request. > Jun 17 04:35:02 synthesis postgres[24337]: [4-4] > Jun 17 04:35:04 synthesis postgres[32525]: [10-1] 2015-06-17 04:35:04 GMT L= OG: unexpected pageaddr 33/7B000000 in log segment 000000010000003300000080= , offset 0 > Jun 17 04:35:05 synthesis postgres[4756]: [5-1] 2015-06-17 04:35:05 GMT LO= G: started streaming WAL from primary at 33/80000000 on timeline 1 >=20 > -rw------- 1 postgres postgres 16777216 Jun 17 06:35 00000001000000330000= 007F >=20 > There's a 1:1 correspondence with log and leaked files. We thought it was related to the ssl renegotiation limit, but reducing it di= dn't seem to make it happen more often.=20 The problem was that I couldn't seem to make a reproducible test case with p= gbench and two servers, so it seems there is slightly more at play.=20 I believe setting the ssl renegotiation limit to 0 made it stop. Can you con= firm? Have you been able to reproduce synthetically?=
Re: Jeff Frost 2015-06-17 <AF73F62A-B83A-41A3-9CAA-CCFFDC4DB204@pgexperts.com> > We thought it was related to the ssl renegotiation limit, but reducing it didn't seem to make it happen more often. > > The problem was that I couldn't seem to make a reproducible test case with pgbench and two servers, so it seems there isslightly more at play. > > I believe setting the ssl renegotiation limit to 0 made it stop. Can you confirm? I've configured that, we'll see later today. > Have you been able to reproduce synthetically? No. I managed to make the test setup leak one file when the slave server was restarted, but atm it doesn't reconnect/barf every 512MB. I'm probably still missing some parameter. (sslcompression=0 was the first I tried...) Christoph -- cb@df7cb.de | http://www.df7cb.de/
Re: To Jeff Frost 2015-06-18 <20150618105305.GA22374@msg.df7cb.de> > > I believe setting the ssl renegotiation limit to 0 made it stop. Can you confirm? > > I've configured that, we'll see later today. 0 makes it stop. > > Have you been able to reproduce synthetically? > > No. I managed to make the test setup leak one file when the slave > server was restarted, but atm it doesn't reconnect/barf every 512MB. > I'm probably still missing some parameter. (sslcompression=0 was the > first I tried...) (Still no success there.) Christoph -- cb@df7cb.de | http://www.df7cb.de/
> On Jun 19, 2015, at 7:50 AM, Christoph Berg <cb@df7cb.de> wrote: >=20 > Re: To Jeff Frost 2015-06-18 <20150618105305.GA22374@msg.df7cb.de> >>> I believe setting the ssl renegotiation limit to 0 made it stop. Can = you confirm? >>=20 >> I've configured that, we'll see later today. >=20 > 0 makes it stop. >=20 >>> Have you been able to reproduce synthetically? >>=20 >> No. I managed to make the test setup leak one file when the slave >> server was restarted, but atm it doesn't reconnect/barf every 512MB. >> I'm probably still missing some parameter. (sslcompression=3D0 was = the >> first I tried...) >=20 > (Still no success there.) I had thought it was fixed on 9.2 by a recent update (not the last 3, = but the one before) as it seemed to stop doing this, but then it started = again after a few days, so there may be some large amount of = transactions required before the funny business begins. I would really love to deliver a self contained test case, but I tried = for a few days unsuccessfully to reproduce it, but I still see it = happening on 9.4.4 and 9.2.13, but not on all servers. :-/=