Several rollbacks on logical-logs

Hello everybody! We´re having several rollback recordins on our logical-logs, generated by dba transactions, on our 11.50.FC4 instance running on a linux_64 machine, as follows: log uniqid: 971. addr len type xid id link 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 54374 *dba* 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM 1488 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 9c0732c 93 9c07410 40 CLR 1488 0 9c07050 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 There´s an enormous quantity of these rollbacks (around 110+) recordings per *second *of logical-log!!! The main question is: 1) how can we trace it, because with our sql trace option running for user "dba", it doesn´t appear any record of rollback!!! 2) there are several r4gl programs running constantly on dba´s crontab file, but on these application logs, there´s no recording of transaction errors.... We´re desperate to find out what´s originating these kind of records, that´s elevating our use of logical-logs too much (the fill time of the above logical-log was): 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up *575 KB/SEC* We´re RTO enabling with RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds but we have a task running a checkpoint in every 40 minutes. If someone could give us an idea of tracing these events, we´d appreciate! Regards. -- Alexandre Marini Analista de Tecnologia da Informação - DBA SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW

Hi Alexandre The extract shows an insert operation into table with hex partnum 600249. If you find out the table that is being operated on ( select hex(partnum),dbsname[1,20], tabname[1,20] from sysmaster:systabnames where partnum='0x600249' ) then maybe that will give you a clue as to what is going on. Regards David Linthwaite Lintel Software Consultancy Ltd IBM Business Partner Tel.: 01244 357250 Fax.: 01244 357248 mailto:dlinthwaite@lintel.co.uk -----Original Message----- From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of Alexandre Marini Sent: 17 June 2009 13:59 To: ids@iiug.org Subject: Several rollbacks on logical-logs [16065] Hello everybody! We´re having several rollback recordins on our logical-logs, generated by dba transactions, on our 11.50.FC4 instance running on a linux_64 machine, as follows: log uniqid: 971. addr len type xid id link 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 54374 *dba* 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM 1488 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 9c0732c 93 9c07410 40 CLR 1488 0 9c07050 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 There´s an enormous quantity of these rollbacks (around 110+) recordings per *second *of logical-log!!! The main question is: 1) how can we trace it, because with our sql trace option running for user "dba", it doesn´t appear any record of rollback!!! 2) there are several r4gl programs running constantly on dba´s crontab file, but on these application logs, there´s no recording of transaction errors.... We´re desperate to find out what´s originating these kind of records, that´s elevating our use of logical-logs too much (the fill time of the above logical-log was): 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up *575 KB/SEC* We´re RTO enabling with RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds but we have a task running a checkpoint in every 40 minutes. If someone could give us an idea of tracing these events, we´d appreciate! Regards. -- Alexandre Marini Analista de Tecnologia da Informação - DBA SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW **************************************************************************** *** Forum Note: Use "Reply" to post a response in the discussion forum.

If the application keep the session open after the rollbacks, maybe you can identify it with this: select * from sysmaster:syssesprof where isrollbacks > 0 what options do you use to active the SQLTRACE ? --- Em qua, 17/6/09, Alexandre Marini <amarini@fazenda.ms.gov.br> escreveu: De: Alexandre Marini <amarini@fazenda.ms.gov.br> Assunto: Several rollbacks on logical-logs [16065] Para: ids@iiug.org Data: Quarta-feira, 17 de Junho de 2009, 9:58 Hello everybody! We´re having several rollback recordins on our logical-logs, generated by dba transactions, on our 11.50.FC4 instance running on a linux_64 machine, as follows: log uniqid: 971. addr len type xid id link 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 54374 *dba* 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM 1488 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 9c0732c 93 9c07410 40 CLR 1488 0 9c07050 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 There´s an enormous quantity of these rollbacks (around 110+) recordings per *second *of logical-log!!! The main question is: 1) how can we trace it, because with our sql trace option running for user "dba", it doesn´t appear any record of rollback!!! 2) there are several r4gl programs running constantly on dba´s crontab file, but on these application logs, there´s no recording of transaction errors.... We´re desperate to find out what´s originating these kind of records, that´s elevating our use of logical-logs too much (the fill time of the above logical-log was): 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up *575 KB/SEC* We´re RTO enabling with RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds but we have a task running a checkpoint in every 40 minutes. If someone could give us an idea of tracing these events, we´d appreciate! Regards. -- Alexandre Marini Analista de Tecnologia da Informação - DBA SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW ******************************************************************************* Forum Note: Use "Reply" to post a response in the discussion forum. Veja quais são os assuntos do momento no Yahoo! +Buscados http://br.maisbuscados.yahoo.com

Bingo!!!! I´ve found the table, now I´m gonna review the analyst code to find out why are there lots of rollbacks!!! Thanks David!!!! And thanks Cesar too!!!! Alexandre Marini Analista de Tecnologia da Informação - DBA msn: alexandre_marini@hotmail.com SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW David Linthwaite escreveu: > Hi Alexandre > > The extract shows an insert operation into table with hex partnum 600249. > If you find out the table that is being operated on ( select > hex(partnum),dbsname[1,20], tabname[1,20] from sysmaster:systabnames where > partnum='0x600249' ) then maybe that will give you a clue as to what is > going on. > > Regards > > David Linthwaite > Lintel Software Consultancy Ltd > IBM Business Partner > > Tel.: 01244 357250 > Fax.: 01244 357248 > > mailto:dlinthwaite@lintel.co.uk > > -----Original Message----- > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of > Alexandre Marini > Sent: 17 June 2009 13:59 > To: ids@iiug.org > Subject: Several rollbacks on logical-logs [16065] > > Hello everybody! > We´re having several rollback recordins on our logical-logs, generated by > dba transactions, on our 11.50.FC4 instance running on a linux_64 machine, > as follows: > > log uniqid: 971. > addr len type xid id link > 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 > 54374 *dba* > 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM 1488 > 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 > 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 9c0732c > 93 9c07410 40 CLR 1488 0 9c07050 > 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 > > There´s an enormous quantity of these rollbacks (around 110+) recordings per > *second *of logical-log!!! > > The main question is: > 1) how can we trace it, because with our sql trace option running for user > "dba", it doesn´t appear any record of rollback!!! > 2) there are several r4gl programs running constantly on dba´s crontab file, > but on these application logs, there´s no recording of transaction > errors.... > > We´re desperate to find out what´s originating these kind of records, that´s > elevating our use of logical-logs too much (the fill time of the above > logical-log was): > 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up *575 > KB/SEC* > > We´re RTO enabling with > RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds > > but we have a task running a checkpoint in every 40 minutes. > > If someone could give us an idea of tracing these events, we´d appreciate! > > Regards. >

Ok!!! Now I could find the table around the rollbacks. On the HINSERT line, there´s the table partnum, and on the next two ADDITEM lines, there are 2 indexes partnum (the 2 indexes that the above table contains). My doubt is: This sql statement mentioned by the HINSERT line, could it be an update clause, or just an insert generate this kind of record? ------------------------------------------------------- Explaining: our r4gl program tryes to do an insert on the table first, and then whe analyse the sql errorcodes, like these two if sqlca.sqlcode = -239 or sqlca.sqlcode = -268 then "we call an update function." Our big rollbacks on logical-logs are happening, even if the application doesn´t indicate any errors on its log. Is that normal, the database should really record these rollbacks? I´m not understanding if there´s really an application error, or a database normal task, because the application had entered the "if" statement above ? Regards, friends. Alexandre Marini Analista de Tecnologia da Informação - DBA msn: alexandre_marini@hotmail.com SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW David Linthwaite escreveu: > Hi Alexandre > > The extract shows an insert operation into table with hex partnum 600249. > If you find out the table that is being operated on ( select > hex(partnum),dbsname[1,20], tabname[1,20] from sysmaster:systabnames where > partnum='0x600249' ) then maybe that will give you a clue as to what is > going on. > > Regards > > David Linthwaite > Lintel Software Consultancy Ltd > IBM Business Partner > > Tel.: 01244 357250 > Fax.: 01244 357248 > > mailto:dlinthwaite@lintel.co.uk > > -----Original Message----- > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of > Alexandre Marini > Sent: 17 June 2009 13:59 > To: ids@iiug.org > Subject: Several rollbacks on logical-logs [16065] > > Hello everybody! > We´re having several rollback recordins on our logical-logs, generated by > dba transactions, on our 11.50.FC4 instance running on a linux_64 machine, > as follows: > > log uniqid: 971. > addr len type xid id link > 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 > 54374 *dba* > 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM 1488 > 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 > 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 9c0732c > 93 9c07410 40 CLR 1488 0 9c07050 > 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 > > There´s an enormous quantity of these rollbacks (around 110+) recordings per > *second *of logical-log!!! > > The main question is: > 1) how can we trace it, because with our sql trace option running for user > "dba", it doesn´t appear any record of rollback!!! > 2) there are several r4gl programs running constantly on dba´s crontab file, > but on these application logs, there´s no recording of transaction > errors.... > > We´re desperate to find out what´s originating these kind of records, that´s > elevating our use of logical-logs too much (the fill time of the above > logical-log was): > 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up *575 > KB/SEC* > > We´re RTO enabling with > RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds > > but we have a task running a checkpoint in every 40 minutes. > > If someone could give us an idea of tracing these events, we´d appreciate! > > Regards. >

Hi Alexandre The HINSERT is almost certainly associated with an SQL INSERT statement. The only occasion that I am aware of that causes an SQL UPDATE statement to translate into an HINSERT record is where a row is being updated in a table that has an in-place alter and in some circumstances this is achieved by inserting a row in the new version format and deleting the row in the old version format. However this would show as a HINSERT followed by a HDELETE and there is no indication that this is happening in the log extract that you sent. However if an attempted insert operation results in a constraint violation (-268) then the insert will be rolled back and the result in the transaction log is likely to be similar to that shown in the extract. If this does not explain all of the rollbacks then maybe there is an error condition, other than -268 and -239, that is also causing rollbacks. Regards David Linthwaite Lintel Software Consultancy Ltd IBM Business Partner Tel: 01244 357250 Fax: 01244 357248 mailto:dlinthwaite@lintel.co.uk > -----Original Message----- > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On > Behalf Of Alexandre Marini > Sent: 19 June 2009 15:13 > To: ids@iiug.org > Subject: Re: Several rollbacks on logical-logs [16101] > > Ok!!! Now I could find the table around the rollbacks. > > On the HINSERT line, there´s the table partnum, and on the > next two ADDITEM lines, there are 2 indexes partnum (the 2 > indexes that the above table contains). > > My doubt is: > This sql statement mentioned by the HINSERT line, could it be > an update clause, or just an insert generate this kind of record? > > ------------------------------------------------------- > Explaining: > our r4gl program tryes to do an insert on the table first, > and then whe analyse the sql errorcodes, like these two if > sqlca.sqlcode = -239 or sqlca.sqlcode = -268 then > > "we call an update function." > > Our big rollbacks on logical-logs are happening, even if the > application doesn´t indicate any errors on its log. > > Is that normal, the database should really record these rollbacks? > > I´m not understanding if there´s really an application error, > or a database normal task, because the application had > entered the "if" statement above ? > > Regards, friends. > > Alexandre Marini > > Analista de Tecnologia da Informação - DBA > > msn: alexandre_marini@hotmail.com > > SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW > > David Linthwaite escreveu: > > Hi Alexandre > > > > The extract shows an insert operation into table with hex > partnum 600249. > > If you find out the table that is being operated on ( select > > hex(partnum),dbsname[1,20], tabname[1,20] from > sysmaster:systabnames > > where partnum='0x600249' ) then maybe that will give you a > clue as to > > what is going on. > > > > Regards > > > > David Linthwaite > > Lintel Software Consultancy Ltd > > IBM Business Partner > > > > Tel.: 01244 357250 > > Fax.: 01244 357248 > > > > mailto:dlinthwaite@lintel.co.uk > > > > -----Original Message----- > > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On > Behalf Of > > Alexandre Marini > > Sent: 17 June 2009 13:59 > > To: ids@iiug.org > > Subject: Several rollbacks on logical-logs [16065] > > > > Hello everybody! > > We´re having several rollback recordins on our > logical-logs, generated > > by dba transactions, on our 11.50.FC4 instance running on a > linux_64 > > machine, as follows: > > > > log uniqid: 971. > > addr len type xid id link > > 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 > > 54374 *dba* > > 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c > 68 ADDITEM > > 1488 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 > 0 9c0732c > > 6003c6 > > 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 > > 9c0732c > > 93 9c07410 40 CLR 1488 0 9c07050 > > 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 > > > > There´s an enormous quantity of these rollbacks (around 110+) > > recordings per *second *of logical-log!!! > > > > The main question is: > > 1) how can we trace it, because with our sql trace option > running for > > user "dba", it doesn´t appear any record of rollback!!! > > 2) there are several r4gl programs running constantly on > dba´s crontab > > file, but on these application logs, there´s no recording of > > transaction errors.... > > > > We´re desperate to find out what´s originating these kind > of records, > > that´s elevating our use of logical-logs too much (the fill time of > > the above logical-log was): > > 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used > and Backed Up > > *575 > > KB/SEC* > > > > We´re RTO enabling with > > RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds > > > > but we have a task running a checkpoint in every 40 minutes. > > > > If someone could give us an idea of tracing these events, > we´d appreciate! > > > > Regards. > > > > > ************************************************************** > ***************** > Forum Note: Use "Reply" to post a response in the discussion forum. >

Failed inserts are expensive because the engine does not realize that the insert is causing a duplicate row until the row and all of its index entries exist, so, if there is a duplicate primary or unique key or a duplicate unique index entry then that portion of the transaction has to be rolled back, yes, even if the update is committed. It is much cheaper to try the update first and check the number of rows affected by the update (updating zero rows is not an error) to make sure that it is one and not zero. This is because the update will use the unique index that is causing the duplicate row failure on insert and immediately return having update no rows since the row was not there. Then if the update updated no rows you can then perform the insert. Rule of thumb: Only if about 70% or more of the operations will result in a successful insert should you try the insert before the update. If even 31% of the operations result in an update being the final successful operation, you should be doing the update first. This is an easy fix. I patched a similar program for a client last year and the mods took about 5 minutes in emacs (probably would have taken me 8 minutes in vi) including reindenting the code that had been moved around. The var you need to check after the attempted update is sqlca.sqlerrd[2] in ESQL/C or sqlca.sqlerrd[3] in 4GL. Art 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. On Fri, Jun 19, 2009 at 10:12 AM, Alexandre Marini < amarini@fazenda.ms.gov.br> wrote: > Ok!!! Now I could find the table around the rollbacks. > > On the HINSERT line, there´s the table partnum, > and on the next two ADDITEM lines, there are 2 indexes partnum (the 2 > indexes that the above table contains). > > My doubt is: > This sql statement mentioned by the HINSERT line, could it be an update > clause, or just an insert generate this kind of record? > > ------------------------------------------------------- > Explaining: > our r4gl program tryes to do an insert on the table first, > and then whe analyse the sql errorcodes, like these two > if sqlca.sqlcode = -239 or sqlca.sqlcode = -268 then > > "we call an update function." > > Our big rollbacks on logical-logs are happening, even if the application > doesn´t indicate any errors on its log. > > Is that normal, the database should really record these rollbacks? > > I´m not understanding if there´s really an application error, or a > database normal task, > because the application had entered the "if" statement above ? > > Regards, friends. > > Alexandre Marini > > Analista de Tecnologia da Informação - DBA > > msn: alexandre_marini@hotmail.com > > SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW > > David Linthwaite escreveu: > > Hi Alexandre > > > > The extract shows an insert operation into table with hex partnum 600249. > > If you find out the table that is being operated on ( select > > hex(partnum),dbsname[1,20], tabname[1,20] from sysmaster:systabnames > where > > partnum='0x600249' ) then maybe that will give you a clue as to what is > > going on. > > > > Regards > > > > David Linthwaite > > Lintel Software Consultancy Ltd > > IBM Business Partner > > > > Tel.: 01244 357250 > > Fax.: 01244 357248 > > > > mailto:dlinthwaite@lintel.co.uk > > > > -----Original Message----- > > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of > > Alexandre Marini > > Sent: 17 June 2009 13:59 > > To: ids@iiug.org > > Subject: Several rollbacks on logical-logs [16065] > > > > Hello everybody! > > We´re having several rollback recordins on our logical-logs, generated by > > dba transactions, on our 11.50.FC4 instance running on a linux_64 > machine, > > as follows: > > > > log uniqid: 971. > > addr len type xid id link > > 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 > > 54374 *dba* > > 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM > 1488 > > 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 > > 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 > 9c0732c > > 93 9c07410 40 CLR 1488 0 9c07050 > > 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 > > > > There´s an enormous quantity of these rollbacks (around 110+) recordings > per > > *second *of logical-log!!! > > > > The main question is: > > 1) how can we trace it, because with our sql trace option running for > user > > "dba", it doesn´t appear any record of rollback!!! > > 2) there are several r4gl programs running constantly on dba´s crontab > file, > > but on these application logs, there´s no recording of transaction > > errors.... > > > > We´re desperate to find out what´s originating these kind of records, > that´s > > elevating our use of logical-logs too much (the fill time of the above > > logical-log was): > > 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up > *575 > > KB/SEC* > > > > We´re RTO enabling with > > RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds > > > > but we have a task running a checkpoint in every 40 minutes. > > > > If someone could give us an idea of tracing these events, we´d > appreciate! > > > > Regards. > > > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --0016e6d27ed19a08b0046cb7a01e

Mr Art, your explanation is so clear, that I thought "how didn´t we think about this before???" KKKKKK I´ve already forward the information to the developers, thanks a lot! Alexandre Marini Analista de Tecnologia da Informação - DBA SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW Art Kagel escreveu: > Failed inserts are expensive because the engine does not realize that the > insert is causing a duplicate row until the row and all of its index entries > exist, so, if there is a duplicate primary or unique key or a duplicate > unique index entry then that portion of the transaction has to be rolled > back, yes, even if the update is committed. > > It is much cheaper to try the update first and check the number of rows > affected by the update (updating zero rows is not an error) to make sure > that it is one and not zero. This is because the update will use the unique > index that is causing the duplicate row failure on insert and immediately > return having update no rows since the row was not there. Then if the > update updated no rows you can then perform the insert. > > Rule of thumb: Only if about 70% or more of the operations will result in > a successful insert should you try the insert before the update. If even > 31% of the operations result in an update being the final successful > operation, you should be doing the update first. This is an easy fix. I > patched a similar program for a client last year and the mods took about 5 > minutes in emacs (probably would have taken me 8 minutes in vi) including > reindenting the code that had been moved around. > > The var you need to check after the attempted update is sqlca.sqlerrd[2] in > ESQL/C or sqlca.sqlerrd[3] in 4GL. > > Art > > 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. > > On Fri, Jun 19, 2009 at 10:12 AM, Alexandre Marini < > amarini@fazenda.ms.gov.br> wrote: > > >> Ok!!! Now I could find the table around the rollbacks. >> >> On the HINSERT line, there´s the table partnum, >> and on the next two ADDITEM lines, there are 2 indexes partnum (the 2 >> indexes that the above table contains). >> >> My doubt is: >> This sql statement mentioned by the HINSERT line, could it be an update >> clause, or just an insert generate this kind of record? >> >> ------------------------------------------------------- >> Explaining: >> our r4gl program tryes to do an insert on the table first, >> and then whe analyse the sql errorcodes, like these two >> if sqlca.sqlcode = -239 or sqlca.sqlcode = -268 then >> >> "we call an update function." >> >> Our big rollbacks on logical-logs are happening, even if the application >> doesn´t indicate any errors on its log. >> >> Is that normal, the database should really record these rollbacks? >> >> I´m not understanding if there´s really an application error, or a >> database normal task, >> because the application had entered the "if" statement above ? >> >> Regards, friends. >> >> Alexandre Marini >> >> Analista de Tecnologia da Informação - DBA >> >> msn: alexandre_marini@hotmail.com >> >> SEFAZ-MS / UIMP / Sistemas: Fronteiras e SIG-DW >> >> David Linthwaite escreveu: >> >>> Hi Alexandre >>> >>> The extract shows an insert operation into table with hex partnum 600249. >>> If you find out the table that is being operated on ( select >>> hex(partnum),dbsname[1,20], tabname[1,20] from sysmaster:systabnames >>> >> where >> >>> partnum='0x600249' ) then maybe that will give you a clue as to what is >>> going on. >>> >>> Regards >>> >>> David Linthwaite >>> Lintel Software Consultancy Ltd >>> IBM Business Partner >>> >>> Tel.: 01244 357250 >>> Fax.: 01244 357248 >>> >>> mailto:dlinthwaite@lintel.co.uk >>> >>> -----Original Message----- >>> From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of >>> Alexandre Marini >>> Sent: 17 June 2009 13:59 >>> To: ids@iiug.org >>> Subject: Several rollbacks on logical-logs [16065] >>> >>> Hello everybody! >>> We´re having several rollback recordins on our logical-logs, generated by >>> dba transactions, on our 11.50.FC4 instance running on a linux_64 >>> >> machine, >> >>> as follows: >>> >>> log uniqid: 971. >>> addr len type xid id link >>> 9c07018 56 BEGIN 1488 971 0 06/17/2009 07:10:01 >>> 54374 *dba* >>> 9c07050 732 HINSERT 1488 0 9c07018 600249 41606 665 9c0732c 68 ADDITEM >>> >> 1488 >> >>> 0 9c07050 60024a 41606 147 1 7 9c07370 64 ADDITEM 1488 0 9c0732c 6003c6 >>> 41606 10 1 4 9c073b0 48 CLR 1488 0 9c07370 a 9c073e0 48 CLR 1488 0 >>> >> 9c0732c >> >>> 93 9c07410 40 CLR 1488 0 9c07050 >>> 9c07438 56 ROLLBACK 1488 0 9c07018 06/17/2009 07:10:01 >>> >>> There´s an enormous quantity of these rollbacks (around 110+) recordings >>> >> per >> >>> *second *of logical-log!!! >>> >>> The main question is: >>> 1) how can we trace it, because with our sql trace option running for >>> >> user >> >>> "dba", it doesn´t appear any record of rollback!!! >>> 2) there are several r4gl programs running constantly on dba´s crontab >>> >> file, >> >>> but on these application logs, there´s no recording of transaction >>> errors.... >>> >>> We´re desperate to find out what´s originating these kind of records, >>> >> that´s >> >>> elevating our use of logical-logs too much (the fill time of the above >>> logical-log was): >>> 50 *971* 100 MB 100 % 3_2508828 2009-06-17 07:10:32 Used and Backed Up >>> >> *575 >> >>> KB/SEC* >>> >>> We´re RTO enabling with >>> RTO_SERVER_RESTART=600 seconds Estimated recovery time 14 seconds >>> >>> but we have a task running a checkpoint in every 40 minutes. >>> >>> If someone could give us an idea of tracing these events, we´d >>> >> appreciate! >> >>> Regards. >>> >>> >> >> >> > ******************************************************************************* > >> Forum Note: Use "Reply" to post a response in the discussion forum. >> >> >> > > --0016e6d27ed19a08b0046cb7a01e > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > > >