Bug #69548 for DBIx-Class: Updating a table with a CLOB field causes SQL to take 40 seconds to execute

Mon Jul 18 10:21:07 2011 gjtunley [...] gmail.com - Ticket created

Subject:	Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 15:20:54 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

Hi, I am trying to convert my code to use DBIx::Class instead of Class::DBI and have hit the following issue. I have a table defined in Oracle as follows: CREATE TABLE transaction ( transaction_id VARCHAR2(50 BYTE), time_started TIMESTAMP(6), method_called VARCHAR2(50 BYTE), input_parameters VARCHAR2(4000 BYTE), return_value CLOB, time_finished TIMESTAMP(6) ); ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY (transaction_id); ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK (method_called IS NOT NULL); ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK (time_started IS NOT NULL); My code which inserts and selects rows works fine, but when I try to update the table to populate the return_value and time_finished fields the SQL executed takes over 40 seconds to run. It only is affected when I do an update with the return_value column in the update. Here is the trace from DBIC_TRACE=1 (annotated by me with the lines beginning with #): # Connect to database and set timestamp format ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': # Check the transaction id doesn't already exist SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' # Create the transaction record BEGIN WORK INSERT INTO transaction ( input_parameters, method_called, time_started, transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" transactionid="10401-1310989565-79528" />', 'System->status', '18/07/2011 12:46:05.915440', '10401-1310989565-79528' COMMIT # ... do the actual work # Find the transaction record to stop SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' # Stop the transaction record BEGIN WORK UPDATE transaction SET return_value = ?, time_finished = ? WHERE ( ( UTL_RAW.CAST_TO_VARCHAR2(RAWTOHEX(DBMS_LOB.SUBSTR(transaction_id, 2000, 1))) = ? ) ): '<opt resultCode="200" resultString="OK" transactionid="10401-1310989565-79528" />', '18/07/2011 12:46:05.947700', '10401-1310989565-79528' COMMIT If I switch to updating the time_finished and return_value columns separately then I see: # Connect to database and set timestamp format ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': # Check the transaction id doesn't already exist SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '8750-1310996465-76528' # Create the transaction record BEGIN WORK INSERT INTO transaction ( input_parameters, method_called, time_started, transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" transactionid="8750-1310996465-76528" /> ', 'System->status', '18/07/2011 14:41:05.962670', '8750-1310996465-76528' COMMIT # ... do the actual work # Find the transaction record to stop SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '8750-1310996465-76528' # Set the time_finished - executes very quickly BEGIN WORK UPDATE transaction SET time_finished = ? WHERE ( transaction_id = ? ): '18/07/2011 14:41:06.038030', '8750-1310996465-76528' COMMIT # Set the return_value - takes long time to execute BEGIN WORK UPDATE transaction SET return_value = ? WHERE ( ( UTL_RAW.CAST_TO_VARCHAR2(RAWTOHEX(DBMS_LOB.SUBSTR(transaction_id, 2000, 1))) = ? ) ): '<opt resultCode="200" resultString="OK" transactionid="8750-1310996465-76528" />', '8750-1310996465-76528' COMMIT Looking at the WHERE clause where the SQL takes a long time, it appears to treating the transaction id as a LOB rather than the return_value column which is the actual LOB value, I am using Perl 5.14.0 DBIx::Class 0.08192 DBI 1.616 DBD::Oracle 1.28 Thanks Gareth

Mon Jul 18 10:45:46 2011 ribasushi [...] leporine.io - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 10:45:28 -0400
To:	Gareth Tunley via RT <bug-DBIx-Class [...] rt.cpan.org>
From:	Peter Rabbitson <ribasushi [...] cpan.org>

On Mon, Jul 18, 2011 at 10:21:09AM -0400, Gareth Tunley via RT wrote: Show quoted text

> Mon Jul 18 10:21:07 2011: Request 69548 was acted upon. > Transaction: Ticket created by gjtunley@gmail.com > Queue: DBIx-Class > Subject: Updating a table with a CLOB field causes SQL to take 40 seconds to execute > Broken in: (no value) > Severity: (no value) > Owner: Nobody > Requestors: gjtunley@gmail.com > Status: new > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > > Hi, > > I am trying to convert my code to use DBIx::Class instead of Class::DBI and > have hit the following issue. > > I have a table defined in Oracle as follows: > > CREATE TABLE transaction ( > transaction_id VARCHAR2(50 BYTE), > time_started TIMESTAMP(6), > method_called VARCHAR2(50 BYTE), > input_parameters VARCHAR2(4000 BYTE), > return_value CLOB, > time_finished TIMESTAMP(6) > ); > > ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY > (transaction_id); > ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK > (method_called IS NOT NULL); > ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK > (time_started IS NOT NULL); > > My code which inserts and selects rows works fine, but when I try to update > the table to populate the return_value and time_finished fields the SQL > executed takes over 40 seconds to run. > > .... > > Looking at the WHERE clause where the SQL takes a long time, it appears to > treating the transaction id as a LOB rather than the return_value column > which is the actual LOB value, > > I am using Perl 5.14.0 > DBIx::Class 0.08192 > DBI 1.616 > DBD::Oracle 1.28

Please supply your Result class definition for the transaction table. Cheers

Mon Jul 18 10:45:51 2011 The RT System itself - Status changed from 'new' to 'open'

Mon Jul 18 10:47:06 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 15:46:52 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

package TransactionDBIx::Schema::Result::Transaction; # Created by DBIx::Class::Schema::Loader # DO NOT MODIFY THE FIRST PART OF THIS FILE use strict; use warnings; use base 'DBIx::Class::Core'; =head1 NAME TransactionDBIx::Schema::Result::Transaction =cut __PACKAGE__->table("transaction"); =head1 ACCESSORS =head2 transaction_id data_type: 'varchar2' is_nullable: 0 size: 50 =head2 time_started data_type: 'timestamp' is_nullable: 0 =head2 method_called data_type: 'varchar2' is_nullable: 0 size: 50 =head2 input_parameters data_type: 'varchar2' is_nullable: 1 size: 4000 =head2 time_finished data_type: 'timestamp' is_nullable: 1 =head2 return_value data_type: 'clob' is_nullable: 1 =cut __PACKAGE__->add_columns( "transaction_id", { data_type => "varchar2", is_nullable => 0, size => 50 }, "time_started", { data_type => "timestamp", is_nullable => 0 }, "method_called", { data_type => "varchar2", is_nullable => 0, size => 50 }, "input_parameters", { data_type => "varchar2", is_nullable => 1, size => 4000 }, "time_finished", { data_type => "timestamp", is_nullable => 1 }, "return_value", { data_type => "clob", is_nullable => 1 }, ); __PACKAGE__->set_primary_key("transaction_id"); # Created by DBIx::Class::Schema::Loader v0.07010 @ 2011-07-16 23:08:00 # DO NOT MODIFY THIS OR ANYTHING ABOVE! md5sum:m7bpdyKU9UDpvSdQbhzrhw # You can replace this text with custom code or comments, and it will be preserved on regeneration 1; Gareth On 18 July 2011 15:45, Peter Rabbitson via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Mon, Jul 18, 2011 at 10:21:09AM -0400, Gareth Tunley via RT wrote:

> > Mon Jul 18 10:21:07 2011: Request 69548 was acted upon. > > Transaction: Ticket created by gjtunley@gmail.com > > Queue: DBIx-Class > > Subject: Updating a table with a CLOB field causes SQL to take 40

> seconds to execute

> > Broken in: (no value) > > Severity: (no value) > > Owner: Nobody > > Requestors: gjtunley@gmail.com > > Status: new > > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > > > > > Hi, > > > > I am trying to convert my code to use DBIx::Class instead of Class::DBI

> and

> > have hit the following issue. > > > > I have a table defined in Oracle as follows: > > > > CREATE TABLE transaction ( > > transaction_id VARCHAR2(50 BYTE), > > time_started TIMESTAMP(6), > > method_called VARCHAR2(50 BYTE), > > input_parameters VARCHAR2(4000 BYTE), > > return_value CLOB, > > time_finished TIMESTAMP(6) > > ); > > > > ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY > > (transaction_id); > > ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK > > (method_called IS NOT NULL); > > ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK > > (time_started IS NOT NULL); > > > > My code which inserts and selects rows works fine, but when I try to

> update

> > the table to populate the return_value and time_finished fields the SQL > > executed takes over 40 seconds to run. > > > > .... > > > > Looking at the WHERE clause where the SQL takes a long time, it appears

> to

> > treating the transaction id as a LOB rather than the return_value column > > which is the actual LOB value, > > > > I am using Perl 5.14.0 > > DBIx::Class 0.08192 > > DBI 1.616 > > DBD::Oracle 1.28

> > Please supply your Result class definition for the transaction table. > > Cheers > >

Mon Jul 18 11:04:53 2011 ribasushi [...] leporine.io - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 11:04:37 -0400
To:	Gareth Tunley via RT <bug-DBIx-Class [...] rt.cpan.org>
From:	Peter Rabbitson <ribasushi [...] cpan.org>

On Mon, Jul 18, 2011 at 10:21:09AM -0400, Gareth Tunley via RT wrote: Show quoted text

> Mon Jul 18 10:21:07 2011: Request 69548 was acted upon. > Transaction: Ticket created by gjtunley@gmail.com > Queue: DBIx-Class > Subject: Updating a table with a CLOB field causes SQL to take 40 seconds to execute > Broken in: (no value) > Severity: (no value) > Owner: Nobody > Requestors: gjtunley@gmail.com > Status: new > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > > Hi, > > I am trying to convert my code to use DBIx::Class instead of Class::DBI and > have hit the following issue. > > I have a table defined in Oracle as follows: > > CREATE TABLE transaction ( > transaction_id VARCHAR2(50 BYTE), > time_started TIMESTAMP(6), > method_called VARCHAR2(50 BYTE), > input_parameters VARCHAR2(4000 BYTE), > return_value CLOB, > time_finished TIMESTAMP(6) > ); > > ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY > (transaction_id); > ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK > (method_called IS NOT NULL); > ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK > (time_started IS NOT NULL); > > My code which inserts and selects rows works fine, but when I try to update > the table to populate the return_value and time_finished fields the SQL > executed takes over 40 seconds to run. > > It only is affected when I do an update with the return_value column in the > update. > > Here is the trace from DBIC_TRACE=1 (annotated by me with the lines > beginning with #): > > # Connect to database and set timestamp format > ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': > > # Check the transaction id doesn't already exist > SELECT me.transaction_id, me.time_started, me.method_called, > me.input_parameters, me.time_finished, me.return_value FROM transaction me > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > # Create the transaction record > BEGIN WORK > INSERT INTO transaction ( input_parameters, method_called, time_started, > transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" > transactionid="10401-1310989565-79528" />', 'System->status', '18/07/2011 > 12:46:05.915440', '10401-1310989565-79528' > COMMIT > > # ... do the actual work > > # Find the transaction record to stop > SELECT me.transaction_id, me.time_started, me.method_called, > me.input_parameters, me.time_finished, me.return_value FROM transaction me > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > # Stop the transaction record > BEGIN WORK > UPDATE transaction SET return_value = ?, time_finished = ? WHERE ( ( > UTL_RAW.CAST_TO_VARCHAR2(RAWTOHEX(DBMS_LOB.SUBSTR(transaction_id, 2000, 1))) > = ? ) ): '<opt resultCode="200" resultString="OK" > transactionid="10401-1310989565-79528" />', '18/07/2011 12:46:05.947700', > '10401-1310989565-79528' > COMMIT

^^ Also the exact DBIC update() call that results in this (note paraphrasing is not sufficient)

Mon Jul 18 11:21:08 2011 rkitover [...] cpan.org - Correspondence added

Hi Gareth, I'm not sure what's going on there, indeed it's doing the cast on the wrong column. I'd like to have a failing test, but that may be difficult to construct, so if you could make a small app with the DDL required in a .sql file and a small test script that demonstrates the problem, I would much appreciate it.

Mon Jul 18 12:31:01 2011 rkitover [...] cpan.org - Correspondence added

Hi Gareth, I've fixed the bug in the ora_lob_bug branch. git://git.shadowcat.co.uk/dbsrgits/DBIx-Class.git If the branch is gone that means we've since merged to master. Please try it out and let us know if it fixes your problem.

Mon Jul 18 12:45:20 2011 rkitover [...] cpan.org - Correspondence added

On Mon Jul 18 12:31:01 2011, RKITOVER wrote: Show quoted text

> Hi Gareth, > > I've fixed the bug in the ora_lob_bug branch. > > git://git.shadowcat.co.uk/dbsrgits/DBIx-Class.git > > If the branch is gone that means we've since merged to master. > > Please try it out and let us know if it fixes your problem.

Sorry, branch is called people/caelum/ora_lob_bug, not ora_lob_bug, going to do a couple minor tweaks to it but should work.

Mon Jul 18 15:24:21 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 20:24:09 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

This is the method which is doing the update: sub _stopTransaction { my $self = shift; my $transactionid = shift; my $result = shift; # Get a log4perl instance my $log = Log::Log4perl->get_logger($self->{_config}->{log4perl}->{logger}); # Get a connection to the database my $schema = $self->_getSchema($transactionid); # Find the record $transaction_record = $schema->resultset('Transaction')->find({ transaction_id => $transactionid, }); # Mark the time finished, the response being returned to the caller $result = XMLout($result); chomp($result); $transaction_record->time_finished($self->_getCurrentTime()); $transaction_record->return_value($result); my $error; # Commit the update to the database eval { $schema->txn_do(sub{ $transaction_record->update; }); } or do { $error = $@; }; # Did anything bad happen? if ($error) { # Yes - Log the fact that we have failed to commit and return the fault $log->debug('Failed to update the transaction record in the database: ' . $error); $log->info("$transactionid - FAIL: 1091 ERROR COMMITTING TRANSACTION TO DATABASE\n"); return({ faultCode => 1091, faultString => 'FAIL: 1091 ERROR COMMITTING TRANSACTION TO DATABASE', transactionid => $transactionid, }); } # Commit succeeded so log this and return $log->info("$transactionid - Transaction request marked as completed\n"); return({ resultCode => 200, resultString => 'OK', transactionid => $transactionid, }); } On 18 July 2011 16:04, Peter Rabbitson via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Mon, Jul 18, 2011 at 10:21:09AM -0400, Gareth Tunley via RT wrote:

> > Mon Jul 18 10:21:07 2011: Request 69548 was acted upon. > > Transaction: Ticket created by gjtunley@gmail.com > > Queue: DBIx-Class > > Subject: Updating a table with a CLOB field causes SQL to take 40

> seconds to execute

> > Broken in: (no value) > > Severity: (no value) > > Owner: Nobody > > Requestors: gjtunley@gmail.com > > Status: new > > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > > > > > Hi, > > > > I am trying to convert my code to use DBIx::Class instead of Class::DBI

> and

> > have hit the following issue. > > > > I have a table defined in Oracle as follows: > > > > CREATE TABLE transaction ( > > transaction_id VARCHAR2(50 BYTE), > > time_started TIMESTAMP(6), > > method_called VARCHAR2(50 BYTE), > > input_parameters VARCHAR2(4000 BYTE), > > return_value CLOB, > > time_finished TIMESTAMP(6) > > ); > > > > ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY > > (transaction_id); > > ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK > > (method_called IS NOT NULL); > > ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK > > (time_started IS NOT NULL); > > > > My code which inserts and selects rows works fine, but when I try to

> update

> > the table to populate the return_value and time_finished fields the SQL > > executed takes over 40 seconds to run. > > > > It only is affected when I do an update with the return_value column in

> the

> > update. > > > > Here is the trace from DBIC_TRACE=1 (annotated by me with the lines > > beginning with #): > > > > # Connect to database and set timestamp format > > ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': > > > > # Check the transaction id doesn't already exist > > SELECT me.transaction_id, me.time_started, me.method_called, > > me.input_parameters, me.time_finished, me.return_value FROM transaction

> me

> > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > > > # Create the transaction record > > BEGIN WORK > > INSERT INTO transaction ( input_parameters, method_called, time_started, > > transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" > > transactionid="10401-1310989565-79528" />', 'System->status', '18/07/2011 > > 12:46:05.915440', '10401-1310989565-79528' > > COMMIT > > > > # ... do the actual work > > > > # Find the transaction record to stop > > SELECT me.transaction_id, me.time_started, me.method_called, > > me.input_parameters, me.time_finished, me.return_value FROM transaction

> me

> > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > > > # Stop the transaction record > > BEGIN WORK > > UPDATE transaction SET return_value = ?, time_finished = ? WHERE ( ( > > UTL_RAW.CAST_TO_VARCHAR2(RAWTOHEX(DBMS_LOB.SUBSTR(transaction_id, 2000,

> 1)))

> > = ? ) ): '<opt resultCode="200" resultString="OK" > > transactionid="10401-1310989565-79528" />', '18/07/2011 12:46:05.947700', > > '10401-1310989565-79528' > > COMMIT

> > ^^ Also the exact DBIC update() call that results in this (note > paraphrasing > is not sufficient) > >

-- Gareth Tunley - gjtunley@gmail.com

Mon Jul 18 15:26:33 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 20:26:22 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

These are the helper methods called by the function sent in previous email: sub _getCurrentTime { my $self = shift; # Set the timestamp format - used by DateTime::Format::Oracle local $ENV{NLS_TIMESTAMP_FORMAT} = 'DD/MM/YYYY HH24:MI:SS.FF'; # Get the current time my $current_datetime = DateTime::HiRes->now(); $current_datetime->set_time_zone('Europe/London'); # Return it as a string for use with Oracle return(DateTime::Format::Oracle->format_timestamp($current_datetime)); } sub _getSchema { my $self = shift; my $transactionid = shift; my $schema; # Get a log4perl instance my $log = Log::Log4perl->get_logger($self->{_config}->{log4perl}->{logger}); # Do we have a connection to the database already if (!$self->{schema}) { # No - make a new connection $log->debug("$transactionid - Making new database connection"); $schema = TransactionDBIx::Schema->connect( $self->{_config}->{transactiondb}->{dsn}, $self->{_config}->{transactiondb}->{username}, $self->{_config}->{transactiondb}->{password}, { AutoCommit => 1, LongTruncOk => 1, LongReadLen => 524288, }, { on_connect_do => "ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF'", }, ); $self->{schema} = $schema; } else { # Yes - reuse existing connection $log->debug("$transactionid - Reusing existing database connection"); $schema = $self->{schema}; } # Return the schema object return($schema); } On 18 July 2011 16:04, Peter Rabbitson via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Mon, Jul 18, 2011 at 10:21:09AM -0400, Gareth Tunley via RT wrote:

> > Mon Jul 18 10:21:07 2011: Request 69548 was acted upon. > > Transaction: Ticket created by gjtunley@gmail.com > > Queue: DBIx-Class > > Subject: Updating a table with a CLOB field causes SQL to take 40

> seconds to execute

> > Broken in: (no value) > > Severity: (no value) > > Owner: Nobody > > Requestors: gjtunley@gmail.com > > Status: new > > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > > > > > Hi, > > > > I am trying to convert my code to use DBIx::Class instead of Class::DBI

> and

> > have hit the following issue. > > > > I have a table defined in Oracle as follows: > > > > CREATE TABLE transaction ( > > transaction_id VARCHAR2(50 BYTE), > > time_started TIMESTAMP(6), > > method_called VARCHAR2(50 BYTE), > > input_parameters VARCHAR2(4000 BYTE), > > return_value CLOB, > > time_finished TIMESTAMP(6) > > ); > > > > ALTER TABLE transaction ADD CONSTRAINT pk_transaction PRIMARY KEY > > (transaction_id); > > ALTER TABLE transaction ADD CONSTRAINT method_called_notnull CHECK > > (method_called IS NOT NULL); > > ALTER TABLE transaction ADD CONSTRAINT transaction_time_notnull CHECK > > (time_started IS NOT NULL); > > > > My code which inserts and selects rows works fine, but when I try to

> update

> > the table to populate the return_value and time_finished fields the SQL > > executed takes over 40 seconds to run. > > > > It only is affected when I do an update with the return_value column in

> the

> > update. > > > > Here is the trace from DBIC_TRACE=1 (annotated by me with the lines > > beginning with #): > > > > # Connect to database and set timestamp format > > ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': > > > > # Check the transaction id doesn't already exist > > SELECT me.transaction_id, me.time_started, me.method_called, > > me.input_parameters, me.time_finished, me.return_value FROM transaction

> me

> > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > > > # Create the transaction record > > BEGIN WORK > > INSERT INTO transaction ( input_parameters, method_called, time_started, > > transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" > > transactionid="10401-1310989565-79528" />', 'System->status', '18/07/2011 > > 12:46:05.915440', '10401-1310989565-79528' > > COMMIT > > > > # ... do the actual work > > > > # Find the transaction record to stop > > SELECT me.transaction_id, me.time_started, me.method_called, > > me.input_parameters, me.time_finished, me.return_value FROM transaction

> me

> > WHERE ( me.transaction_id = ? ) : '10401-1310989565-79528' > > > > # Stop the transaction record > > BEGIN WORK > > UPDATE transaction SET return_value = ?, time_finished = ? WHERE ( ( > > UTL_RAW.CAST_TO_VARCHAR2(RAWTOHEX(DBMS_LOB.SUBSTR(transaction_id, 2000,

> 1)))

> > = ? ) ): '<opt resultCode="200" resultString="OK" > > transactionid="10401-1310989565-79528" />', '18/07/2011 12:46:05.947700', > > '10401-1310989565-79528' > > COMMIT

> > ^^ Also the exact DBIC update() call that results in this (note > paraphrasing > is not sufficient) > >

-- Gareth Tunley - gjtunley@gmail.com

Mon Jul 18 15:27:13 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 20:27:03 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

Sure I will try to do this tomorrow morning when I'm back in the office. Garetj On 18 July 2011 16:21, Rafael Kitover via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > Hi Gareth, > > I'm not sure what's going on there, indeed it's doing the cast on the > wrong column. > > I'd like to have a failing test, but that may be difficult to > construct, so if you could make a small app with the DDL required in > a .sql file and a small test script that demonstrates the problem, I > would much appreciate it. >

-- Gareth Tunley - gjtunley@gmail.com

Mon Jul 18 15:27:46 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Mon, 18 Jul 2011 20:27:30 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

WOW that was fast - will give that a go tomorrow morning. Thanks! Gareth On 18 July 2011 17:45, Rafael Kitover via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Mon Jul 18 12:31:01 2011, RKITOVER wrote:

> > Hi Gareth, > > > > I've fixed the bug in the ora_lob_bug branch. > > > > git://git.shadowcat.co.uk/dbsrgits/DBIx-Class.git > > > > If the branch is gone that means we've since merged to master. > > > > Please try it out and let us know if it fixes your problem.

> > Sorry, branch is called people/caelum/ora_lob_bug, not ora_lob_bug, > going to do a couple minor tweaks to it but should work. >

-- Gareth Tunley - gjtunley@gmail.com

Tue Jul 19 03:24:25 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Tue, 19 Jul 2011 08:24:09 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

Patch works perfectly. Output from DBIC_TRACE: # Connect to database and set timestamp format ALTER SESSION SET NLS_TIMESTAMP_FORMAT='DD/MM/YYYY HH24:MI:SS.FF': # Check transaction doesn't already exist in database SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '4830-1311060120-99557' # Insert it into the table BEGIN WORK INSERT INTO transaction ( input_parameters, method_called, time_started, transaction_id) VALUES ( ?, ?, ?, ? ): '<opt method="status" transactionid="4830-1311060120-99557" />', 'System->status', '19/07/2011 08:22:01.325650', '4830-1311060120-99557' COMMIT # Do the work # Retrieve the transaction record SELECT me.transaction_id, me.time_started, me.method_called, me.input_parameters, me.time_finished, me.return_value FROM transaction me WHERE ( me.transaction_id = ? ) : '4830-1311060120-99557' # Update with the result and commit BEGIN WORK UPDATE transaction SET return_value = ?, time_finished = ? WHERE ( transaction_id = ? ): '<opt resultCode="200" resultString="OK" transactionid="4830-1311060120-99557" />', '19/07/2011 08:22:01.367730', '4830-1311060120-99557' COMMIT Thanks! Gareth On 18 July 2011 17:45, Rafael Kitover via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Mon Jul 18 12:31:01 2011, RKITOVER wrote:

> > Hi Gareth, > > > > I've fixed the bug in the ora_lob_bug branch. > > > > git://git.shadowcat.co.uk/dbsrgits/DBIx-Class.git > > > > If the branch is gone that means we've since merged to master. > > > > Please try it out and let us know if it fixes your problem.

> > Sorry, branch is called people/caelum/ora_lob_bug, not ora_lob_bug, > going to do a couple minor tweaks to it but should work. >

-- Gareth Tunley - gjtunley@gmail.com

Tue Jul 19 07:57:09 2011 ribasushi [...] leporine.io - Correspondence added

On Tue Jul 19 03:24:25 2011, gjtunley@gmail.com wrote: Show quoted text

> Patch works perfectly. >

Please test currnet master one more time (not the branch). We changed some of the internal logic, but nothing should make a diff. to you. This will ship as 0.08194 in about 15 minutes unless you say otherwise.

Tue Jul 19 07:59:59 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Tue, 19 Jul 2011 12:59:44 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

Checking out now On 19 July 2011 12:57, Peter Rabbitson via RT <bug-DBIx-Class@rt.cpan.org>wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > > > On Tue Jul 19 03:24:25 2011, gjtunley@gmail.com wrote:

> > Patch works perfectly. > >

> > Please test currnet master one more time (not the branch). We changed > some of the internal logic, but nothing should make a diff. to you. > This will ship as 0.08194 in about 15 minutes unless you say otherwise. >

-- Gareth Tunley - gjtunley@gmail.com

Tue Jul 19 08:05:51 2011 gjtunley [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #69548] Updating a table with a CLOB field causes SQL to take 40 seconds to execute
Date:	Tue, 19 Jul 2011 13:05:39 +0100
To:	bug-DBIx-Class [...] rt.cpan.org
From:	Gareth Tunley <gjtunley [...] gmail.com>

Still appears to be working absolutely fine. Thanks again. Gareth On 19 July 2011 12:59, Gareth Tunley <gjtunley@gmail.com> wrote: Show quoted text

> Checking out now > > > On 19 July 2011 12:57, Peter Rabbitson via RT <bug-DBIx-Class@rt.cpan.org>wrote: >

>> <URL: https://rt.cpan.org/Ticket/Display.html?id=69548 > >> >> On Tue Jul 19 03:24:25 2011, gjtunley@gmail.com wrote:

>> > Patch works perfectly. >> >

>> >> Please test currnet master one more time (not the branch). We changed >> some of the internal logic, but nothing should make a diff. to you. >> This will ship as 0.08194 in about 15 minutes unless you say otherwise. >>

> > > > -- > Gareth Tunley - gjtunley@gmail.com >

-- Gareth Tunley - gjtunley@gmail.com

Tue Jul 19 09:06:13 2011 ribasushi [...] leporine.io - Status changed from 'open' to 'patched'

Thu Jul 21 06:24:56 2011 ribasushi [...] leporine.io - Status changed from 'patched' to 'resolved'

Thu Jul 21 06:24:56 2011 ribasushi [...] leporine.io - Fixed in 0.08194 added