Log backup recovery error

[Former Member]

Hello all,

we use Max DB 7.5.0.34 and have a problem restoring log backup on a "stand-by" instance.

Parameters and volume sizes on master and stand-by databases are identical.

KNLDIAGERR file shows:

2010-01-19 20:48:54 0xC14 ERR 54111 MOVE UpdMap.2: 93[98]->96[102] len:7

2010-01-19 20:48:54 0xC14 ERR 5 Restart REDO: T434555392 (committed) redoresult: 3, TrError: -9111

DBMPRT file:

2010-01-19 20:47:29 0x00000e7c 0 DBM command backup_media_put "ALOGIMPORT" "D:\<path>" FILE LOG 0 0 NO NO ""

2010-01-19 20:48:35 0x00000e7c 0 DBM command backup_restore "ALOGIMPORT" LOG 50542

2010-01-19 20:48:52 0x000007e4 0 DBM command backup_restore_state

2010-01-19 20:48:52 0x000007e4 ERR -24988 DBM ERR_SQL: sql error

0x000007e4 ERR -24988 DBM -1000,Too many lock requests

2010-01-19 20:48:54 0x000007e4 0 DBM command backup_restore_state

2010-01-19 20:48:54 0x000007e4 ERR -24988 DBM ERR_SQL: sql error

0x000007e4 ERR -24988 DBM -1000,Too many lock requests

2010-01-19 20:48:56 0x000007e4 0 DBM command backup_restore_state

2010-01-19 20:48:56 0x000007e4 ERR -24988 DBM ERR_SQL: sql error

...

We made a new full backup / created a new stand-by instance to start from a different LOG-backup,

but the problem is still there. We tried to restore an incremental backup and it seems to work.

Could you please help us to resolve the issue or provide some tips on what to check next?

Thanks a lot in advance.

Alexander Pigolkin

[Former Member]

Hi,

MAXLOCKS is 6000000, I increased it to 8000000 and the result of restore is:

2010-01-20 08:08:18 0x00000758 0 DBM command trace_show

2010-01-20 08:08:50 0x00000a10 0 DBM command backup_restore "ALOGIMPORT" LOG 50836

2010-01-20 08:08:51 0x00000110 0 DBM command backup_restore_state

2010-01-20 08:08:51 0x00000110 ERR -24988 DBM ERR_SQL: sql error

0x00000110 ERR -24988 DBM -8000,SERVERDB must be restarted

2010-01-20 08:08:53 0x00000110 0 DBM command backup_restore_state

2010-01-20 08:08:53 0x00000110 ERR -24988 DBM ERR_SQL: sql error

0x00000110 ERR -24988 DBM -8000,SERVERDB must be restarted

In this case I tried to restore LOG-backup after restoring incremental backup (I didn't put database online).

May be this makes problems now. And I noticed that restore of the LOG-files works differently now:

database "skips" first log file and restores next one, but stops afterwards, though there are other LOG

files to restore.

Regards,

Alexander Pigolkin

Edited by: Alexander Pigolkin on Jan 20, 2010 11:13 AM

[former_member524429]

MAXLOCKS parameter changes only become active when you restart the database.

Have you restarted DB after changing MAXLOCKS param? If not restart it.

Regards,

Bhavik G. Shroff

[Former Member]

I restarted database and checked that the new settings are active ( in Database Manager, Configuraion->Parameters)

Regards,

Alexander Pigolkin

[former_member524429]

Wt is the current mode status of Database ?

Is it having Online Status ?

Try to Switch the database to ONLINE mode.

Regards,

Bhavik G. Shroff

[Former Member]

Database was in Admin mode.

I switched to Online.

DBMPRT file:

<pre>

2010-01-20 10:59:03 0x00000690 0 DBM command db_online -f

2010-01-20 10:59:44 0x00000690 0 DBM command db_execute SELECT ID,CREATEDATE,USEDSIZE

2010-01-20 10:59:44 0x00000690 ERR -24988 DBM ERR_SQL: sql error

0x00000690 ERR -24988 DBM 100,Row not found

2010-01-20 10:59:53 0x00000690 0 DBM command trace_show

</pre>

KNLDIAGERR:

<pre>

2010-01-20 10:59:03 --- Starting GMT 2010-01-20 10:59:03

7.5.0 Build 034-123-118-234

</pre>

KNLDIAG:

<pre>

2010-01-20 10:59:18 0xDF8 19633 CONNECT Connect req. (T4, Node:'', PID:1680)

2010-01-20 10:59:18 0xDF8 19651 CONNECT Connection released, T4

2010-01-20 10:59:18 0xDF8 19633 CONNECT Connect req. (T4, Node:'', PID:1680)

2010-01-20 10:59:18 0xDF8 19651 CONNECT Connection released, T4

2010-01-20 10:59:18 0xDF8 19633 CONNECT Connect req. (T4, Node:'', PID:1680)

2010-01-20 10:59:18 0xDF8 19615 VOLUMEIO Attaching volume 'DAT_0001'

2010-01-20 10:59:18 0xE48 19613 DBSTATE I/O thread for 'DAT_0001' started

2010-01-20 10:59:18 0xDF8 19617 VOLUMEIO Single I/O attach, 'DAT_0001', UKT:3

2010-01-20 10:59:18 0xDF8 19615 VOLUMEIO Attaching volume 'DAT_0002'

2010-01-20 10:59:18 0x950 19613 DBSTATE I/O thread for 'DAT_0002' started

2010-01-20 10:59:18 0xDF8 19617 VOLUMEIO Single I/O attach, 'DAT_0002', UKT:3

2010-01-20 10:59:18 0xDF8 19615 VOLUMEIO Attaching volume 'DAT_0003'

2010-01-20 10:59:18 0xB8C 19613 DBSTATE I/O thread for 'DAT_0003' started

2010-01-20 10:59:18 0xDF8 19617 VOLUMEIO Single I/O attach, 'DAT_0003', UKT:3

2010-01-20 10:59:18 0xDF8 19615 VOLUMEIO Attaching volume 'DAT_0004'

2010-01-20 10:59:18 0x2DC 19613 DBSTATE I/O thread for 'DAT_0004' started

2010-01-20 10:59:18 0xDF8 19617 VOLUMEIO Single I/O attach, 'DAT_0004', UKT:3

2010-01-20 10:59:18 0xDF8 19615 VOLUMEIO Attaching volume 'LOG_001'

2010-01-20 10:59:18 0xD00 19613 DBSTATE I/O thread for 'LOG_001' started

2010-01-20 10:59:18 0xDF8 19617 VOLUMEIO Single I/O attach, 'LOG_001', UKT:3

2010-01-20 10:59:18 0xDF8 12 Pager Start Read Converter

2010-01-20 10:59:34 0xDF8 13 Pager Stop Read Converter, Pages: 17373 IO: 17373

2010-01-20 10:59:34 0xDF8 54003 dynpool DATA_CACHE_REGIONS : 16

2010-01-20 10:59:34 0xDF8 54003 dynpool B20_DATACACHE_HEAD : 159568

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE head num item: 9973

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE head item siz: 16

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE task queue : 7848

2010-01-20 10:59:34 0xDF8 54003 dynpool US + SV + DW + 8 : 327

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE taskq elem : 24

2010-01-20 10:59:34 0xDF8 54003 dynpool B20_DATACACHE_TASKQ : 167416

2010-01-20 10:59:34 0xDF8 54003 dynDATA DATA_CACHE_PAGES : 787

2010-01-20 10:59:34 0xDF8 54003 dynpool B20_DATACACHE_CB : 88144

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE num cblocks : 787

2010-01-20 10:59:34 0xDF8 54003 dynpool DATACACHE cblock size : 112

2010-01-20 10:59:34 0xDF8 54003 dynpool DYNP_B20_DATACACHE :4088960

2010-01-20 10:59:34 0xDF8 54003 dynDATA DYND_B20_DATACACHE : 12592

2010-01-20 10:59:34 0xDF8 53000 B*TREE Restart FileDir finished successfully

2010-01-20 10:59:34 0xDF8 54003 dynpool DYNP_K51_LOCK_LIST : 1997312336

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK maxlocks :8000000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK items : 24002400

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK Regions : 24

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TransRegions : 8

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK RegionGlob+Space : 3456

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TransGlob : 768

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK SupplyItemsPerRgn : 100

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK SupplySize : 192000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK RowHash entries :8000000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TabHash entries : 400000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK Row+Tab hash size : 67200000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK Trans entries : 1096

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK trans_list size : 245504

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TransPtrList : 8768

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TransHash entries : 1096

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK TransHash size : 8832

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK SupplyPoolSegments: 240000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK SupplyPoolSize : 1925760000

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK ObjColl_list size : 35072

2010-01-20 10:59:34 0xDF8 54003 dynpool LOCK ObjReq_list size : 17536

2010-01-20 10:59:34 0xDF8 0 Log no update of LogInfoPage:

DeviceState = Cleared, LogIsEmpty = true

2010-01-20 10:59:34 0xDF8 6 Log 1 queues, flushmode is

'MinimizeSpace', devstate is 'Cleared'

2010-01-20 10:59:34 0xDF8 7 Log Oldest not saved is ioseq

NIL @ off 1

2010-01-20 10:59:34 0xDF8 9 Log LogVolume not completely

written until now

2010-01-20 10:59:34 0xDF8 5 Log Restart from ioseq

4294967295 @ off 4294967295 to ioseq NIL @ off 4294967295

2010-01-20 10:59:34 0xDF8 10 Log Result after checking the

log device: 'Ok'

2010-01-20 10:59:41 0xE80 12 Log last-redo-read#0:

TR4294967295(0)[NIL]@4294967295.65535'NoOp':0:0

2010-01-20 10:59:41 0xDF8 56 Log Savepoint requested

by T4 reason 'Restart' (started).

2010-01-20 10:59:41 0xE80 4 Pager SVP(1) Start Write Data

2010-01-20 10:59:41 0xE80 5 Pager SVP(1) Stop Data IO, Pages: 0 IO: 0

2010-01-20 10:59:41 0xE80 6 Pager SVP(2) Wait for last split, TaskId: 320

2010-01-20 10:59:41 0xE80 7 Pager SVP(2) Stop Wait for last split, Pages: 0 IO: 0

2010-01-20 10:59:41 0x1AC 19617 VOLUMEIO Single I/O attach, 'LOG_001', UKT:2

2010-01-20 10:59:41 0xE80 53070 SAVPOINT B20PREPARE_SVP: 54910

2010-01-20 10:59:41 0xE80 8 Pager SVP(3) Start Write Data

2010-01-20 10:59:42 0xE80 9 Pager SVP(3) Stop Data IO, Pages: 1 IO: 1

2010-01-20 10:59:42 0xE80 10 Pager SVP(3) Start Write Converter

2010-01-20 10:59:42 0xE80 11 Pager SVP(3) Stop Converter IO, Pages: 2 IO: 2

2010-01-20 10:59:42 0xE80 53071 SAVPOINT B20SVP_COMPLETED: 54910

2010-01-20 10:59:42 0xDF8 20037 Admin Kernel state: 'REDO LOG' finished

2010-01-20 10:59:42 0xDF8 54003 dynpool DYNP_A42_PARSEID : 3000

2010-01-20 10:59:42 0xDF8 54000 OBJECT c:\program files\sdb\7500\pgm\liboms

2010-01-20 10:59:42 0xDF8 20207 RTE Kernel state changed from ADMIN to ONLINE

2010-01-20 10:59:42 0xDF8 20208 RTE Used physical memory 2206 MByte

2010-01-20 10:59:42 0xDF8 20039 Admin Kernel state: 'ONLINE' reached

2010-01-20 10:59:42 0xDF8 19651 CONNECT Connection released, T4

2010-01-20 10:59:42 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 10:59:42 0xBE0 19617 VOLUMEIO Single I/O attach, 'DAT_0002', UKT:7

2010-01-20 10:59:42 0xBE0 19617 VOLUMEIO Single I/O attach, 'DAT_0001', UKT:7

2010-01-20 10:59:42 0xBE0 19617 VOLUMEIO Single I/O attach, 'DAT_0003', UKT:7

2010-01-20 10:59:42 0xBE0 19651 CONNECT Connection released, T53

2010-01-20 10:59:42 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 10:59:43 0xBE0 19617 VOLUMEIO Single I/O attach, 'DAT_0004', UKT:7

2010-01-20 10:59:44 0xA2C 19633 CONNECT Connect req. (T85, Node:'', PID:1680)

2010-01-20 10:59:44 0xA2C 19617 VOLUMEIO Single I/O attach, 'DAT_0004', UKT:8

2010-01-20 10:59:44 0xA2C 19617 VOLUMEIO Single I/O attach, 'DAT_0002', UKT:8

2010-01-20 10:59:44 0xA2C 19651 CONNECT Connection released, T85

2010-01-20 10:59:44 0xBE0 19651 CONNECT Connection released, T53

2010-01-20 10:59:53 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 10:59:53 0xBE0 19651 CONNECT Connection released, T53

2010-01-20 10:59:53 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 10:59:53 0xBE0 19651 CONNECT Connection released, T53

2010-01-20 11:01:30 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 11:01:30 0xBE0 19651 CONNECT Connection released, T53

2010-01-20 11:01:30 0xBE0 19633 CONNECT Connect req. (T53, Node:'', PID:1680)

2010-01-20 11:01:30 0xBE0 19651 CONNECT Connection released, T53

</pre>

-

---

current write position -

---

Regards,

Alexander Pigolkin

Edited by: Alexander Pigolkin on Jan 20, 2010 12:20 PM

[former_member524429]

Please refer this[ link to get more info|http://wiki.sdn.sap.com/wiki/display/MaxDB/HowTo-SAPMaxDBrecoverywithDatabaseManagerCLI#HowTo-SAPMaxDBrecoverywithDatabaseManagerCLI-Restorealogbackup].

Current status of your DB Instance ?

Regards,

Bhavik G. Shroff

[Former Member]

Thank you for the info, I'll check the documentation.

Current status is Online.

Alexander Pigolkin

[Former Member]

Hello,

we restored the database according to documentation, but problems are still there.

We made new full backups and tried to restore them and afterwards new LOG-backups and

noticed that some LOG-backups can be restored, but after few successful LOGs

process hangs again on some LOG-file and produces database error

2010-01-25 09:39:46 0xD18 ERR 54111 MOVE UpdMap.2: 93 [98] ->96 [102] len:7

2010-01-25 09:39:46 0xD18 ERR 5 Restart REDO: T437960507 (committed) redoresult: 3, TrError: -9111

Could it be that changes to some tables or LONG-fields cannot get into stand-by DB due to some reason ?

Would it be possible to force MaxDB to provide more log of the recovery or to parse LOG-file

to check which transactions cannot be performed?

Thank's a lot in advance.

Alexander Pigolkin

[former_member229109]

Hello Alexander Pigolkin,

1) As you know that after you restarted the database in online status, you could not continue with the recovery of the log backups. The "stand-by" instance has to be in admin or offline status, if you need to continue with log backups recovery in sequence.

2) You are restoring log backup on a "stand-by" instance.

Parameters and volume sizes on master and stand-by databases are identical. So far itu2019s fine.

Please follow the known by you documentation.

3) You are using the old database version u201CMax DB 7.5.0.34u201D.

Concerning the last postederror:

u201CERR 5 Restart REDO: T434555392 (committed) redoresult: 3, TrError: -9111u201D,

It could be known problem fixed in the latest released 7.5 patch.

To get clear on this issue, it will be helpful to check the database logs, knltrace file.

Are you SAP customer?

Thank you and best regards, Natalia Khlopina

[Former Member]

Hello Natalia,

thank you for the information.

I restarted database in online status to check whether database can be started or is it completely damaged

and to provide information to the Bhavik G. Shroff in the thread, normally we do operations in admin mode only.

We use LOG-shipping for approx. 1,5 years and this problem happened only now.

Could you please provide more information about the problem or may be a link to the problem/fix description?

Is there any way to bypass the problem?

We tried to switch to 7.5.0.44 last year, but we faced many other errors in the database and decided to

stay with 7.5.0.34.

Could you please tell me how I can provide the logs and knltrace?

We are not a customer of SAP.

Thank you very much in advance.

Best regards,

Alexander Pigolkin

[former_member229109]

Hello Alexander,

1) u201CCould you please provide more information about the problem or may be a link to the problem/fix description? u201C

For example, the problems with the redo logs have been solved as of 7.5.00.51,

PTS 1162300

< www.sapdb.org/webpts >.

What is the highest assigned I/O Sequence Number in the source database?

< In dbm.knl, backup history file, for example. Check a line for one of the last log backups.

In the ninth column, just before you specify the medium indicator, you can find a number

that specifies the range reached by the log pages or the I/O Sequence number. >

2) Please post the link to the downloaded files < standby database > in the thread

after the problem was reproduced:

Knldiag, knldiag.err, dbm.prt, dbm.knl, knltrace.prt

< Run u201C<InstallationPath>/bin/xkernprot -f knltrace akbmxu201D to convert the knltrace binary file.

Run u201Cxinstinfo <SID>u201D to get the InstallationPath of the database. >

3) Did you report the problems when you updated to 7.5.0.44 last year?

Are planning the upgrade to 7.6 version?

Thank you and best regards, Natalia Khlopina

[Former Member]

Hello Natalia,

I apologize for delay with answer. We created the source database from a full backup one more time

and started log-shipping from the beginning, but the problem happened again.

> 1) What is the highest assigned I/O Sequence Number in the source database?

Number from the ninth column : 179008

> 2) Please post the link to the downloaded files < standby database > in the thread

> Knldiag, knldiag.err, dbm.prt, dbm.knl, knltrace.prt

http://cid-c65c81e165f8f4dc.skydrive.live.com/browse.aspx/.Public/DbLogs

>3) Did you report the problems when you updated to 7.5.0.44 last year?

> Are planning the upgrade to 7.6 version?

No, we didn't report problems. There are no upgrade plans for a moment.

Best regards,

Alexander Pigolkin

[former_member229109]

Hello Alexander,

Could you please post additional information:

1) What was status of the database activity tasks when the error occurred?

x_cons DATABASE show active

x_cons DATABASE sh all 10 10 > showall.txt

2) Please review the document u201CMaxDB database traceu201D at http://wiki.sdn.sap.com/wiki/display/MaxDB/MaxDBdatabasetrace

Please activate a VTRACE with the Option "DEFAULAT" and "STOP ON ERROR"

with error code "-9111" . Please reproduce the issue after that, when the error occurs,

the VTRACE will be automatically stopped.

Please convert the knltrace & give the link to check the trace and showall.txt file.

Thank you and best regards, Natalia Khlopina

[Former Member]

Hello Natalia,

I created log files. They are here:

http://cid-c65c81e165f8f4dc.skydrive.live.com/browse.aspx/.Public/DbLogs

Best regards,

Alexander Pigolkin

[Former Member]

Hello Natalia,

I apologize for disturbing you. Could you please provide information on whether log-files

helped to understand the problem and whether there is another option to try to resolve the problem ?

Thank you very much in advance.

Best regards,

Alexander Pigolkin

[former_member229109]

Hello Alexander Pigolkin,

1.I had problems with my PC after I downloaded & displayed the Vtrace. IT recommended to delete the file from PCu2026

2.After you dropped the question, I checked with IT the file again.

May be it was unlucky coincident

I will check the file tomorrow or ask my colleagues to help you.

Thank you and best regards, Natalia Khlopina

[Former Member]

Hello Natalia,

Could you please provide more information on which files contain viruses

and the message from antivirus program.

I provided a link to a Zip-file with 3 text files (100% ASCII characters)

and to my knowledge there is no way to write a virus inside such text files.

Thank you very much in advance.

Alexander Pigolkin

[roland_mallmann]

Hi,

just on a side note: I downloaded, scanned and opened the files just now: no issues here at all.

Regards,

Roland

[former_member229109]

Hello Alexander Pigolkin,

The Vtrace and output of the x_cons command was checked. Thank you.

The case was discussed with MAXDB support colleagues and MAXDB development.

1. The database upgrade to 7.5.00.52 version is recommended first, if you prefer to use the 7.5 database version.

You told that the upgrade to 7.5.00.44 leads to other problems.

Itu2019s better to go forward and check/solve those problems.

We have implemented a lot of corrections between 7.5.00.35 and 7.5.00.52.

And we had many SAP customers who successfully run shadow databases

with the newer patches of 7.5.

2. Could you please check if the MAXDB parameters MAXUSERTASKS and LOCAL_REDO_LOG_BUFFER_SIZE have the same value in the main database and

the shadow database.

3. Do you plan the database upgrade to the 7.6 version?

Regards, Natalia Khlopina

Edited by: Natalia Khlopina on Feb 26, 2010 10:04 PM

[Former Member]

Hello Natalia,

Thank you very much for the information.

Parameters MAXUSERTASKS and LOCAL_REDO_LOG_BUFFER_SIZE have the same value in both databases.

We would like to try the upgdate to 7.5.0.52 first and then think of 7.6.

Could you please tell me how we can try to update to 7.5.0.52 ?

Thank you very much in advance.

Best regards,

Alexander Pigolkin

[former_member229109]

Hello Alexander,

I checked with database development & we donu2019t have any newer 7.5 software available for non-SAP customers anymore. So due to the new regulations, we also cannot provide any updates of 7.5 to you.

Currently as non-SAP customer you have the options to use the versions available to

download in SDN:

Database Versions 7.6.06 Build 03 or 7.7.06 Build 09.

Best regards, Natalia Khlopina

[former_member524429]

Hi,

Value of MAXLOCKS database parameter ?

If possible try to Increase MAXLOCKS database parameter.

Regards,

Bhavik G. Shroff