IDS 9.30.TC2 Database Corruptions?! Help!
I am
running Informix Dynamic Server Version 9.30.TC2 on Windows 2000 SP4. We run a
custom application provided by an informix developer.
I'm not really sure what is causing it, and our application provider doesn't
seem to know either. We did have an unexpected shutdown, but I would be
suprised if it wasn't robust enough to handle that.
Below I have copied some of the error messages we have recorded in a *.log
file as well as from the Security Event log. Can anyone decipher them?
Currently one of our options is to restore an old backup, and lose over a
week's data, but I don't really want to do that. Generally the system seems
stable, except in a few areas.
Any ideas? Are there other places to look for error messages from IDS?
Thanks!
Craig.
14/2/05...
12:34:11 Assert Failed: Slot 1 not free in page 0x2c in partnum 0x20019b
12:34:11 Informix Dynamic Server Version 9.30.TC2
12:34:11 Who: Session(382, informix@MYSERVER.OURDOMAIN, 5280, 0)
Thread(423, sqlexec, 0, 1)
File: rsbitmap.c Line: 4349
12:34:11 Results: Internally corrected
12:34:11 stack trace for pid 3792 written to E:\\\\tmp\\\\af.58f0e23
12:34:11 See Also: E:\\\\tmp\\\\af.58f0e23
12:34:14 Releasing server from system block
12:34:21 Slot 1 not free in page 0x2c in partnum 0x20019b
12:34:21 Slot 1 not free in page 0x2c in partnum 0x20019b
12:34:21 Assert Failed: Slot allocation error for 'maindb:"root".studabsent'
12:34:21 Informix Dynamic Server Version 9.30.TC2
12:34:21 Who: Session(382, informix@MYSERVER.OURDOMAIN, 5280, 0)
Thread(423, sqlexec, 0, 1)
File: rsbitmap.c Line: 1759
12:34:21 Results: Internally corrected
12:34:21 Action: Run 'oncheck -cDI maindb:"root".studabsent'
12:34:21 stack trace for pid 3792 written to E:\\\\tmp\\\\af.58f0e23
12:34:21 See Also: E:\\\\tmp\\\\af.58f0e23
12:34:28 Slot allocation error for 'maindb:"root".studabsent'
12:34:28 Slot allocation error for 'maindb:"root".studabsent'
12:35:14 Fuzzy Checkpoint Completed: duration was 0 seconds, 88 buffers not
flushed.
12:35:14 Checkpoint loguniq 4494, logpos 0x1ba508
15:10:34 Logical Log 4495 Complete.
15:10:43 Assert Failed: Slot 1 not free in page 0x423 in partnum 0x20022d
15:10:43 Informix Dynamic Server Version 9.30.TC2
15:10:43 Who: Session(490, informix@MYSERVER.OURDOMAIN, 5644, 0)
Thread(529, sqlexec, 0, 1)
File: rsbitmap.c Line: 4349
15:10:43 Results: Internally corrected
15:10:43 stack trace for pid 3792 written to E:\\\\tmp\\\\af.5f932d3
15:10:43 See Also: E:\\\\tmp\\\\af.5f932d3
15:10:46 Releasing server from system block
15:10:52 Slot 1 not free in page 0x423 in partnum 0x20022d
15:10:52 Slot 1 not free in page 0x423 in partnum 0x20022d
15:10:52 Assert Failed: Slot allocation error for 'maindb:"root".paraddress'
15:10:52 Informix Dynamic Server Version 9.30.TC2
15:10:52 Who: Session(490, informix@MYSERVER.OURDOMAIN, 5644, 0)
Thread(529, sqlexec, 0, 1)
File: rsbitmap.c Line: 1759
15:10:52 Results: Internally corrected
15:10:52 Action: Run 'oncheck -cDI maindb:"root".paraddress'
15:10:52 stack trace for pid 3792 written to E:\\\\tmp\\\\af.5f932d3
15:10:52 See Also: E:\\\\tmp\\\\af.5f932d3
15:10:59 Slot allocation error for 'maindb:"root".paraddress'
15:10:59 Slot allocation error for 'maindb:"root".paraddress'
15:11:42 Fuzzy Checkpoint Completed: duration was 0 seconds, 129 buffers not
flushed.
15:11:42 Checkpoint loguniq 4496, logpos 0x1b444
16/2/05...
09:37:19 Assert Failed: Error updating table record.
09:37:19 Informix Dynamic Server Version 9.30.TC2
09:37:19 Who: Session(124, informix@MYSERVER.OURDOMAIN, 2168, 0)
Thread(187, sqlexec, 0, 1)
File: rsrwrite.c Line: 926
09:37:19 Results: Update failed
09:37:19 Action: Run 'oncheck -cDI maindb:"root".studabsent'
09:37:19 stack trace for pid 5844 written to E:\\\\tmp\\\\af.4a387ae
09:37:19 See Also: E:\\\\tmp\\\\af.4a387ae, shmem.4a387ae.0
09:37:22 Releasing server from system block
09:37:29 Error updating table record.
09:37:30 Error updating table record.
Event Type: Error
Event Source: OnLine
Event Category: None
Event ID: 3
Date: 16/02/2005
Time: 9:37:29 AM
User: N/A
Computer: MYSERVER
Description:
tass : Internal Subsystem failure: 'MT' Error updating table record.
Event Type: Error
Event Source: OnLine
Event Category: None
Event ID: 3
Date: 14/02/2005
Time: 3:10:59 PM
User: N/A
Computer: MYSERVER
Description:
tass : Internal Subsystem failure: 'MT' Slot allocation error for
'maindb:"root".paraddress'
Event Type: Error
Event Source: OnLine
Event Category: None
Event ID: 3
Date: 14/02/2005
Time: 3:10:52 PM
User: N/A
Computer: MYSERVER
Description:
tass : Internal Subsystem failure: 'MT' Slot 1 not free in page 0x423 in
partnum 0x20022d
Event Type: Error
Event Source: OnLine
Event Category: None
Event ID: 3
Date: 14/02/2005
Time: 12:34:28 PM
User: N/A
Computer: MYSERVER
Description:
tass : Internal Subsystem failure: 'MT' Slot allocation error for
'maindb:"root".studabsent'
Event Type: Error
Event Source: OnLine
Event Category: None
Event ID: 3
Date: 14/02/2005
Time: 12:34:21 PM
User: N/A
Computer: MYSERVER
Description:
tass : Internal Subsystem failure: 'MT' Slot 1 not free in page 0x2c in
partnum 0x20019b
Craig
Do you know what caused your server to fail? Can you bring the server up?
Have you run the onchecks of the tables listed in the Informix log?
It looks like you have had some disk corruption. Depending upon the source
you may or may not be able to repair. If you cannot repair then restore is
the only option.
I would seriously look at your backup procedures if you have to restore to a
week ago. You should be able to restore to minutes before the corruption
event.
HTH
MW
> -----Original Message-----
> From: forum.subscriber@iiug.org
> [mailto:forum.subscriber@iiug.org] On Behalf Of CRAIG JOHNSON
> Sent: Monday, 21 February 2005 8:44 p.m.
> To: ids@iiug.org
> Subject: IDS 9.30.TC2 Database Corruptions?! Help! [4304]
>
> I am running Informix Dynamic Server Version 9.30.TC2 on
> Windows 2000 SP4. We run a custom application provided by an
> informix developer.
>
> I'm not really sure what is causing it, and our application
> provider doesn't seem to know either. We did have an
> unexpected shutdown, but I would be suprised if it wasn't
> robust enough to handle that.
>
> Below I have copied some of the error messages we have
> recorded in a *.log file as well as from the Security Event
> log. Can anyone decipher them?
>
> Currently one of our options is to restore an old backup, and
> lose over a week's data, but I don't really want to do that.
> Generally the system seems stable, except in a few areas.
>
> Any ideas? Are there other places to look for error messages from IDS?
>
> Thanks!
>
> Craig.
>
> 14/2/05...
>
> 12:34:11 Assert Failed: Slot 1 not free in page 0x2c in
> partnum 0x20019b
> 12:34:11 Informix Dynamic Server Version 9.30.TC2
> 12:34:11 Who: Session(382, informix@MYSERVER.OURDOMAIN, 5280, 0)
> Thread(423, sqlexec, 0, 1)
> File: rsbitmap.c Line: 4349
> 12:34:11 Results: Internally corrected
> 12:34:11 stack trace for pid 3792 written to E:\\\\tmp\\\\af.58f0e23
> 12:34:11 See Also: E:\\\\tmp\\\\af.58f0e23
> 12:34:14 Releasing server from system block
> 12:34:21 Slot 1 not free in page 0x2c in partnum 0x20019b
> 12:34:21 Slot 1 not free in page 0x2c in partnum 0x20019b
> 12:34:21 Assert Failed: Slot allocation error for
> 'maindb:"root".studabsent'
> 12:34:21 Informix Dynamic Server Version 9.30.TC2
> 12:34:21 Who: Session(382, informix@MYSERVER.OURDOMAIN, 5280, 0)
> Thread(423, sqlexec, 0, 1)
> File: rsbitmap.c Line: 1759
> 12:34:21 Results: Internally corrected
> 12:34:21 Action: Run 'oncheck -cDI maindb:"root".studabsent'
> 12:34:21 stack trace for pid 3792 written to E:\\\\tmp\\\\af.58f0e23
> 12:34:21 See Also: E:\\\\tmp\\\\af.58f0e23
> 12:34:28 Slot allocation error for 'maindb:"root".studabsent'
> 12:34:28 Slot allocation error for 'maindb:"root".studabsent'
> 12:35:14 Fuzzy Checkpoint Completed: duration was 0
> seconds, 88 buffers not flushed.
> 12:35:14 Checkpoint loguniq 4494, logpos 0x1ba508
>
>
> 15:10:34 Logical Log 4495 Complete.
> 15:10:43 Assert Failed: Slot 1 not free in page 0x423 in
> partnum 0x20022d
> 15:10:43 Informix Dynamic Server Version 9.30.TC2
> 15:10:43 Who: Session(490, informix@MYSERVER.OURDOMAIN, 5644, 0)
> Thread(529, sqlexec, 0, 1)
> File: rsbitmap.c Line: 4349
> 15:10:43 Results: Internally corrected
> 15:10:43 stack trace for pid 3792 written to E:\\\\tmp\\\\af.5f932d3
> 15:10:43 See Also: E:\\\\tmp\\\\af.5f932d3
> 15:10:46 Releasing server from system block
> 15:10:52 Slot 1 not free in page 0x423 in partnum 0x20022d
> 15:10:52 Slot 1 not free in page 0x423 in partnum 0x20022d
> 15:10:52 Assert Failed: Slot allocation error for
> 'maindb:"root".paraddress'
> 15:10:52 Informix Dynamic Server Version 9.30.TC2
> 15:10:52 Who: Session(490, informix@MYSERVER.OURDOMAIN, 5644, 0)
> Thread(529, sqlexec, 0, 1)
> File: rsbitmap.c Line: 1759
> 15:10:52 Results: Internally corrected
> 15:10:52 Action: Run 'oncheck -cDI maindb:"root".paraddress'
> 15:10:52 stack trace for pid 3792 written to E:\\\\tmp\\\\af.5f932d3
> 15:10:52 See Also: E:\\\\tmp\\\\af.5f932d3
> 15:10:59 Slot allocation error for 'maindb:"root".paraddress'
> 15:10:59 Slot allocation error for 'maindb:"root".paraddress'
> 15:11:42 Fuzzy Checkpoint Completed: duration was 0
> seconds, 129 buffers not flushed.
> 15:11:42 Checkpoint loguniq 4496, logpos 0x1b444
>
>
> 16/2/05...
>
> 09:37:19 Assert Failed: Error updating table record.
>
> 09:37:19 Informix Dynamic Server Version 9.30.TC2
> 09:37:19 Who: Session(124, informix@MYSERVER.OURDOMAIN, 2168, 0)
> Thread(187, sqlexec, 0, 1)
> File: rsrwrite.c Line: 926
> 09:37:19 Results: Update failed
> 09:37:19 Action: Run 'oncheck -cDI maindb:"root".studabsent'
> 09:37:19 stack trace for pid 5844 written to E:\\\\tmp\\\\af.4a387ae
> 09:37:19 See Also: E:\\\\tmp\\\\af.4a387ae, shmem.4a387ae.0
> 09:37:22 Releasing server from system block
> 09:37:29 Error updating table record.
>
> 09:37:30 Error updating table record.
>
>
>
> Event Type: Error
> Event Source: OnLine
> Event Category: None
> Event ID: 3
> Date: 16/02/2005
> Time: 9:37:29 AM
> User: N/A
> Computer: MYSERVER
> Description:
> tass : Internal Subsystem failure: 'MT' Error updating table record.
>
>
> Event Type: Error
> Event Source: OnLine
> Event Category: None
> Event ID: 3
> Date: 14/02/2005
> Time: 3:10:59 PM
> User: N/A
> Computer: MYSERVER
> Description:
> tass : Internal Subsystem failure: 'MT' Slot allocation error
> for 'maindb:"root".paraddress'
>
>
> Event Type: Error
> Event Source: OnLine
> Event Category: None
> Event ID: 3
> Date: 14/02/2005
> Time: 3:10:52 PM
> User: N/A
> Computer: MYSERVER
> Description:
> tass : Internal Subsystem failure: 'MT' Slot 1 not free in
> page 0x423 in partnum 0x20022d
>
>
> Event Type: Error
> Event Source: OnLine
> Event Category: None
> Event ID: 3
> Date: 14/02/2005
> Time: 12:34:28 PM
> User: N/A
> Computer: MYSERVER
> Description:
> tass : Internal Subsystem failure: 'MT' Slot allocation error
> for 'maindb:"root".studabsent'
>
>
> Event Type: Error
> Event Source: OnLine
> Event Category: None
> Event ID: 3
> Date: 14/02/2005
> Time: 12:34:21 PM
> User: N/A
> Computer: MYSERVER
> Description:
> tass : Internal Subsystem failure: 'MT' Slot 1 not free in
> page 0x2c in partnum 0x20019b
>
>
Thanks for your response.
The unexpected shutdown had to do with power outages. It was 3 days before the
error messages first appeared. (I would have thought they might be detected on
startup or during backup or something.) Otherwise I don't know why the server
is failing.
The server still works, and informix does dbexports every night and ontape
backups to file, apparently successfully.
I haven't done the onchecks yet, but I guess I will do those this morning.
What exactly do they do?
The reason I am saying about restoring to a week ago is because we only just
detected the errors, and the first error was a week ago. However, as I said,
based on dbexports, tables seem to be intact (even the two on which the errors
seem to be occurring).
Do you know exactly what those error messages mean and what generally causes
them?
The other thing I didn't mention is that currently that server also has an
installation of MS Exchange and MS SQL Server. As far as I can tell, I don't
think it is taking a performance hit, but could that be an issue somehow?
(However, given that the errors only occur in one of two tables so far, it
seems more related to specific tables rather than some general server problem.)
--
Craig.
> Craig
>
> Do you know what caused your server to fail? Can you bring the server up?
> Have you run the onchecks of the tables listed in the Informix log?
>
> It looks like you have had some disk corruption. Depending upon the source
> you may or may not be able to repair. If you cannot repair then restore is
> the only option.
>
> I would seriously look at your backup procedures if you have to restore to a
> week ago. You should be able to restore to minutes before the corruption
> event.
>
> HTH
> MW
Further
to the previous, I have now run oncheck -cDI on the two tables as per log
recommendation, and that detected some problems and asked to reset partition
data:
ERROR: Count of version 0 data pages 1 != pnv_pages 0
Reset partition data? y
and...
ERROR: Count of version 0 data pages 1066 != pnv_pages 1065
Reset partition data? y
After doing this I ran oncheck again, and seemed to be okay. Should I do
anything else?
Thanks
Craig.
Now take a
good current backup.
More than likely, the oncheck found and repaired the errors Informix
detected in the data and/or indexes. Everything is likely to be OK now. I
suggest you monitor the logs several times daily now. Perhaps you could
write a script that looks at the log contents and emails you when an error
occurs.
"CRAIG JOHNSON" <cjohnson@wcc.qld.edu.au>
Sent by: forum.subscriber@iiug.org
02/21/2005 08:13 PM
To: ids@iiug.org
cc:
Subject: Re: Re: RE: IDS 9.30.TC2 Database Corruptions?! Help! [4312]
Further to the previous, I have now run oncheck -cDI on the two tables as
per log recommendation, and that detected some problems and asked to reset
partition data:
ERROR: Count of version 0 data pages 1 != pnv_pages 0
Reset partition data? y
and...
ERROR: Count of version 0 data pages 1066 != pnv_pages 1065
Reset partition data? y
After doing this I ran oncheck again, and seemed to be okay. Should I do
anything else?
Thanks
Craig.