Perl script excessively executing statement
Hi all, I have a perl script in my monitoring system that has been working for months without an issue. Basically, it connects to an Oracle 12c database, prepares a statement, then it executes the statement, then it has a while loop to process the returned rows. So under normal conditions the statement is executed once every 5 minutes. Now on Friday last week, it did something really strange which I cannot account for the behaviour. According to the DBA, the statement in the script was executed 12610 times over a 50 minute period causing the database to become non-responsive. The DBAs also stated that the script only connected to the database once at the beginning of the 50 minute period. Average execution time of the statement was 0.26 seconds. According to the log for my script, the script only executed once at the beginning of the 50 minute period, and then after that, returned to executing every 5 minutes. Since that incident, the statememt in question has only executed the expected 12 times per hour. I have yet to find a satisfactory reason the SQL statement from this perl script executed so many times in the 50 minute period. Script is running on an Oracle Linux 7.7 server with; * oracle 12c client installed * perl 5.16.3 * perl-DBI 1.627-4 ( from Oracle Linix Latest yum repository) * perl-DBD-ODBC 1.50.-3 (from EPEL) * DBD::Oracle 1.80 (from CPAN) Oracle 12 database is on a remote server. Anyone have any ideas why the SQL statement would have been executed 12000+ times in a 50minute period, when the script and its schedule should not have executed the SQL any more frequiently than 12 times an hour? Regards, John
Re: Perl script excessively executing statement
I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated along with everything else. On Tue, Feb 11, 2020 at 11:56 PM JohnD Blackburn wrote: > Hi all, > > > > I have a perl script in my monitoring system that has been working for > months without an issue. > > > > Basically, it connects to an Oracle 12c database, prepares a statement, > then it executes the statement, then it has a while loop to process the > returned rows. > > > > So under normal conditions the statement is executed once every 5 minutes. > > > > Now on Friday last week, it did something really strange which I cannot > account for the behaviour. > > > > According to the DBA, the statement in the script was executed 12610 times > over a 50 minute period causing the database to become non-responsive. The > DBAs also stated that the script only connected to the database once at the > beginning of the 50 minute period. Average execution time of the statement > was 0.26 seconds. > > > > According to the log for my script, the script only executed once at the > beginning of the 50 minute period, and then after that, returned to > executing every 5 minutes. > > > > Since that incident, the statememt in question has only executed the > expected 12 times per hour. > > > > I have yet to find a satisfactory reason the SQL statement from this perl > script executed so many times in the 50 minute period. > > > > Script is running on an Oracle Linux 7.7 server with; > >- oracle 12c client installed >- perl 5.16.3 >- perl-DBI 1.627-4 ( from Oracle Linix Latest yum repository) >- perl-DBD-ODBC 1.50.-3 (from EPEL) >- DBD::Oracle 1.80 (from CPAN) > > > > Oracle 12 database is on a remote server. > > > > Anyone have any ideas why the SQL statement would have been executed > 12000+ times in a 50minute period, when the script and its schedule should > not have executed the SQL any more frequiently than 12 times an hour? > > > > Regards, > > John > > > > >
RE: Perl script excessively executing statement
Is that a behavior of DBI or DBD::Oracle? My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1st place, I don’t know how to reproduce it to test if any mitigations are sufficient. Cheers, John From: Geoffrey Rommel Sent: Thursday, 13 February 2020 2:56 AM To: JohnD Blackburn Cc: dbi-users@perl.org Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated along with everything else. On Tue, Feb 11, 2020 at 11:56 PM JohnD Blackburn mailto:johnd.blackb...@au.abb.com>> wrote: Hi all, I have a perl script in my monitoring system that has been working for months without an issue. Basically, it connects to an Oracle 12c database, prepares a statement, then it executes the statement, then it has a while loop to process the returned rows. So under normal conditions the statement is executed once every 5 minutes. Now on Friday last week, it did something really strange which I cannot account for the behaviour. According to the DBA, the statement in the script was executed 12610 times over a 50 minute period causing the database to become non-responsive. The DBAs also stated that the script only connected to the database once at the beginning of the 50 minute period. Average execution time of the statement was 0.26 seconds. According to the log for my script, the script only executed once at the beginning of the 50 minute period, and then after that, returned to executing every 5 minutes. Since that incident, the statememt in question has only executed the expected 12 times per hour. I have yet to find a satisfactory reason the SQL statement from this perl script executed so many times in the 50 minute period. Script is running on an Oracle Linux 7.7 server with; * oracle 12c client installed * perl 5.16.3 * perl-DBI 1.627-4 ( from Oracle Linix Latest yum repository) * perl-DBD-ODBC 1.50.-3 (from EPEL) * DBD::Oracle 1.80 (from CPAN) Oracle 12 database is on a remote server. Anyone have any ideas why the SQL statement would have been executed 12000+ times in a 50minute period, when the script and its schedule should not have executed the SQL any more frequiently than 12 times an hour? Regards, John
Re: Perl script excessively executing statement
On 13/2/20 11:13 am, JohnD Blackburn wrote: Is that a behavior of DBI or DBD::Oracle? Maybe your script, if you are blindly looping when it gets an error? Overall, I don't think there is enough information to point directly at a cause. Presumably the DBA meant that a SQL statement (of some kind) was executed 12610 times; not that your script was invoked that number of times. My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <Somewhere you might want to tune ora_prefetch_rows or RowCacheSize, depending how many rows you expect the query to return. This is unrelated to your question. my $arraySelect = $dbh->prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1^st place, I don’t know how to reproduce it to test if any mitigations are sufficient. You can set sqlnet.ora parameters to bound the time taken for connection and statement execution. Refer to https://cx-oracle.readthedocs.io/en/latest/user_guide/ha.html#network-configuration and https://oracle.github.io/node-oracledb/doc/api.html#connectionha since the sqlnet.ora settings will be the same for DBD::Oracle - the network layer is common across all the C-based drivers. Depending on your requirements, you may want to sleep between retries. Chris Cheers, John *From:* Geoffrey Rommel *Sent:* Thursday, 13 February 2020 2:56 AM *To:* JohnD Blackburn *Cc:* dbi-users@perl.org *Subject:* Re: Perl script excessively executing statement *CAUTION:*This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated along with everything else. On Tue, Feb 11, 2020 at 11:56 PM JohnD Blackburn mailto:johnd.blackb...@au.abb.com>> wrote: Hi all, I have a perl script in my monitoring system that has been working for months without an issue. Basically, it connects to an Oracle 12c database, prepares a statement, then it executes the statement, then it has a while loop to process the returned rows. So under normal conditions the statement is executed once every 5 minutes. Now on Friday last week, it did something really strange which I cannot account for the behaviour. According to the DBA, the statement in the script was executed 12610 times over a 50 minute period causing the database to become non-responsive. The DBAs also stated that the script only connected to the database once at the beginning of the 50 minute period. Average execution time of the statement was 0.26 seconds. According to the log for my script, the script only executed once at the beginning of the 50 minute period, and then after that, returned to executing every 5 minutes. Since that incident, the statememt in question has only executed the expected 12 times per hour. I have yet to find a satisfactory reason the SQL statement from this perl script executed so many times in the 50 minute period. Script is running on an Oracle Linux 7.7 server with; * oracle 12c client installed * perl 5.16.3 * perl-DBI 1.627-4 ( from Oracle Linix Latest yum repository) * perl-DBD-ODBC 1.50.-3 (from EPEL) * DBD::Oracle 1.80 (from CPAN) Oracle 12 database is on a remote server. Anyone have any ideas why the SQL statement would have been executed 12000+ times in a 50minute period, when the script and its schedule should not have executed the SQL any more frequiently than 12 times an hour? Regards, John -- https://twitter.com/ghrd
RE: Perl script excessively executing statement
The DBA pulled info from some cache that showed the SQL statement from the script was executed 12610 times. So if I were to add an “or die $!” statement after the fetchrow_array(), that might fix things? (or prevent it from trying to continue if there are errors?) Or catch errors after the execute statement? From: Christopher Jones Sent: Thursday, 13 February 2020 12:56 PM To: dbi-users@perl.org; JohnD Blackburn Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On 13/2/20 11:13 am, JohnD Blackburn wrote: Is that a behavior of DBI or DBD::Oracle? Maybe your script, if you are blindly looping when it gets an error? Overall, I don't think there is enough information to point directly at a cause. Presumably the DBA meant that a SQL statement (of some kind) was e xecuted 12610 times; not that your script was invoked that number of times. My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1st place, I don’t know how to reproduce it to test if any mitigations are sufficient. You can set sqlnet.ora parameters to bound the time taken for connection and statement execution. Refer to https://cx-oracle.readthedocs.io/en/latest/user_guide/ha.html#network-configuration<https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fcx-oracle.readthedocs.io%2Fen%2Flatest%2Fuser_guide%2Fha.html%23network-configuration&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7C75ee9e961c994c802fe708d7b030497c%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C0%7C637171593755922211&sdata=wVBUPnUXOnie2z9yYwGPwC4J%2FtiDtMUXl1DXAjKZtyo%3D&reserved=0> and https://oracle.github.io/node-oracledb/doc/api.html#connectionha<https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Foracle.github.io%2Fnode-oracledb%2Fdoc%2Fapi.html%23connectionha&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7C75ee9e961c994c802fe708d7b030497c%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C0%7C637171593755932204&sdata=iZPYDmpjTj%2FPw%2FShQqdiSQIccucpjLqO1chp%2BQq9I4Q%3D&reserved=0> since the sqlnet.ora settings will be the same for DBD::Oracle - the network layer is common across all the C-based drivers. Depending on your requirements, you may want to sleep between retries. Chris Cheers, John From: Geoffrey Rommel <mailto:wgrom...@gmail.com> Sent: Thursday, 13 February 2020 2:56 AM To: JohnD Blackburn <mailto:johnd.blackb...@au.abb.com> Cc: dbi-users@perl.org<mailto:dbi-users@perl.org> Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated along with everything else. On Tue, Feb 11, 2020 at 11:56 PM JohnD Blackburn mailto:johnd.blackb...@au.abb.com>> wrote: Hi all, I have a perl script in my monitoring system that has been working for months without an issue. Basically, it connects to an Oracle 12c database, prepares a statement, then it executes the statement, then it has a while loop to process the returned rows. So under normal conditions the statement is executed once every 5 minutes. Now on Friday last week, it did something really strange which I cannot account for the behaviour. According to the DBA, the statement in the script was executed 12610 times over a 50 minute period causing the database to become non-responsive. The DBAs also stated that the script only connected to the database once at the beginning of the 50 minute period. Average execution time of the statement was 0.26 seconds. According to the log for my script, the script only executed once at the beginning
AW: Perl script excessively executing statement
Hi John, in my opinion do yourself a favor and use the RaiseError-option of DBI. Any error you then get while using DBI related calls raise and exception. And when you think about it there a seldom cases where you can react better than killing a process getting a db related error. And if you really need to catch an db related exception Try::Tiny is your friend. Best regards Andreas Von: JohnD Blackburn Gesendet: Donnerstag, 13. Februar 2020 07:59 An: Christopher Jones ; dbi-users@perl.org Betreff: RE: Perl script excessively executing statement The DBA pulled info from some cache that showed the SQL statement from the script was executed 12610 times. So if I were to add an “or die $!” statement after the fetchrow_array(), that might fix things? (or prevent it from trying to continue if there are errors?) Or catch errors after the execute statement? From: Christopher Jones mailto:christopher.jo...@oracle.com> > Sent: Thursday, 13 February 2020 12:56 PM To: dbi-users@perl.org <mailto:dbi-users@perl.org> ; JohnD Blackburn mailto:johnd.blackb...@au.abb.com> > Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On 13/2/20 11:13 am, JohnD Blackburn wrote: Is that a behavior of DBI or DBD::Oracle? Maybe your script, if you are blindly looping when it gets an error? Overall, I don't think there is enough information to point directly at a cause. Presumably the DBA meant that a SQL statement (of some kind) was e xecuted 12610 times; not that your script was invoked that number of times. My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1st place, I don’t know how to reproduce it to test if any mitigations are sufficient. You can set sqlnet.ora parameters to bound the time taken for connection and statement execution. Refer to https://cx-oracle.readthedocs.io/en/latest/user_guide/ha.html#network-configuration <https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fcx-oracle.readthedocs.io%2Fen%2Flatest%2Fuser_guide%2Fha.html%23network-configuration&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7C75ee9e961c994c802fe708d7b030497c%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C0%7C637171593755922211&sdata=wVBUPnUXOnie2z9yYwGPwC4J%2FtiDtMUXl1DXAjKZtyo%3D&reserved=0> and https://oracle.github.io/node-oracledb/doc/api.html#connectionha <https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Foracle.github.io%2Fnode-oracledb%2Fdoc%2Fapi.html%23connectionha&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7C75ee9e961c994c802fe708d7b030497c%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C0%7C637171593755932204&sdata=iZPYDmpjTj%2FPw%2FShQqdiSQIccucpjLqO1chp%2BQq9I4Q%3D&reserved=0> since the sqlnet.ora settings will be the same for DBD::Oracle - the network layer is common across all the C-based drivers. Depending on your requirements, you may want to sleep between retries. Chris Cheers, John From: Geoffrey Rommel <mailto:wgrom...@gmail.com> Sent: Thursday, 13 February 2020 2:56 AM To: JohnD Blackburn <mailto:johnd.blackb...@au.abb.com> Cc: dbi-users@perl.org <mailto:dbi-users@perl.org> Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated along with everything else. On Tue, Feb 11, 2020 at 11:56 PM JohnD Blackburn mailto:johnd.blackb...@au.abb.com> > wrote: Hi all, I have a perl script in my monitoring system that has be
RE: Perl script excessively executing statement
If you are trying to execute one SQL statement against the database for each loop iteration – you are doing it wrong. You are adding a round trip for every row which will be slow for the client and waist time and other resources on the server. Look on the net for other approaches using NVL and “in” and DECODE. Learn about Oracle inline-views, and clever uses of joins – Learn the difference between “union all” and “union” and how to use DUAL and UNION ALL to create a dynamic-view that can be joined with other tables. Try to figure out how you can do the whole thing in a single SQL statement, then just process the results one row at time. Learn about how to bind variables instead of doing dynamically generated SQL. Learn about how oracle implements UPSERT (insert + update). Hunt down relevant articles on “Ask Tom”. You will have to think harder but your code will be faster and your DBA happier. And you will be a wiser professional. Ask the DBA for help if you are having a hard time figuring it out or share your problem and your solution here and ask for alternatives (you left out most of your code – security concerns?). From: JohnD Blackburn Sent: Thursday, February 13, 2020 1:59 AM To: Christopher Jones ; dbi-users@perl.org Subject: [EXTERNAL] RE: Perl script excessively executing statement The DBA pulled info from some cache that showed the SQL statement from the script was executed 12610 times. So if I were to add an “or die $!” statement after the fetchrow_array(), that might fix things? (or prevent it from trying to continue if there are errors?) Or catch errors after the execute statement? From: Christopher Jones mailto:christopher.jo...@oracle.com>> Sent: Thursday, 13 February 2020 12:56 PM To: dbi-users@perl.org<mailto:dbi-users@perl.org>; JohnD Blackburn mailto:johnd.blackb...@au.abb.com>> Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On 13/2/20 11:13 am, JohnD Blackburn wrote: Is that a behavior of DBI or DBD::Oracle? Maybe your script, if you are blindly looping when it gets an error? Overall, I don't think there is enough information to point directly at a cause. Presumably the DBA meant that a SQL statement (of some kind) was e xecuted 12610 times; not that your script was invoked that number of times. My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1st place, I don’t know how to reproduce it to test if any mitigations are sufficient. You can set sqlnet.ora parameters to bound the time taken for connection and statement execution. Refer to https://cx-oracle.readthedocs.io/en/latest/user_guide/ha.html#network-configuration<https://urldefense.proofpoint.com/v2/url?u=https-3A__eur03.safelinks.protection.outlook.com_-3Furl-3Dhttps-253A-252F-252Fcx-2Doracle.readthedocs.io-252Fen-252Flatest-252Fuser-5Fguide-252Fha.html-2523network-2Dconfiguration-26data-3D02-257C01-257Cjohnd.blackburn-2540au.abb.com-257C75ee9e961c994c802fe708d7b030497c-257C372ee9e09ce04033a64ac07073a91ecd-257C0-257C0-257C637171593755922211-26sdata-3DwVBUPnUXOnie2z9yYwGPwC4J-252FtiDtMUXl1DXAjKZtyo-253D-26reserved-3D0&d=DwMGaQ&c=ukcTAPl5KduEyRvXoL9XMA&r=0EHe68Ki46dgcWiA0JMjgV97dO_1ZKSBkQjMhiDvNg4&m=eTYZSq6Vb362v-t0y-oZeWFoQiPoRGJNQO4DhxguDXE&s=jOEfAb0cL_vx5m2o6rFu3BH8zKp97CHp7KtW8sLMBm0&e=> and https://oracle.github.io/node-oracledb/doc/api.html#connectionha<https://urldefense.proofpoint.com/v2/url?u=https-3A__eur03.safelinks.protection.outlook.com_-3Furl-3Dhttps-253A-252F-252Foracle.github.io-252Fnode-2Doracledb-252Fdoc-252Fapi.html-2523connectionha-26data-3D02-257C01-257Cjohnd.blackburn-2540au.abb.com-257C75ee9e961c994c802fe708d7b030497c-257C372ee9e09ce04033a64ac07073a91ecd-257C0-257C0-257C637171593755932204-26sdata-3DiZPYDmpjTj-252FPw-252FShQqdiSQIccucpjLqO1chp-252BQq9I4Q-253D-26reserved-3D0&d=DwMGaQ&c=ukcTAPl5KduEyRvXoL9XMA&r=0EHe68Ki46dgcWiA0JMjgV97dO_1ZKSBkQjMhiDvNg4&m=eTYZSq6Vb362v-t0y-oZeWFoQiPoRGJNQO4DhxguDXE&s=4Q7U6LmFtJl8YNEeYPfh5DxjTmL2M
Re: Perl script excessively executing statement
On Feb 13, 2020, at 8:30 AM, Fennell, Brian mailto:fenne...@radial.com>> wrote: Try to figure out how you can do the whole thing in a single SQL statement, then just process the results one row at time. Well, based on his example code that’s exactly what he was doing. The only loop was processing the returned rows via $arraySelect->fetchrow_array() I am honestly with Geoffrey on this, I suspect something was broken on the DB itself and it was only coincidental that John’s script was running at the time the db became unresponsive. 1) this was a change in behavior without a change in code; the script had been running just fie for a long time. 2) barring the query returning enormous numbers of rows with a hugely inefficient query involving multiple remote database, etc , even a fairly minimal Oracle install can manage 4 queries per second (12K queries in 50 minutes) without becoming unresponsive, even if they do return tens or hundreds of thousands of rows. -- Bruce Johnson University of Arizona College of Pharmacy Information Technology Group Institutions do not have opinions, merely customs
Re: Perl script excessively executing statement
On 13/2/20 5:58 pm, JohnD Blackburn wrote: The DBA pulled info from some cache that showed the SQL statement from the script was executed 12610 times. So if I were to add an “or die $!” statement after the fetchrow_array(), that might fix things? (or prevent it from trying to continue if there are errors?) Or catch errors after the execute statement? Error checking after each call is a good idea. The prepare() (if my implementation refreshing skills are accurate) maps to an Oracle call that does a lightweight parse to check things like bind variables and quotes. Most errors will come from the execute() - bogus syntax, wrong columns, DB space errors etc. Chris *From:* Christopher Jones *Sent:* Thursday, 13 February 2020 12:56 PM *To:* dbi-users@perl.org; JohnD Blackburn *Subject:* Re: Perl script excessively executing statement *CAUTION:*This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On 13/2/20 11:13 am, JohnD Blackburn wrote: Is that a behavior of DBI or DBD::Oracle? Maybe your script, if you are blindly looping when it gets an error? Overall, I don't think there is enough information to point directly at a cause. Presumably the DBA meant that a SQL statement (of some kind) was e xecuted 12610 times; not that your script was invoked that number of times. My script says prepare or die, so any retries would have had to come directly from the DBD::Oracle module Script basically says: use DBD::Oracle; my $dbh = DBI->connect("dbi:Oracle:$dbSID", $user, $passwd, {AutoCommit => 0 }); my $statement = <Somewhere you might want to tune ora_prefetch_rows or RowCacheSize, depending how many rows you expect the query to return. This is unrelated to your question. my $arraySelect = $dbh->prepare($statement) or die $!; $arraySelect->execute(); while ( my ($var1, $var2, $var3, $var4) = $arraySelect->fetchrow_array() ) { } $arraySelect->finish(); $dbh->disconnect(); I don’t work much with the DBD::Oracle module or perl and what I have is just reworked from scripts others have written. Is there parameters for the DBD::Oracle functions that can affect their behavior? If this is behavior of the execute function, I really need to be able to reign it in to limit its impact if it ever does it again. Not knowing why the issue triggered in the 1^st place, I don’t know how to reproduce it to test if any mitigations are sufficient. You can set sqlnet.ora parameters to bound the time taken for connection and statement execution. Refer to https://cx-oracle.readthedocs.io/en/latest/user_guide/ha.html#network-configuration <https://urldefense.com/v3/__https://eur03.safelinks.protection.outlook.com/?url=https*3A*2F*2Fcx-oracle.readthedocs.io*2Fen*2Flatest*2Fuser_guide*2Fha.html*23network-configuration&data=02*7C01*7Cjohnd.blackburn*40au.abb.com*7C75ee9e961c994c802fe708d7b030497c*7C372ee9e09ce04033a64ac07073a91ecd*7C0*7C0*7C637171593755922211&sdata=wVBUPnUXOnie2z9yYwGPwC4J*2FtiDtMUXl1DXAjKZtyo*3D&reserved=0__;JSUlJSUlJSUlJSUlJSUlJSUl!!GqivPVa7Brio!P9p6l_vepYYnGyu45_vqxFEUnEd_tpXLUZ8DxElcAZGs05cgs-IJxDx4g8H-qje3S1gj1g$> and https://oracle.github.io/node-oracledb/doc/api.html#connectionha <https://urldefense.com/v3/__https://eur03.safelinks.protection.outlook.com/?url=https*3A*2F*2Foracle.github.io*2Fnode-oracledb*2Fdoc*2Fapi.html*23connectionha&data=02*7C01*7Cjohnd.blackburn*40au.abb.com*7C75ee9e961c994c802fe708d7b030497c*7C372ee9e09ce04033a64ac07073a91ecd*7C0*7C0*7C637171593755932204&sdata=iZPYDmpjTj*2FPw*2FShQqdiSQIccucpjLqO1chp*2BQq9I4Q*3D&reserved=0__;JSUlJSUlJSUlJSUlJSUlJSUlJQ!!GqivPVa7Brio!P9p6l_vepYYnGyu45_vqxFEUnEd_tpXLUZ8DxElcAZGs05cgs-IJxDx4g8H-qjdP4_-wrg$> since the sqlnet.ora settings will be the same for DBD::Oracle - the network layer is common across all the C-based drivers. Depending on your requirements, you may want to sleep between retries. Chris Cheers, John *From:* Geoffrey Rommel <mailto:wgrom...@gmail.com> *Sent:* Thursday, 13 February 2020 2:56 AM *To:* JohnD Blackburn <mailto:johnd.blackb...@au.abb.com> *Cc:* dbi-users@perl.org <mailto:dbi-users@perl.org> *Subject:* Re: Perl script excessively executing statement *CAUTION:*This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. I don't work with Oracle, but here's a guess. Maybe the database was unresponsive before your script started running, not as a result of it. If so, maybe your script tried to prepare the statement, failed, and retried 12000 times. Eventually the DBA noticed the problem and restarted the database, at which time your script was terminated
RE: Perl script excessively executing statement
John, One way for you to execute sql thousands of times from perl is to do it in your loop. The other way is for the Oracle server to do it for you in its loop. Sometimes an Oracle Upgrade will cause the Oracle Optimizer to change - this can cause SQL that "worked fine" to start behaving differently. A SQL join is translated to one or more nested loops by the Oracle Optimizer - SQL is an algebraic notation but computers don't really "do" algebra, they do nested loops. Which table is selected first and which is second (and third and so-on). If you have functions they may execute SQL once per row, but this may be in the outer loop (seldom) or in the inner loop (often). The Oracle SQL Optimizer plan can also change when the table statistics are recalculated - which doesn't require an Oracle upgrade. EXPLAIN PLAN is your way to see which table gets looped over in which order as the table statistics and the Oracle optimizer are RIGHT NOW. Some more hints: EXPLAIN PLAN https://grokbase.com/t/perl/dbi-users/094mcz7m5w/an-explain-plan-for-oracle-queries-with-placeholders https://www.oracle.com/technetwork/database/bi-datawarehousing/twp-explain-the-explain-plan-052011-393674.pdf DBI DEBUG https://www.easysoft.com/developer/languages/perl/dbi-debugging.html https://www.perlmonks.org/bare/?node_id=90692DBI-trace() https://www.effectiveperlprogramming.com/2010/04/use-dbi_trace-to-follow-dbis-work/ The error you are getting may be a result of a client/server incompatibility (if the server version changed and your client version did not) - you could try an alternate Oracle DBD plug-in / class. Alternate Oracle DBD plugin https://github.com/perl5-dbi/DBD-Oracle Can be installed with cpanm using a git url (but not with cpan) https://metacpan.org/pod/cpanm you will need oracle C libraries to build - it won't be easy Alternate Oracle DBD plugin - Oracle JDBC https://metacpan.org/pod/JDBC https://metacpan.org/pod/distribution/DBD-JDBC/JDBC.pod#Starting-the-server you will need a jvm installed - and oracle's jdbc jars - it might be easier (or not) you can get a free jvm here: https://sdkman.io/ From: JohnD Blackburn Sent: Wednesday, February 12, 2020 12:56 AM To: dbi-users@perl.org Subject: [EXTERNAL] Perl script excessively executing statement Hi all, I have a perl script in my monitoring system that has been working for months without an issue. Basically, it connects to an Oracle 12c database, prepares a statement, then it executes the statement, then it has a while loop to process the returned rows. So under normal conditions the statement is executed once every 5 minutes. Now on Friday last week, it did something really strange which I cannot account for the behaviour. According to the DBA, the statement in the script was executed 12610 times over a 50 minute period causing the database to become non-responsive. The DBAs also stated that the script only connected to the database once at the beginning of the 50 minute period. Average execution time of the statement was 0.26 seconds. According to the log for my script, the script only executed once at the beginning of the 50 minute period, and then after that, returned to executing every 5 minutes. Since that incident, the statememt in question has only executed the expected 12 times per hour. I have yet to find a satisfactory reason the SQL statement from this perl script executed so many times in the 50 minute period. Script is running on an Oracle Linux 7.7 server with; * oracle 12c client installed * perl 5.16.3 * perl-DBI 1.627-4 ( from Oracle Linix Latest yum repository) * perl-DBD-ODBC 1.50.-3 (from EPEL) * DBD::Oracle 1.80 (from CPAN) Oracle 12 database is on a remote server. Anyone have any ideas why the SQL statement would have been executed 12000+ times in a 50minute period, when the script and its schedule should not have executed the SQL any more frequiently than 12 times an hour? Regards, John The information contained in this electronic mail transmission is intended only for the use of the individual or entity named in this transmission. If you are not the intended recipient of this transmission, you are hereby notified that any disclosure, copying or distribution of the contents of this transmission is strictly prohibited and that you should delete the contents of this transmission from your system immediately. Any comments or statements contained in this transmission do not necessarily reflect the views or position of Radial or its subsidiaries and/or affiliates.
RE: Perl script excessively executing statement
The SQL statement is only executed once within the Perl script. There is no additional executions of the query. The query only selects from tables. It was the entire query that was executed according to statspack 12000 times, not sub-components of it. So seems as if some mechanism within DBI, DBD, or Oracle was at fault. Here is the statement that Statspack reported the excessive executions on: select prog_name, dstrct_code, Start_Date, Start_Time, Runtime_Minutes, Median_Elapsed, Std_Deviation, Count_Instances, (4*Std_Deviation+Median_Elapsed + 5) as THRESHOLD, UUID from ( with history as ( select prog_name, dstrct_code, round(sum(elapsed_minutes),5) as Elapsed_Minutes, round(avg(elapsed_minutes),5) as Average_Elapsed, round(median(elapsed_minutes),5) as Median_Elapsed, round(stddev(elapsed_minutes),5) as Std_Deviation, count(*) as Count_Instances from ( select prog_name, dstrct_code, 1440 * (to_date(stop_date||stop_time_hhmmss,'MMDDHH24MISS') - to_date(start_date||start_time_hhmmss,'MMDDHH24MISS')) as Elapsed_Minutes fromellipse.msf085 History ) group by prog_name, dstrct_code ) select Executing.prog_name, Executing.dstrct_code, Executing.start_date, Executing.start_time, round((1440 * ((cast(SYSTIMESTAMP at time zone NVL(trim(tz.district_time_zone),sessiontimezone) as date)) - to_date(Executing.start_date || Executing.start_time, 'MMDDHH24MI') ) ),5) as RUNTIME_MINUTES, History.Median_elapsed, History.Count_Instances, History.Std_Deviation, Executing.UUID from Ellipse.MSF080 Executing inner join History on (history.dstrct_code = Executing.dstrct_code and History.prog_name = Executing.prog_name) inner join Ellipse.msf000_dc0002 tz on (tz.dstrct_code = Executing.dstrct_code) where Executing.process_Status = 'E' ) order by 1,2,3,4,5 It is not being executed inside a loop. Only loop is a while loop calling fetchrow_array, and there is no subsequent SQL being executed by the script inside the loop. The version of the database and Oracle client has not been changed. Optimizer adaptive features are disabled in this database. I will have a look at the links you provided for DBI debug. Although this was the only instance we know about where this query was executed excessively, maybe it is happening more frequently than we realize and debugging might provide some answers. Thanks for your reply Regards, John -Original Message- From: Fennell, Brian Sent: Saturday, 15 February 2020 5:47 AM To: JohnD Blackburn ; dbi-users@perl.org Subject: RE: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. John, One way for you to execute sql thousands of times from perl is to do it in your loop. The other way is for the Oracle server to do it for you in its loop. Sometimes an Oracle Upgrade will cause the Oracle Optimizer to change - this can cause SQL that "worked fine" to start behaving differently. A SQL join is translated to one or more nested loops by the Oracle Optimizer - SQL is an algebraic notation but computers don't really "do" algebra, they do nested loops. Which table is selected first and which is second (and third and so-on). If you have functions they may execute SQL once per row, but this may be in the outer loop (seldom) or in the inner loop (often). The Oracle SQL Optimizer plan can also change when the table statistics are recalculated - which doesn't require an Oracle upgrade. EXPLAIN PLAN is your way to see which table gets looped over in which order as the table statistics and the Oracle optimizer are RIGHT NOW. Some more hints: EXPLAIN PLAN https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgrokbase.com%2Ft%2Fperl%2Fdbi-users%2F094mcz7m5w%2Fan-explain-plan-for-oracle-queries-with-placeholders&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7Ce88a55c0922e4e14f3c108d7b186aad0%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C1%7C637173064272927190&sdata=aLJqdmPbot3GZJiLhGQ9YOfFt%2F8T75SYMMoHIDkuKe0%3D&reserved=0 https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.oracle.com%2Ftechnetwork%2Fdatabase%2Fbi-datawarehousing%2Ftwp-explain-the-explain-plan-052011-393674.pdf&data=02%7C01%7Cjohnd.blackburn%40au.abb.com%7Ce88a55c0922e4e14f3c108d7b186aad0%7C372ee9e09ce04033a64ac07073a91ecd%7C0%7C1%7C637173064272927190&sdata=ws%2Fz9T0NP3RTNB7xktNLPmn38OOwQC06dADwTU4Pyug%3D&reserved=0 DBI DEBUG https://eur03.safelinks.p
Re: Perl script excessively executing statement
On Thu, 13 Feb 2020 06:58:37 + JohnD Blackburn wrote: > The DBA pulled info from some cache that showed the SQL statement > from the script was executed 12610 times. > > So if I were to add an “or die $!” statement after the > fetchrow_array(), that might fix things? (or prevent it from trying > to continue if there are errors?) Or catch errors after the execute > statement? Q: What are you really trying to accomplish? Basic rules: If you need to run SQL more than once parepare it. If you are not sure how well it runs then you can evaluate it beorehand -- which also spots errors, can help track down un-used indexes. As noted, generating a single query, preparing and running once, then extracting the rows (preferably as arrays rather than hashes) will be the most effecient way. The database is going to do a much better job filtering anything it can locally in native format beore you convert it to ASCII char strings and pull the same content across a LAN. -- Steven Lembark3646 Flora Place Workhorse ComputingSt. Louis, MO 63110 lemb...@wrkhors.com+1 888 359 3508
RE: Perl script excessively executing statement
The problem is not about how well the SQL runs. It runs in less than a second, and it should only be getting executed 12 times an hour. What I'm trying to do is to figure out how the SQL statement got executed 1000 times more than it should have done (which brought the db to its knees for 50 minutes with nothing being able to connect). If there is something in DBI that is automatically re-executing for some unknown reason, I need to be able to mange how often it retries, and how many times, and even how long between re-executions. The logic in the script does not account for 12000 executions in a 1 hour period, so I need to figure out how it happened so I can prevent it happening in the future. There is locking around the perl script execution so that the perl script can't be started if the previous execution has not completed, and the logs show that in the 50 minute period in question, the script only ran once . It didn't report any errors, and appeared to eventually exit successfully. The only thing abnormal is that Oracle Stats Pack shows that SQL statement in the script executed 12000 times and was consuming all available DB threads. I've reviewed the DBI debugging links provided by Brian Fennell and have now added some DBI debugging to the script in the hopes that I can get more info on how DBI is behaving. I came to this mailing list because it seems to me that the problem is with DBI, either I've hit some bug, or my usage is not correct (or there is some other problem deeper down in the stack) Cheers, John -Original Message- From: Steven Lembark Sent: Tuesday, 18 February 2020 3:47 AM To: dbi-users@perl.org Cc: lemb...@wrkhors.com Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Thu, 13 Feb 2020 06:58:37 + JohnD Blackburn wrote: > The DBA pulled info from some cache that showed the SQL statement from > the script was executed 12610 times. > > So if I were to add an “or die $!” statement after the > fetchrow_array(), that might fix things? (or prevent it from trying > to continue if there are errors?) Or catch errors after the execute > statement? Q: What are you really trying to accomplish? Basic rules: If you need to run SQL more than once parepare it. If you are not sure how well it runs then you can evaluate it beorehand -- which also spots errors, can help track down un-used indexes. As noted, generating a single query, preparing and running once, then extracting the rows (preferably as arrays rather than hashes) will be the most effecient way. The database is going to do a much better job filtering anything it can locally in native format beore you convert it to ASCII char strings and pull the same content across a LAN. -- Steven Lembark3646 Flora Place Workhorse ComputingSt. Louis, MO 63110 lemb...@wrkhors.com+1 888 359 3508
Re: Perl script excessively executing statement
On 18/2/20 9:51 am, JohnD Blackburn wrote: The problem is not about how well the SQL runs. It runs in less than a second, and it should only be getting executed 12 times an hour. What I'm trying to do is to figure out how the SQL statement got executed 1000 times more than it should have done (which brought the db to its knees for 50 minutes with nothing being able to connect). If there is something in DBI that is automatically re-executing for some unknown reason, I need to be able to mange how often it retries, and how many times, and even how long between re-executions. The logic in the script does not account for 12000 executions in a 1 hour period, so I need to figure out how it happened so I can prevent it happening in the future. There is locking around the perl script execution so that the perl script can't be started if the previous execution has not completed, and the logs show that in the 50 minute period in question, the script only ran once . It didn't report any errors, and appeared to eventually exit successfully. The only thing abnormal is that Oracle Stats Pack shows that SQL statement in the script executed 12000 times and was consuming all available DB threads. I've reviewed the DBI debugging links provided by Brian Fennell and have now added some DBI debugging to the script in the hopes that I can get more info on how DBI is behaving. I came to this mailing list because it seems to me that the problem is with DBI, either I've hit some bug, or my usage is not correct (or there is some other problem deeper down in the stack) Cheers, John The scenario is unexpected, so I think you're at the 'take an aspirin and if pain persists...' stage. Add the extra error checking, locking and logging, and then see if it happens again. As well as the extra locking around the script invocation, you could ensure the script itself doesn't execute the statement unnecessarily, e.g. in a loop after a failure. Make sure you're using bind variables appropriately, since these can reduce overhead on the DB. See https://metacpan.org/pod/DBD::Oracle#Placeholders They are also important for reducing SQL Injection attacks. Chris -Original Message- From: Steven Lembark Sent: Tuesday, 18 February 2020 3:47 AM To: dbi-users@perl.org Cc: lemb...@wrkhors.com Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Thu, 13 Feb 2020 06:58:37 + JohnD Blackburn wrote: The DBA pulled info from some cache that showed the SQL statement from the script was executed 12610 times. So if I were to add an “or die $!” statement after the fetchrow_array(), that might fix things? (or prevent it from trying to continue if there are errors?) Or catch errors after the execute statement? Q: What are you really trying to accomplish? Basic rules: If you need to run SQL more than once parepare it. If you are not sure how well it runs then you can evaluate it beorehand -- which also spots errors, can help track down un-used indexes. As noted, generating a single query, preparing and running once, then extracting the rows (preferably as arrays rather than hashes) will be the most effecient way. The database is going to do a much better job filtering anything it can locally in native format beore you convert it to ASCII char strings and pull the same content across a LAN. -- Steven Lembark3646 Flora Place Workhorse ComputingSt. Louis, MO 63110 lemb...@wrkhors.com+1 888 359 3508 -- https://twitter.com/ghrd
RE: Perl script excessively executing statement
After reviewing the log4perl output from DBIx when running this script I found the following perl module being executed: /usr/local/lib64/perl5/DBD/Oracle.pm Which contains the following subroutine: sub execute_for_fetch { my ($sth, $fetch_tuple_sub, $tuple_status) = @_; my $row_count = 0; my $err_total = 0; my $tuple_count="0E0"; my $tuple_batch_status; my $dbh = $sth->{Database}; my $batch_size =($dbh->{'ora_array_chunk_size'}||= 1000); if(defined($tuple_status)) { @$tuple_status = (); $tuple_batch_status = [ ]; } my $finished; while (1) { my @tuple_batch; for (my $i = 0; $i < $batch_size; $i++) { $finished = $fetch_tuple_sub->(); push @tuple_batch, [@{$finished || last}]; } last unless @tuple_batch; my $err_count = 0; my $res = ora_execute_array($sth, \@tuple_batch, scalar(@tuple_batch), $tuple_batch_status, $err_count ); if (defined($res)) { #no error $row_count += $res; } else { $row_count = undef; } $err_total += $err_count; $tuple_count+=@tuple_batch; push @$tuple_status, @$tuple_batch_status if defined($tuple_status); last if !$finished; } #error check here return $sth->set_err($DBI::stderr, "executing $tuple_count generated $err_total errors") if $err_total; return wantarray ? ($tuple_count, defined $row_count ? $row_count : undef) : $tuple_count; } Is that "while(1)" loop a potential contender for causing this? -Original Message- From: JohnD Blackburn Sent: Tuesday, 18 February 2020 8:51 AM To: Steven Lembark ; dbi-users@perl.org Subject: RE: Perl script excessively executing statement The problem is not about how well the SQL runs. It runs in less than a second, and it should only be getting executed 12 times an hour. What I'm trying to do is to figure out how the SQL statement got executed 1000 times more than it should have done (which brought the db to its knees for 50 minutes with nothing being able to connect). If there is something in DBI that is automatically re-executing for some unknown reason, I need to be able to mange how often it retries, and how many times, and even how long between re-executions. The logic in the script does not account for 12000 executions in a 1 hour period, so I need to figure out how it happened so I can prevent it happening in the future. There is locking around the perl script execution so that the perl script can't be started if the previous execution has not completed, and the logs show that in the 50 minute period in question, the script only ran once . It didn't report any errors, and appeared to eventually exit successfully. The only thing abnormal is that Oracle Stats Pack shows that SQL statement in the script executed 12000 times and was consuming all available DB threads. I've reviewed the DBI debugging links provided by Brian Fennell and have now added some DBI debugging to the script in the hopes that I can get more info on how DBI is behaving. I came to this mailing list because it seems to me that the problem is with DBI, either I've hit some bug, or my usage is not correct (or there is some other problem deeper down in the stack) Cheers, John -Original Message- From: Steven Lembark Sent: Tuesday, 18 February 2020 3:47 AM To: dbi-users@perl.org Cc: lemb...@wrkhors.com Subject: Re: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Thu, 13 Feb 2020 06:58:37 + JohnD Blackburn wrote: > The DBA pulled info from some cache that showed the SQL statement from > the script was executed 12610 times. > > So if I were to add an “or die $!” statement after the > fetchrow_array(), that might fix things? (or prevent it from trying > to continue if there are errors?) Or catch errors after the execute > statement? Q: What are you really trying to accomplish? Basic rules: If you need to run SQL more than once parepare it. If you are not sure how well it runs then you can evaluate it beorehand -- which also spots errors, can help track down un-used indexes. As noted, generating a single query, preparing and running once, then extracting the rows (preferably as arrays rather than hashes) will be the most effecient way. The da
Re: Perl script excessively executing statement
On 18/02/2020 07:57, JohnD Blackburn wrote: After reviewing the log4perl output from DBIx when running this script I found the following perl module being executed: /usr/local/lib64/perl5/DBD/Oracle.pm Which contains the following subroutine: sub execute_for_fetch { my ($sth, $fetch_tuple_sub, $tuple_status) = @_; my $row_count = 0; my $err_total = 0; my $tuple_count="0E0"; my $tuple_batch_status; my $dbh = $sth->{Database}; my $batch_size =($dbh->{'ora_array_chunk_size'}||= 1000); if(defined($tuple_status)) { @$tuple_status = (); $tuple_batch_status = [ ]; } my $finished; while (1) { my @tuple_batch; for (my $i = 0; $i < $batch_size; $i++) { $finished = $fetch_tuple_sub->(); push @tuple_batch, [@{$finished || last}]; } last unless @tuple_batch; my $err_count = 0; my $res = ora_execute_array($sth, \@tuple_batch, scalar(@tuple_batch), $tuple_batch_status, $err_count ); if (defined($res)) { #no error $row_count += $res; } else { $row_count = undef; } $err_total += $err_count; $tuple_count+=@tuple_batch; push @$tuple_status, @$tuple_batch_status if defined($tuple_status); last if !$finished; } #error check here return $sth->set_err($DBI::stderr, "executing $tuple_count generated $err_total errors") if $err_total; return wantarray ? ($tuple_count, defined $row_count ? $row_count : undef) : $tuple_count; } Is that "while(1)" loop a potential contender for causing this? Not unless you are using execute_array. The code you posted didn't look like it was. Martin -- Martin J. Evans Wetherby, UK
RE: Perl script excessively executing statement
John, The part of the story that troubles me is this: "it was working fine - nothing changed - then it broke". It is the middle part - something must have changed. If I were in your shoes I would be looking for the "what changed". I had a piece of perl / Oracle code break when we upgraded the OS. When the OS changed the version of Perl 5 changed, the version of the Oracle module had to change along with the version of perl changing, because there were changes in perl to that made certain "only once" internal variables part of a structure which could be instantiated once per thread. The Oracle C code for the version of the module which worked, relied on there only being one, with the old naming convention. The new version of the Oracle Perl Module had a bug related to buffering n-byte charter sets (which the OS, perl, C, Oracle Client and Oracle Server all had to agree on in order to keep certain buffers from over flowing and causing a seg-fault core dump. Finding the buffer overflow bug we like trying to find a needle in a haystack - I didn't have the time to re-ramp up on C-buffer overflow kung-fu and the free and very-not-free tools which are needed to hunt down the bug. The version on CPAN was abandon-ware, but the few people who wanted to adopt it couldn't get CPAN to break control of the owner - so there were non-official forks in GIT - rebuilding from them was non-trivial. I tried rolling back the version of the Oracle Perl Module to the one that had been working but it was not incompatible with the new version of perl 5 which came with the OS. Finally I had to roll back the version of perl 5, building from source and making a second perl install on my box - then change all the code which ran perl-scripts from perl-scripts from perl-scipts (with system and qx) to make sure none of the legacy code "fell off" the new version of perl 5. Then it all worked again - the n-byte character bug was not exposed, the buffer overflow did not occur and the legacy code wen back to working, but the OS could be upgraded (a security concern). But - I had to ask "what changed" - then hunt down the root cause. Because "nothing changed" is never the root cause. Brian Fennell -Original Message- From: JohnD Blackburn Sent: Tuesday, February 18, 2020 2:57 AM To: dbi-users@perl.org Subject: RE: Perl script excessively executing statement After reviewing the log4perl output from DBIx when running this script I found the following perl module being executed: /usr/local/lib64/perl5/DBD/Oracle.pm Which contains the following subroutine: sub execute_for_fetch { my ($sth, $fetch_tuple_sub, $tuple_status) = @_; my $row_count = 0; my $err_total = 0; my $tuple_count="0E0"; my $tuple_batch_status; my $dbh = $sth->{Database}; my $batch_size =($dbh->{'ora_array_chunk_size'}||= 1000); if(defined($tuple_status)) { @$tuple_status = (); $tuple_batch_status = [ ]; } my $finished; while (1) { my @tuple_batch; for (my $i = 0; $i < $batch_size; $i++) { $finished = $fetch_tuple_sub->(); push @tuple_batch, [@{$finished || last}]; } last unless @tuple_batch; my $err_count = 0; my $res = ora_execute_array($sth, \@tuple_batch, scalar(@tuple_batch), $tuple_batch_status, $err_count ); if (defined($res)) { #no error $row_count += $res; } else { $row_count = undef; } $err_total += $err_count; $tuple_count+=@tuple_batch; push @$tuple_status, @$tuple_batch_status if defined($tuple_status); last if !$finished; } #error check here return $sth->set_err($DBI::stderr, "executing $tuple_count generated $err_total errors") if $err_total; return wantarray ? ($tuple_count, defined $row_count ? $row_count : undef) : $tuple_count; } Is that "while(1)" loop a potential contender for causing this? -Original Message----- From: JohnD Blackburn Sent: Tuesday, 18 February 2020 8:51 AM To: Steven Lembark ; dbi-users@perl.org Subject: RE: Perl script excessively executing statement The problem is not about how well the SQL runs. It runs in less than a second, and it should only be getting executed 12 times an hour. What I'm trying to do is to figure out how the SQL statement got executed 1000 times more than it should have done (which brought the db to its knees for 50 minutes with nothing be
RE: Perl script excessively executing statement
Actually, we don't know that it hasn't occurred previously, it may have happened previously, but this is the 1st time we noticed it. There has been no DB patching recently Only OS package updated on the day the issue occurred were curl and libcurl, and that was 14 hours before the incident occurred. So only change on system would be customer data. Problem is, we are only aware of the one instance when this behavior occurred. Ever since that one incident, the script has run without issue, running once every 5 minutes, and executing the SQL only once, working as it should. As suggested by Steven Lembark, I've been stepping through the script with the perl debugger. Initially this was with the modified script containing the additions for DBIx::Log4perl, but I was finding all the calls to log4pel adding excessive steps making it difficult to find the DBI and DBD::Oracle calls, so I removed the additions, and tried debugging with the original script, only to discover the perl debugger won't step into the execute call. So still no nearer to knowing why we experienced the strange behavior. And now it has returned to working normally - there was only 1 execution of the script when it misbehaved - making it difficult to know why it broke once or how to prevent it happening again in the future. Using the debugger doesn't seem to help at the moment because all I see in the debugger is it working the way it is supposed to work. All I can think of to do now, is to have debugging code in the script and hope I have enough there so that if the incident does happen again, I have enough info to understand what was happening at that time. -Original Message- From: Fennell, Brian Sent: Wednesday, 19 February 2020 2:45 AM To: JohnD Blackburn ; dbi-users@perl.org Subject: RE: Perl script excessively executing statement CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. John, The part of the story that troubles me is this: "it was working fine - nothing changed - then it broke". It is the middle part - something must have changed. If I were in your shoes I would be looking for the "what changed". I had a piece of perl / Oracle code break when we upgraded the OS. When the OS changed the version of Perl 5 changed, the version of the Oracle module had to change along with the version of perl changing, because there were changes in perl to that made certain "only once" internal variables part of a structure which could be instantiated once per thread. The Oracle C code for the version of the module which worked, relied on there only being one, with the old naming convention. The new version of the Oracle Perl Module had a bug related to buffering n-byte charter sets (which the OS, perl, C, Oracle Client and Oracle Server all had to agree on in order to keep certain buffers from over flowing and causing a seg-fault core dump. Finding the buffer overflow bug we like trying to find a needle in a haystack - I didn't have the time to re-ramp up on C-buffer overflow kung-fu and the free and very-not-free tools which are needed to hunt down the bug. The version on CPAN was abandon-ware, but the few people who wanted to adopt it couldn't get CPAN to break control of the owner - so there were non-official forks in GIT - rebuilding from them was non-trivial. I tried rolling back the version of the Oracle Perl Module to the one that had been working but it was not incompatible with the new version of perl 5 which came with the OS. Finally I had to roll back the version of perl 5, building from source and making a second perl install on my box - then change all the code which ran perl-scripts from perl-scripts from perl-scipts (with system and qx) to make sure none of the legacy code "fell off" the new version of perl 5. Then it all worked again - the n-byte character bug was not exposed, the buffer overflow did not occur and the legacy code wen back to working, but the OS could be upgraded (a security concern). But - I had to ask "what changed" - then hunt down the root cause. Because "nothing changed" is never the root cause. Brian Fennell -Original Message- From: JohnD Blackburn Sent: Tuesday, February 18, 2020 2:57 AM To: dbi-users@perl.org Subject: RE: Perl script excessively executing statement After reviewing the log4perl output from DBIx when running this script I found the following perl module being executed: /usr/local/lib64/perl5/DBD/Oracle.pm Which contains the following subroutine: sub execute_for_fetch { my ($sth, $fetch_tuple_sub, $tuple_status) = @_; my $row_count = 0; my $err_total = 0; my $tuple_count="0E0"; my $tuple_batch_status; my $dbh = $sth->