Re: The mystery of the disappearing dbspaces ...
Posted in 2008
On IDS 10.00.FC8 under RHEL 5, Neil Truby built a new instance, added logical logs to llogdbs and three temp dbspaces, then changed PHYSDBS/PHYSFILE in the ONCONFIG and bounced the engine (onmode -ky) to move the physical log. On restart, four dbspaces and the added logs had vanished; the server ran fast recovery from log 4 even though the shutdown checkpoint was in log 9, suggesting it read a stale checkpoint reserve page. Suggestions included using onparams -p rather than editing ONCONFIG, shutting down with onmode -uky, taking an archive after adding spaces, comparing oncheck -pr output to verify alternating reserve-page writes, and possible lost OS buffered writes on cooked files. No resolution or root cause is recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Neil Truby wrote:
> IDS 10.0FC8 on RHEL 5.
>
> Here's a funny old thing!
> I'm just building a new database server.
> I have 6 dbspaces so far: root, physdbs, llogdbs, and tempdbs1-3
>
> You can see that I'm adding the logs to llogdbs. Then I shut down Informix
> and restart it to move the PHYSDBS.
>
> What do you know? 4 of my dbspaces have disappeared into thin air!
> Including the one "DBspace 3" that you can referenced in the log as having
> logical logs added to it.
>
> Don't know if
> 00:44:25 pid 26739: scan_eh_frame(): bad CIE reference> has anything to do with it.
>
> But it's spooky!
=========================================================
00:42:58 Maximum server connections 1
00:42:59 Log file 409 added to DBspace 3.
00:42:59 Checkpoint Completed: duration was 0 seconds.
00:42:59 Checkpoint loguniq 9, logpos 0xdf128, timestamp: 0x1053b
00:42:59 Maximum server connections 1
00:44:06 Log file 410 added to DBspace 3.
00:44:06 Checkpoint Completed: duration was 0 seconds.
00:44:06 Checkpoint loguniq 9, logpos 0xe1128, timestamp: 0x10f57
00:44:06 Maximum server connections 1
00:44:14 Checkpoint Completed: duration was 0 seconds.
00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
00:44:14 Maximum server connections 1
00:44:15 IBM Informix Dynamic Server Stopped.
00:44:24 IBM Informix Dynamic Server Started.
00:44:24 Segment locked: addr=0x44000000, size=3370373120
00:44:24 Segment locked: addr=0x10ce3d000, size=2621440000
Mon Mar 3 00:44:25 2008
00:44:25 pid 26739: scan_eh_frame(): bad CIE reference
00:44:26 Event alarms enabled. ALARMPROG =
'/opt/informix/10.0/etc/alarmprogram.sh'
00:44:26 Booting Language <c> from module <>
00:44:26 Loading Module <CNULL>
00:44:26 Booting Language <builtin> from module <>
00:44:26 Loading Module <BUILTINNULL>
00:44:31 DR: DRAUTO is 0 (Off)
00:44:31 IBM Informix Dynamic Server Version 10.00.FC8 Software SerialNumber AAA#B000000
00:44:31 IBM Informix Dynamic Server Initialized -- Shared MemoryInitialized.
00:44:31 Warning: Invalid (non-existent/blobspace/disabled) dbspace listed
in DBSPACETEMP: 'tempdbs1'
00:44:31 Warning: Invalid (non-existent/blobspace/disabled) dbspace listed
in DBSPACETEMP: 'tempdbs2'
00:44:31 Warning: Invalid (non-existent/blobspace/disabled) dbspace listed
in DBSPACETEMP: 'tempdbs3'
00:44:31 Physical Recovery Started at Page (1:1026).
00:44:31 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored.
00:44:31 Logical Recovery Started.
00:44:31 10 recovery worker threads will be started.
00:44:32 Fast Recovery Switching to Log 4
IBM Informix Dynamic Server Version 10.00.FC8 -- On-Line -- Up
00:08:10 -- 5851924 Kbytes
Dbspaces
address number flags fchunk nchunks pgsize flags
owner name
10d275e78 1 0x60001 1 1 2048 N B
informix rootdbs
10f20a1c8 2 0x60001 2 1 2048 N B
informix physdbs
2 active, 2047 maximum
Chunks
address chunk/dbs offset size free bpages
flags pathname
10d276028 1 1 0 51200 45411
PO-B /opt/informix/dbspaces1/rootdbs_1
10f20a028 2 2 0 512000 0
PO-B /opt/informix/dbspaces1/physdbs_1
2 active, 32766 maximum
NOTE: The values in the "size" and "free" columns for DBspace chunks are
displayed in terms of "pgsize" of the DBspace to which they belong.
Expanded chunk capacity mode: alway
=========================================================
Interesting ...
1. How are you shutting the engine down?
onmode -ky or onmode -uky??
I would suggest NOT onmode -uky as you are doing recovery work :
00:44:06 Maximum server connections 1
00:44:14 Checkpoint Completed: duration was 0 seconds.
00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
00:44:14 Maximum server connections 1
00:44:15 IBM Informix Dynamic Server Stopped.
...
(shutdown / start up).
00:44:31 10 recovery worker threads will be started.
00:44:32 Fast Recovery Switching to Log 4
2. Are you taking backups after adding dbspaces?
Perhaps not :-/ Although this is what it says to do (i.e. you will get a full checkpoint from doing an archive).
3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
How are you actually moving PHYSDBS (I assume you mean that you are moving the Physical Log file?)
onparams? or "Modify $ONCONFIG and restart"?
Ho humm.
"TBP (The Big Potato)" <TBP@NotHere.Co.Uk> wrote in message
news:f_Qyj.29341$d62.17568@newsfe6-gui.ntli.net...
>
> 1. How are you shutting the engine down?
onmode -ky>
> 2. Are you taking backups after adding dbspaces?
No. Well, I did the 2nd time I had to do it all ... ;-). I think the
message about taking archives is years old and is just a "good practice"
thing. I build hundreds of db servers a year and have never done it before.
> 3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
Er, not sure I understand the question. Who else is going to do it? The
Physical Log Fairy? ;-)
>> How are you actually moving PHYSDBS (I assume you mean that you are
>> moving the Physical Log file?)
By altering the values of PHYSDBS and PHYSFILE and re-cycling the IDS
instance.
Neil Truby wrote:
> "TBP (The Big Potato)" <TBP@NotHere.Co.Uk> wrote in message
> news:f_Qyj.29341$d62.17568@newsfe6-gui.ntli.net...
>
>>1. How are you shutting the engine down?
>
> onmode -ky>
Always use onmode -uky - keeps life straight forward (i.e transactions are killed on shutdown, and no recovery required on startup)
If you start recovery at Log 4, and you added the dbspaces / moved the logs in log 9, then you will see some "oddities" or
"rollforward requirements" - Personally I do no like rolling forward things like log additions or dbspace additions.
>
>>2. Are you taking backups after adding dbspaces?
>
> No. Well, I did the 2nd time I had to do it all ... ;-). I think the
> message about taking archives is years old and is just a "good practice"
> thing. I build hundreds of db servers a year and have never done it before.
>
Err ... so "Good practice" ... :S
I would go through "set up all my dbspaces and logical logs and physical logs" then take an archive - not sure why you are shutting
down half way through a set up --- oh yes ... (see below)
>
>>3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
>
> Er, not sure I understand the question. Who else is going to do it? The
> Physical Log Fairy? ;-)
>
>
Is the Physical Log Fairy called onparams?
Usage: onparams -a -d <DBspace> [-s <size>] [-i] |
-b -g <pagesize> [-n <number of buffers>]
[-r <number of LRUs>] [-x <maxdirty>] [-m <mindirty>] |
-d -l <log file number> [-y] |
-m <param> <value> |
-p -s <size> [-d <DBspace>] [-y]
-a - Add a logical log file
-b - Add a buffer pool
-i - Insert after current log
-d - Drop a logical log file
-m - Modify the value of one of the following configuration parameters:
AFFAIL, AFCRASH, AFWARN, AFLINES, LTXHWM, LTXEHWM, DYNAMIC_LOGS
*-p - Change physical log size and location*
-y - Automatically responds "yes" to all prompts
Why not use onparams???
Neil Truby wrote:
> "TBP (The Big Potato)" <TBP@NotHere.Co.Uk> wrote in message
> news:f_Qyj.29341$d62.17568@newsfe6-gui.ntli.net...
>> 1. How are you shutting the engine down?
> onmode -ky>
This will not make a checkpoint...
>
>> 2. Are you taking backups after adding dbspaces?
> No. Well, I did the 2nd time I had to do it all ... ;-). I think the
> message about taking archives is years old and is just a "good practice"
> thing. I build hundreds of db servers a year and have never done it before.
>
It's nice you don't have to restore any of those servers at the wrong time :)
>> 3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
> Er, not sure I understand the question. Who else is going to do it? The
> Physical Log Fairy? ;-)
>
>>> How are you actually moving PHYSDBS (I assume you mean that you are
>>> moving the Physical Log file?)
> By altering the values of PHYSDBS and PHYSFILE and re-cycling the IDS
> instance.
Don't do this without making a checkpoint...
You may want to read the list of parameters to be removed in the beta version...
onparams is the right tool to do it. You'll have to be in quiescent mode...
On 11+ you can do it with the Admin API also...
Regards.
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
On Mar 3, 4:46 pm, Fernando Nunes <s...@onlinedomus.net> wrote:
> Neil Truby wrote:
> > "TBP (The Big Potato)" <T...@NotHere.Co.Uk> wrote in message
> >news:f_Qyj.29341$d62.17568@newsfe6-gui.ntli.net...
> >> 1. How are you shutting the engine down?
> > onmode -ky>>
> This will not make a checkpoint...
>
onmode -ky certainly does attempt to perform a checkpoint before bringthe server off-line. It does not guarantee a checkpoint will
complete, and with the -y you don't get a message that it doesn't
compete (if no -y you would get a message about the checkpoint not
completing), but it does try to do one. You can even see the
checkpoint completed from the MSGPATH file included in the original
post:
00:44:06 Maximum server connections 1
00:44:14 Checkpoint Completed: duration was 0 seconds.
00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
00:44:14 Maximum server connections 1
00:44:15 IBM Informix Dynamic Server Stopped.
So it checkpointed immediately before the stopped message.
Jacques
>
>
> >> 2. Are you taking backups after adding dbspaces?
> > No. Well, I did the 2nd time I had to do it all ... ;-). I think the
> > message about taking archives is years old and is just a "good practice"
> > thing. I build hundreds of db servers a year and have never done it before.
>
> It's nice you don't have to restore any of those servers at the wrong time :)
>
> >> 3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
> > Er, not sure I understand the question. Who else is going to do it? The
> > Physical Log Fairy? ;-)
>
> >>> How are you actually moving PHYSDBS (I assume you mean that you are
> >>> moving the Physical Log file?)
> > By altering the values of PHYSDBS and PHYSFILE and re-cycling the IDS
> > instance.
>
> Don't do this without making a checkpoint...
> You may want to read the list of parameters to be removed in the beta version...
>
> onparams is the right tool to do it. You'll have to be in quiescent mode...
> On 11+ you can do it with the Admin API also...
>
> Regards.
>
> --
> Fernando Nunes
> Portugal
>
> http://informix-technology.blogspot.com
> My email works... but I don't check it frequently...
>
> Interesting ...
>
> 1. How are you shutting the engine down?
>
> onmode -ky or onmode -uky??>
> I would suggest NOT onmode -uky as you are doing recovery work :
>
> 00:44:06 Maximum server connections 1
> 00:44:14 Checkpoint Completed: duration was 0 seconds.
> 00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
>
> 00:44:14 Maximum server connections 1
> 00:44:15 IBM Informix Dynamic Server Stopped.
> ...
> (shutdown / start up).
>
> 00:44:31 10 recovery worker threads will be started.
> 00:44:32 Fast Recovery Switching to Log 4>
This is an interesting point, as the checkpoint immediately completed
before the server comes offline is in loguniq 9, however, when the
server starts up fast recovery it's going back to loguniq 4 (possibly
back to 3 as I think that message is put into the log when the server
switches from loguniq 3 to loguniq 4). That's obviously 5 logs before
the most current two checkpoints. I can't even begin to think of how
the server could have retained information for such an old
checkpoint. According to the MSGPATH info you provided, the server
should only be keeping track of the 2 most recent checkpoints, and
those should have been at 00:44:06 and 00:44:14 (for the info below)
00:44:06 Checkpoint Completed: duration was 0 seconds.
00:44:06 Checkpoint loguniq 9, logpos 0xe1128, timestamp: 0x10f57
00:44:06 Maximum server connections 1
00:44:14 Checkpoint Completed: duration was 0 seconds.
00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
The server is supposed to alternate writes to the checkpoint reserve
pages and then pick the most recent one when coming online, so it
almost seems as though the server isn't alternating it's writes to the
reserve pages all the time, and then when it came online, it was
picked the wrong page of the 2 (it picked the older one) which must
have had a checkpoint back from loguniq 4. I guess to make sure the
alternating writes is happening, you might want to look at some
oncheck -pr output. Like add 1 chunk, dbspace, or log, force acheckpoint, do an oncheck -pr redirected to a file, then add another
chunk, dbspace, or log and do another checkpoint, and another oncheck -
pr and make sure it's alternated from whatever page it was using in
the 1st -pr to the other in the 2nd, and also verify that you are
seeing the most current information (like both things that you did add
really are there).
I guess I would be really curious to see a couple more lines down in
your MSGPATH to see what loguniq the checkpoint got that is the
checkpoint the server does when it comes online and completes
recovery. I would assume that since you were missing dbspaces and
logs that the checkpoint would be something in loguniq 4 and so
somehow your server basically when back in time (which shouldn't be
possible since it should only have information for the 2 most recent
checkpoints) to before those dbspaces and logs were added and then
wasn't able to roll forward to add them back.
> -----Original Message-----
> From: informix-list-bounces@iiug.org [mailto:informix-list-
> bounces@iiug.org] On Behalf Of jprenaut@yahoo.com
> Sent: Monday, March 03, 2008 7:47 PM
> To: informix-list@iiug.org
> Subject: Re: The mystery of the disappearing dbspaces ...
>
>
> >
> > Interesting ...
> >
> > 1. How are you shutting the engine down?
> >
> > onmode -ky or onmode -uky??> >
> > I would suggest NOT onmode -uky as you are doing recovery work :
> >
> > 00:44:06 Maximum server connections 1
> > 00:44:14 Checkpoint Completed: duration was 0 seconds.
> > 00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
> >
> > 00:44:14 Maximum server connections 1
> > 00:44:15 IBM Informix Dynamic Server Stopped.
> > ...
> > (shutdown / start up).
> >
> > 00:44:31 10 recovery worker threads will be started.
> > 00:44:32 Fast Recovery Switching to Log 4> >
>
> This is an interesting point, as the checkpoint immediately completed
> before the server comes offline is in loguniq 9, however, when the
> server starts up fast recovery it's going back to loguniq 4 (possibly
> back to 3 as I think that message is put into the log when the server
> switches from loguniq 3 to loguniq 4). That's obviously 5 logs before
> the most current two checkpoints. I can't even begin to think of how
> the server could have retained information for such an old
> checkpoint. According to the MSGPATH info you provided, the server
> should only be keeping track of the 2 most recent checkpoints, and
> those should have been at 00:44:06 and 00:44:14 (for the info below)
>
> 00:44:06 Checkpoint Completed: duration was 0 seconds.
> 00:44:06 Checkpoint loguniq 9, logpos 0xe1128, timestamp: 0x10f57
>
> 00:44:06 Maximum server connections 1
> 00:44:14 Checkpoint Completed: duration was 0 seconds.
> 00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64>
> The server is supposed to alternate writes to the checkpoint reserve
> pages and then pick the most recent one when coming online, so it
> almost seems as though the server isn't alternating it's writes to the
> reserve pages all the time, and then when it came online, it was
> picked the wrong page of the 2 (it picked the older one) which must
> have had a checkpoint back from loguniq 4. I guess to make sure the
> alternating writes is happening, you might want to look at some
> oncheck -pr output. Like add 1 chunk, dbspace, or log, force a> checkpoint, do an oncheck -pr redirected to a file, then add another
> chunk, dbspace, or log and do another checkpoint, and another oncheck
-
> pr and make sure it's alternated from whatever page it was using in
> the 1st -pr to the other in the 2nd, and also verify that you are
> seeing the most current information (like both things that you did add
> really are there).
>
> I guess I would be really curious to see a couple more lines down in
> your MSGPATH to see what loguniq the checkpoint got that is the
> checkpoint the server does when it comes online and completes
> recovery. I would assume that since you were missing dbspaces and
> logs that the checkpoint would be something in loguniq 4 and so
> somehow your server basically when back in time (which shouldn't be
> possible since it should only have information for the 2 most recent
> checkpoints) to before those dbspaces and logs were added and then
> wasn't able to roll forward to add them back.
Neil, are you using cooked files for your chunks? Is it somehow
possible that the write(s) to the reserved pages did not actually
happen, but got lost in the OS write buffer?? A shot in the dark, I
know...
HTH,
Paul M.
jprenaut@yahoo.com wrote:
> On Mar 3, 4:46 pm, Fernando Nunes <s...@onlinedomus.net> wrote:
>> Neil Truby wrote:
>>> "TBP (The Big Potato)" <T...@NotHere.Co.Uk> wrote in message
>>> news:f_Qyj.29341$d62.17568@newsfe6-gui.ntli.net...
>>>> 1. How are you shutting the engine down?
>>> onmode -ky>>> This will not make a checkpoint...
>>
>
> onmode -ky certainly does attempt to perform a checkpoint before bring> the server off-line. It does not guarantee a checkpoint will
> complete, and with the -y you don't get a message that it doesn't
> compete (if no -y you would get a message about the checkpoint not
> completing), but it does try to do one. You can even see the
> checkpoint completed from the MSGPATH file included in the original
> post:
>
> 00:44:06 Maximum server connections 1
> 00:44:14 Checkpoint Completed: duration was 0 seconds.
> 00:44:14 Checkpoint loguniq 9, logpos 0xe3018, timestamp: 0x10f64
>
> 00:44:14 Maximum server connections 1
> 00:44:15 IBM Informix Dynamic Server Stopped.>
> So it checkpointed immediately before the stopped message.
>
> Jacques
>
>>
>>>> 2. Are you taking backups after adding dbspaces?
>>> No. Well, I did the 2nd time I had to do it all ... ;-). I think the
>>> message about taking archives is years old and is just a "good practice"
>>> thing. I build hundreds of db servers a year and have never done it before.
>> It's nice you don't have to restore any of those servers at the wrong time :)
>>
>>>> 3. Why are YOU shutting down and restarting Informix to move the PHYSDBS?
>>> Er, not sure I understand the question. Who else is going to do it? The
>>> Physical Log Fairy? ;-)
>>>>> How are you actually moving PHYSDBS (I assume you mean that you are
>>>>> moving the Physical Log file?)
>>> By altering the values of PHYSDBS and PHYSFILE and re-cycling the IDS
>>> instance.
>> Don't do this without making a checkpoint...
>> You may want to read the list of parameters to be removed in the beta version...
>>
>> onparams is the right tool to do it. You'll have to be in quiescent mode...
>> On 11+ you can do it with the Admin API also...
>>
>> Regards.
>>
>> --
>> Fernando Nunes
>> Portugal
>>
>> http://informix-technology.blogspot.com
>> My email works... but I don't check it frequently...
>
My mistake... which version did you use?
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...