Обсуждение: Apparent Wraparound?
Hi there, I just found the following message in my logs: Jun 8 10:38:38 caligula postgres[56868]: [1-1] : LOG: could not truncate directory "pg_subtrans": apparent wraparound Should I be worried or can I just ignore this one? My database is still small (a pg_dumpall bzippe'd is still around 500KB) so I doubt that I'm affected by any transaction id wraparound problems. I also vacuum analyze once a day and have pg_autovacuum turned on. Gunther
Gunther Mayer wrote: > Hi there, > > I just found the following message in my logs: > > Jun 8 10:38:38 caligula postgres[56868]: [1-1] : LOG: could not > truncate directory "pg_subtrans": apparent wraparound > > Should I be worried or can I just ignore this one? My database is still > small (a pg_dumpall bzippe'd is still around 500KB) so I doubt that I'm > affected by any transaction id wraparound problems. I also vacuum > analyze once a day and have pg_autovacuum turned on. What version are you running? This seems to match the description of a bug fixed for 8.2 and 8.1.5: revision 1.20 date: 2006-07-19 20:46:42 -0400; author: tgl; state: Exp; lines: +8 -3; Don't try to truncate multixact SLRU files in checkpoints done during xlog recovery. In the first place, it doesn't work because slru's latest_page_number isn't set up yet (this is why we've been hearing reports of strange "apparent wraparound" log messages during crash recovery, but only from people who'd managed to advance their next-mxact counters some considerable distance from 0). In the second place, it seems a bit unwise to be throwing away data during crash recovery anwyway. This latter consideration convinces me to just disable truncation during recovery, rather than computing latest_page_number and pushing ahead. -- Alvaro Herrera http://www.amazon.com/gp/registry/CTMLCN8V17R4 "La verdad no siempre es bonita, pero el hambre de ella sí"
On Jun 8, 3:23 pm, alvhe...@commandprompt.com (Alvaro Herrera) wrote: > Gunther Mayer wrote: > > Hi there, > > > I just found the following message in my logs: > > > Jun 8 10:38:38 caligula postgres[56868]: [1-1] : LOG: could not > > truncate directory "pg_subtrans": apparent wraparound > > > Should I be worried or can I just ignore this one? My database is still > > small (a pg_dumpall bzippe'd is still around 500KB) so I doubt that I'm > > affected by any transaction id wraparound problems. I also vacuum > > analyze once a day and have pg_autovacuum turned on. > > What version are you running? This seems to match the description of a > bug fixed for 8.2 and 8.1.5: > I noticed the same message in my logfiles (once on each of two servers). I'm running 8.1.8, and the server's been running flawless for about 2 months. Gerhard
On Jun 13, 2:35 pm, g.hinterma...@inode.at wrote: > On Jun 8, 3:23 pm, alvhe...@commandprompt.com (Alvaro Herrera) wrote: > > > > > Gunther Mayer wrote: > > > Hi there, > > > > I just found the following message in my logs: > > > > Jun 8 10:38:38 caligula postgres[56868]: [1-1] : LOG: could not > > > truncate directory "pg_subtrans": apparent wraparound > > > > Should I be worried or can I just ignore this one? My database is still > > > small (a pg_dumpall bzippe'd is still around 500KB) so I doubt that I'm > > > affected by any transaction id wraparound problems. I also vacuum > > > analyze once a day and have pg_autovacuum turned on. > > > What version are you running? This seems to match the description of a > > bug fixed for 8.2 and 8.1.5: > > I noticed the same message in my logfiles (once on each of two > servers). I'm running 8.1.8, and the server's been running flawless > for about 2 months. > > Gerhard Can someone tell me if I should be concerned about this log entry ? My database is quite large (~ 2G in PGDATA) regards Gerhard
On Jun 18, 11:08 am, g.hinterma...@inode.at wrote: > On Jun 13, 2:35 pm, g.hinterma...@inode.at wrote: > > Can someone tell me if I should be concerned about this log entry ? My > database is quite large (~ 2G in PGDATA) > > regards > Gerhard BTW, I do not use autovacuum, and run vacuumdb on a weekly basis. regards Gerhard
g.hintermayer@inode.at wrote: > On Jun 18, 11:08 am, g.hinterma...@inode.at wrote: > > On Jun 13, 2:35 pm, g.hinterma...@inode.at wrote: > > > > Can someone tell me if I should be concerned about this log entry ? My > > database is quite large (~ 2G in PGDATA) > > BTW, I do not use autovacuum, and run vacuumdb on a weekly basis. Ok, here is what I can tell you: 1. this message can only appear during checkpoint. 2. this message, by itself, is harmless. All it says is that it tried to truncate (meaning, removing files previous to the segments in active use) the multixact system (directory PGDATA/pg_multixact) and it couldn't find an appropriate truncating point. 3. If it cannot find a truncating point, it logs this message and then moves the "already truncated" point to the requested truncating point. This means that some files might remain on disk. This is harmless because they will be overwritten when the numbering mechanism wraps around and creates the same files again. Make sure we are actually talking about the same log message: it must mention the directory "pg_multixact". The only situation in which this could be an actual problem is when the numbering is actually wrapping around very quickly, i.e. faster than checkpoints. If you are using lots of multixacts then this may be possible -- I am not sure. You use multixacts by creating shared tuple locks, which in turn are created when foreign keys are checked by more than one process at the same time. Questions: - what files are actually in PGDATA/pg_multixact/offsets and members? - do the multixact counters increase quickly? You can check them with pg_controldata -- Alvaro Herrera http://www.CommandPrompt.com/ The PostgreSQL Company - Command Prompt, Inc.
Aha, google thinks it's wise to make the last postings (probably if more than n ?) show only the poster name and make the name clickable. Not very userfriendly :-( but now i know it ;-) Sorry if that wasn't clear. I'm getting the same log entry as the original poster, i.e.: LOG: could not truncate directory "pg_subtrans": apparent wraparound. I'm just running an analysis of the "daily transaction id consumption" on my databases to see, if the uptime of the server matches with the time the wraparound was logged. Gerhard
g.hintermayer@inode.at wrote: > Aha, google thinks it's wise to make the last postings (probably if > more than n ?) show only the poster name and make the name clickable. > Not very userfriendly :-( but now i know it ;-) I don't very much understand what you mean. I do see that you said "I noticed the same message" that Gunther Meyer was reporting but you weren't very explicit. I feared that the directory mentioned was different. > Sorry if that wasn't clear. I'm getting the same log entry as the > original > poster, i.e.: LOG: could not truncate directory "pg_subtrans": > apparent > wraparound. Ok. > I'm just running an analysis of the "daily transaction id consumption" > on my databases to see, if the uptime of the server matches with the > time the wraparound was logged. Please check "MultiXact" id consumption. Do you mean that your server has crashed? -- Alvaro Herrera http://www.CommandPrompt.com/ PostgreSQL Replication, Consulting, Custom Development, 24x7 support
On Jun 18, 10:44 pm, alvhe...@commandprompt.com (Alvaro Herrera) wrote: > > Please check "MultiXact" id consumption. Do you mean that your server > has crashed? > How do I check MilitXact id consumption ? Is it "Latest checkpoint's NextXID:" in the output of pg_controldata ? transaction id consumption is ~ 350000 per day (extrapolated from 16 hours). No, the Server has been up for about 2 month (regular reboot due to kernel and postgresql upgrade to 8.1.8), was running before for 7 month flawless, and before that i migrated from 8.0 to 8.1.4 with a complete dump/restore). pg_multixact/members shows: -rw------- 1 postgres postgres 8192 Aug 30 2006 0000 pg_multixact/offsets shows: -rw------- 1 postgres postgres 8192 Apr 13 15:03 0000 pg_controldata shows: pg_control version number: 812 Catalog version number: 200510211 Database system identifier: 4969068620492422615 Database cluster state: in production pg_control last modified: Tue Jun 19 08:00:36 2007 Current log file ID: 10 Next log file segment: 102 Latest checkpoint location: A/65362150 Prior checkpoint location: A/652E091C Latest checkpoint's REDO location: A/65362150 Latest checkpoint's UNDO location: 0/0 Latest checkpoint's TimeLineID: 1 Latest checkpoint's NextXID: 99983151 Latest checkpoint's NextOID: 7758309 Latest checkpoint's NextMultiXactId: 1 Latest checkpoint's NextMultiOffset: 0 Time of latest checkpoint: Tue Jun 19 08:00:36 2007 Maximum data alignment: 4 Database block size: 8192 Blocks per segment of large relation: 131072 Bytes per WAL segment: 16777216 Maximum length of identifiers: 64 Maximum columns in an index: 32 Date/time type storage: floating-point numbers Maximum length of locale name: 128 LC_COLLATE: C LC_CTYPE: C regards Gerhard
g.hintermayer@inode.at wrote: > On Jun 18, 10:44 pm, alvhe...@commandprompt.com (Alvaro Herrera) > wrote: > > > > > Please check "MultiXact" id consumption. Do you mean that your server > > has crashed? > > > How do I check MilitXact id consumption ? Is it "Latest checkpoint's > NextXID:" in the output of pg_controldata ? No, it is these lines: > Latest checkpoint's NextMultiXactId: 1 > Latest checkpoint's NextMultiOffset: 0 Which are the initial values. This means that you haven't use MultiXacts at all! The message about failing to truncate the dir is certainly a bug, and certainly harmless. > transaction id consumption is ~ 350000 per day (extrapolated from 16 > hours). > No, the Server has been up for about 2 month (regular reboot due to > kernel and postgresql upgrade to 8.1.8), was running before for 7 > month flawless, and before that i migrated from 8.0 to 8.1.4 with a > complete dump/restore). And when was the message logged? -- Alvaro Herrera http://www.advogato.org/person/alvherre "Saca el libro que tu religión considere como el indicado para encontrar la oración que traiga paz a tu alma. Luego rebootea el computador y ve si funciona" (Carlos Duclós)
> And when was the message logged? > after the server was running with version 8.1.8 for about 2 month (actually it was Jun 13 on one server and Apr 5 on the other) and no similar log entries since then. Gerhard