Strange time for LOGBUFF warning...
A DBA saw the alert "Checkpoint log record may not fit into the logical log buffer. Recommended minimum value for LOGBUFF is 34" appear mid-morning as connection counts climbed, even though actual checkpoint records were only 36 bytes and log activity was modest. Respondents (Renaut, Kagel, IBM's John Miller) explained the engine computes a worst case where every connected user has an open transaction at checkpoint time; if that record could exceed LOGBUFF, a partial write risks an unrecoverable crash. The fix is simply to raise LOGBUFF above the recommended 34K, and the poster accepted the explanation.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Informix Dudettes and Dudes - I wanna float something up the flag pole here and see if it flies. Don't yell at me if I am off base though, I am tryin' to be smart here... On two of our production instances we got an email this morning re: Event severity is: 3 Event class id is: 7 Event class msg is: Dynamic Server Initialization failure. Event specific msg is: Checkpoint log record may not fit into the logical log buffer. Recommended minimum value for LOGBUFF is 34. See also is: Environment is: prodserv I looked in the online.log for this instance and saw: 09:07:03 Maximum server connections 271 09:17:03 Checkpoint Completed: duration was 0 seconds. 09:17:03 Checkpoint loguniq 57480, logpos 0x5cc018, timestamp: 0x5ce22977 09:17:03 Maximum server connections 417 09:27:03 Checkpoint Completed: duration was 0 seconds. 09:27:03 Checkpoint loguniq 57480, logpos 0x61b70c, timestamp: 0x5ce2766a 09:27:03 Maximum server connections 561 09:28:50 Checkpoint log record may not fit into the logical log buffer. Recommended minimum value for LOGBUFF is 34. 09:32:03 Checkpoint Completed: duration was 0 seconds. 09:32:03 Checkpoint loguniq 57480, logpos 0x8b1018, timestamp: 0x5cea01ec 09:32:03 Maximum server connections 684 09:37:03 Checkpoint Completed: duration was 0 seconds. 09:37:03 Checkpoint loguniq 57480, logpos 0x8b9018, timestamp: 0x5cea0534 Although it appears we are supporting an increased user load between checkpoints, we are not exactly rolling through our logs - 749 logical log pages were used between the time of the checkpoint 9:17 and the one at 9:37. The other instance's online log is similar to this one - it does show more logging activity however. We want to know why the engine decided to deliver the warning message that it did? Does the engine suspect that since the user load is increasing that there will likely be a corresponding increase in logging such that it delivers the warning message? Kind of like the engine saying: "Dude we know you only have a 32 K size pool, and there are lots of swimmers who are showing up. We don't know if they are gonna swim or just sit on the side and drink margarita's but if they decide to swim you're gonna need a bigger pool." Mike
If I remember correctly the warning was caused by the increase in users. The engine computes some sort of worse case event where all active users would have open transactions at a checkpoint, and if the size of that worse case checkpoint record is greater then your current actual LOGBUFF value, you'll see that message. (Since a checkpoint record contains information about all current open transactions, the larger the number of open transactions, the larger your checkpoint record would be)
It's not complaining about the logical logs themselves. It is complaining about the size set in LOGBUFF which, apparently, is less than 34K. It's telling you that the checkpoint records it has to write have grown such that they no longer fit into a single log buffer (sized by LOGBUFF). This is dangerous because the engine could crash with only part of the checkpoint record written to disk which would likely prevent the engine from restarting after the crash. The likelyhood of this happening is exascerbated if you are using BUFFERED logging. The solution is to increase LOGBUFF so that it is larger than 34K, as suggested in your message log. Art On Mon, Jun 23, 2008 at 11:33 AM, MIKE MAGIE <jmmagie@yahoo.com> wrote: > Informix Dudettes and Dudes - > > I wanna float something up the flag pole here and see if it flies. Don't > yell > at me if I am off base though, I am tryin' to be smart here... > > On two of our production instances we got an email this morning re: > > Event severity is: 3 > Event class id is: 7 > Event class msg is: Dynamic Server Initialization failure. > Event specific msg is: Checkpoint log record may not fit into the logical > log > buffer. > Recommended minimum value for LOGBUFF is 34. > See also is: > Environment is: prodserv > > I looked in the online.log for this instance and saw: > > 09:07:03 Maximum server connections 271 > 09:17:03 Checkpoint Completed: duration was 0 seconds. > 09:17:03 Checkpoint loguniq 57480, logpos 0x5cc018, timestamp: 0x5ce22977 > > 09:17:03 Maximum server connections 417 > 09:27:03 Checkpoint Completed: duration was 0 seconds. > 09:27:03 Checkpoint loguniq 57480, logpos 0x61b70c, timestamp: 0x5ce2766a > > 09:27:03 Maximum server connections 561 > 09:28:50 Checkpoint log record may not fit into the logical log buffer. > Recommended minimum value for LOGBUFF is 34. > 09:32:03 Checkpoint Completed: duration was 0 seconds. > 09:32:03 Checkpoint loguniq 57480, logpos 0x8b1018, timestamp: 0x5cea01ec > > 09:32:03 Maximum server connections 684 > 09:37:03 Checkpoint Completed: duration was 0 seconds. > 09:37:03 Checkpoint loguniq 57480, logpos 0x8b9018, timestamp: 0x5cea0534 > > Although it appears we are supporting an increased user load between > checkpoints, we are not exactly rolling through our logs - 749 logical log > pages were used between the time of the checkpoint 9:17 and the one at > 9:37. > The other instance's online log is similar to this one - it does show more > logging activity however. > > We want to know why the engine decided to deliver the warning message that > it > did? Does the engine suspect that since the user load is increasing that > there > will likely be a corresponding increase in logging such that it delivers > the > warning message? Kind of like the engine saying: > > "Dude we know you only have a 32 K size pool, and there are lots of > swimmers > who are showing up. We don't know if they are gonna swim or just sit on the > side and drink margarita's but if they decide to swim you're gonna need a > bigger pool." > > Mike > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > -- Art S. Kagel Oninit (www.oninit.com) IIUG Board of Directors (art@iiug.org) Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Oninit, the IIUG, nor any other organization with which I am associated either explicitly or implicitly. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves.
Thanks for looking at this Art -
But I dunno - the part about the checkpoint log record growing sounds fishy.
None of the checkpoint records were larger than 36 bytes:
Here is some onlog output - all of the CKPOINTS were the same size. We're not
checkpointing with a ton of open tx's or anything:
13f018 36 CKPOINT 1 57480 0 0
146018 36 CKPOINT 1 57480 0 0
147018 36 CKPOINT 1 57480 0 0
148018 36 CKPOINT 1 57480 0 0
14f018 36 CKPOINT 1 57480 0 0
1c74a4 36 CKPOINT 1 57480 0 0
463018 36 CKPOINT 1 57480 0 0
46d018 36 CKPOINT 1 57480 0 0
473018 36 CKPOINT 1 57480 0 0
55a018 36 CKPOINT 1 57480 0 0
I am satisfied with J Pierre Renaut's response.
MM
I wish we had an edit feature on here... I re-read your post Art see that you were saying pretty much the same thing that Jacques was - It's all good. The engine is just looking after us... MM
Mike:
I think you might want to listen to Art on this one. It is not as fish=
as
it
may sound. Your current checkpoint does not have any open transaction=
but that not to say your future checkpoints will not. hit the worst
possible case
which is the current number of users (actually the current number of
open transactions). In which case the system will shutdown on you when=
trying to write this logical log record because it would not be recover=
able
through fast recovery or archive restore while rolling for this checkpo=
int
record.
John F. Miller III
STSM, Support Architect
miller3@us.ibm.com
503-578-5645
IBM Informix Dynamic Server (IDS)
=
"MIKE MAGIE" =
<jmmagie@yahoo.co =
m> =
To
Sent by: ids@iiug.org =
ids-bounces@iiug. =
cc
org =
Subj=
ect
Re: Strange time for LOGBUFF =
06/23/2008 10:40 warning... [12484] =
AM =
=
=
Please respond to =
ids@iiug.org =
=
=
Thanks for looking at this Art -
But I dunno - the part about the checkpoint log record growing sounds
fishy.
None of the checkpoint records were larger than 36 bytes:
Here is some onlog output - all of the CKPOINTS were the same size. We'=
re
not
checkpointing with a ton of open tx's or anything:
13f018 36 CKPOINT 1 57480 0 0
146018 36 CKPOINT 1 57480 0 0
147018 36 CKPOINT 1 57480 0 0
148018 36 CKPOINT 1 57480 0 0
14f018 36 CKPOINT 1 57480 0 0
1c74a4 36 CKPOINT 1 57480 0 0
463018 36 CKPOINT 1 57480 0 0
46d018 36 CKPOINT 1 57480 0 0
473018 36 CKPOINT 1 57480 0 0
55a018 36 CKPOINT 1 57480 0 0
I am satisfied with J Pierre Renaut's response.
MM
***********************************************************************=
********
Forum Note: Use "Reply" to post a response in the discussion forum.
=