You are viewing a plain text version of this content. The canonical link for it is here.
Posted to torque-user@db.apache.org by Sam Joseph <ga...@yha.att.ne.jp> on 2003/01/15 09:14:39 UTC
Torque fails on BasePeer.doInsert() [was Re: recursive save]
Hi
Replying to my own post (which I sent to dev and should have sent here -
sorry), further investigation suggests that I do not a recursive save
problem. I have now been able to replicate the problem in my test
environment and I have determined that the save failure occurs on one
database and not on another. Both are MySQL databases, and the major
difference is the size of the table in question. In the smaller
database there are 9000 rows in the table we are trying to insert into.
In the larger database there are 30000 or so.
The difference could not be more severe. The 9000 row table receives
inserts no problem. The 30000 row table leads to a OutOfMemory error
after BasePeer.doInsert() is called.
Profiling makes it look like a succession of TorqueExceptions are being
called. I can imagine that the database is throwing an exception, but
Torque is getting in a lot of trouble handling it.
Has anyone else ever had this kind of problem?
I guess I'm going to try and check the latest version of Torque out of
CVS and see if that helps.
CHEERS> SAM
Sam Joseph wrote:
> Hi,
>
> I seem to be experiencing something that seems like a recursive save.
> At least I am getting java.lang.OutOfMemory errors when I am trying to
> perform a save() operation.
> The odd thing is that it doesn't seem to happen when I run an
> independent test, but only when I am running the code from within
> Tomcat. Well, I think in the independent mode the JVM just terminates
> itself (it's running within ant). Whereas in the Tomcat environment,
> the JVM doesn't crash out, but the memory consumption spirals up and
> up until I get OutOfMemoryErrors.
>
> Under these circumstances a recursive bit of code would fit the bill
> as culprit, however looking at my OM classes I see that after the
> save() operation in called in my Event object that extends BaseEvent
> the following functions are called:
>
> [Event] save()
> [BaseEvent] save(String dbName)
> [BaseEvent] save(DBConnection dbCon)
> [BaseEventPeer] doInsert( Criteria criteria, DBConnection dbCon )
> [BasePeer] doInsert( Criteria criteria, DBConnection dbCon )
>
> It is after calling BasePeer.doInsert() that the code hangs - and I
> get OutOfMemory errors in a Tomcat environment, and the JVM terminates
> in the ant test environment.
>
> I haven't placed debug statements with the BasePeer code yet, as that
> will require re-compiling the jar etc., but superficially there does
> not seem to be any recursion taking place in the OM classes, although
> conceivably my bugging operations are not telling the whole story.
>
> I have read the emails regarding the recursive saving problem, and
> been looking at the latest code in Torque CVS but I can't fathom what
> is actually causing the recursive problem being talked about, and
> whether it might be the same problem I am experiencing.
>
> Could anyone explain to me what the existing recursive save problem
> was? Or rather which are the methods that are called recursively and
> what triggers them to be called so, a flag or something?
Re: Torque fails on BasePeer.doInsert() [was Re: recursive save]
Posted by Sam Joseph <ga...@yha.att.ne.jp>.
And just to follow up on my previous post. Inspecting my database I
found the ID_TABLE looking like this:
+-------------+------------+------------+------------+
| ID_TABLE_ID | TABLE_NAME | NEXT_ID | QUANTITY |
+-------------+------------+------------+------------+
| 101 | KEYWORD | 9508 | 50 |
| 102 | PREDICATE | 180 | 10 |
| 103 | EVENT_TYPE | 160 | 10 |
| 104 | URI | 3990 | 15 |
| 105 | NG_USER | 3110 | 10 |
| 106 | URI_DESC | 3886 | 14 |
| 107 | URI_TRIPLE | 32657 | 136 |
| 108 | EVENT | 2147483647 | 2147483647 |
+-------------+------------+------------+------------+
and looking at the EVENT table I saw I had some very odd numbers in the
EVENT_ID columns for like 10 or 15 rows. I deleted them and then set
the ID_TABLE back to appropriate values, and now things seem to be okay.
Anybody know what the meaning, or point, of the QUANTITY column is?
CHEERS> SAM
Sam Joseph wrote:
> Hi Peter,
>
> Thanks for your mail.
>
> Peter S. Hamlen wrote:
>
>> I've had a similar problem - if I recall correctly, my base object would
>> load a related object (eg, an order object loading it's customer object)
>> which in turn have ALL the order objects for the customer, each of which
>> would then end up loading the customer again. So essentially, for every
>> order, I had a distinct customer object and all the order objects.
>>
>> I basically had a poorly defined collection which ended up creating
>
> ... ended up creating ...?
>
>> Admittedly, I didn't see any "TorqueExceptions" being called so my
>> experience could be completely worthless.
>>
> Ah, but I didn't see any Torque Exceptions either, except when I ran a
> memory profiler (your suggestion 4 below) and could see that a large
> number of TorqueException objects were being created.
>
>> Some debugging hints:
>> 1) Put a breakpoint on the executeSQL in the Mysql jdbc driver (I use
>> postgresql and use this technique a lot.) It will show you what objects
>> are getting saved.
>>
> You mean recompile the jdbc driver with some debug code in it?
>
>> 2) If you can't do 1, check out which SELECT statements are being
>> logged (ie, set Torque logging to DEBUG). This might help seeing what's
>> being loaded. (Again, assumes you run out of memory because objects are
>> being created.)
>>
> Ah, this sounds like a good idea - I've never known there was any
> logging in Torque. I guess I'll want something like this:
>
> log4j.category.org.apache.torque = DEBUG, org.apache.torque
>
> Interesting. Before my JVM memory consumption spirals out of control
> I get this log output:
>
> [junit] 2003-01-16 08:50:39,451 INFO [main] (IDBroker.java:440) -
> Forced id retrieval - no available list
> [junit] 2003-01-16 08:50:39,641 DEBUG [Finalizer]
> (BasePeer.java:1548) - Elapsed time=220 ms
> [junit] 2003-01-16 08:50:40,602 DEBUG [main] (IDBroker.java:921) -
> updateQuantity: UPDATE ID_TABLE SET QUANTITY = 2147483647 WHERE
> TABLE_NAME = 'EVENT'
> [junit] 2003-01-16 08:50:40,993 DEBUG [main] (IDBroker.java:879) -
> updateNextId: UPDATE ID_TABLE SET NEXT_ID = 4294967294 WHERE
> TABLE_NAME = 'EVENT'
>
> Hmmm.....
>
>> 3) Check your foreign key relationships to the table.
>>
> MySQL doesn't actually support foreign key relations in the version
> I'm using.
>
>> 4) Run it in a memory profiler and see how many of each object is being
>> created.
>>
> Yes - did that already. It's where I saw the TorqueExceptions being
> created. What do you use as a profiler? I've found it difficult to
> find good open source ones.
>
> CHEERS> SAM
>
>
>
> --
> To unsubscribe, e-mail:
> <ma...@jakarta.apache.org>
> For additional commands, e-mail:
> <ma...@jakarta.apache.org>
>
>
>
Re: Torque fails on BasePeer.doInsert() [was Re: recursive save]
Posted by "Peter S. Hamlen" <ph...@mail.com>.
(I see from your next email that you solved the problem - cool!)
Tackling some of your questions:
1) "ended up creating" - a better choice of words would be "ended up
instantiating".
2) Technically, I mean "recompile the driver with the DEBUG flag on" -
this allows any Java debugger to set a breakpoint on the lines in the
driver. In particular, in Postgresql, there's an "ExecuteSql" line
which has the exact SQL about to execute. I leave a disabled breakpoint
on that line in my debugger and if I ever REALLY need to know what's
going on, I reenable it. (This trick obviously only works on
open-source databases.)
3) Yes, that's the line you want for Log4J logging. Bear in mind that
it will usually log select statements but necessarily insert and update
statements (which is annoying.)
4) I have to admit that I dislike almost all the public profilers.
It's high on the list of "things I would write if I had time."
-Peter
On Wed, 2003-01-15 at 18:53, Sam Joseph wrote:
> Hi Peter,
>
> Thanks for your mail.
>
> Peter S. Hamlen wrote:
>
> >I've had a similar problem - if I recall correctly, my base object would
> >load a related object (eg, an order object loading it's customer object)
> >which in turn have ALL the order objects for the customer, each of which
> >would then end up loading the customer again. So essentially, for every
> >order, I had a distinct customer object and all the order objects.
> >
> >I basically had a poorly defined collection which ended up creating
> >
> ... ended up creating ...?
>
> >Admittedly, I didn't see any "TorqueExceptions" being called so my
> >experience could be completely worthless.
> >
> Ah, but I didn't see any Torque Exceptions either, except when I ran a
> memory profiler (your suggestion 4 below) and could see that a large
> number of TorqueException objects were being created.
>
> >Some debugging hints:
> >1) Put a breakpoint on the executeSQL in the Mysql jdbc driver (I use
> >postgresql and use this technique a lot.) It will show you what objects
> >are getting saved.
> >
> You mean recompile the jdbc driver with some debug code in it?
>
> >2) If you can't do 1, check out which SELECT statements are being
> >logged (ie, set Torque logging to DEBUG). This might help seeing what's
> >being loaded. (Again, assumes you run out of memory because objects are
> >being created.)
> >
> Ah, this sounds like a good idea - I've never known there was any
> logging in Torque. I guess I'll want something like this:
>
> log4j.category.org.apache.torque = DEBUG, org.apache.torque
>
> Interesting. Before my JVM memory consumption spirals out of control I
> get this log output:
>
> [junit] 2003-01-16 08:50:39,451 INFO [main] (IDBroker.java:440) -
> Forced id retrieval - no available list
> [junit] 2003-01-16 08:50:39,641 DEBUG [Finalizer]
> (BasePeer.java:1548) - Elapsed time=220 ms
> [junit] 2003-01-16 08:50:40,602 DEBUG [main] (IDBroker.java:921) -
> updateQuantity: UPDATE ID_TABLE SET QUANTITY = 2147483647 WHERE
> TABLE_NAME = 'EVENT'
> [junit] 2003-01-16 08:50:40,993 DEBUG [main] (IDBroker.java:879) -
> updateNextId: UPDATE ID_TABLE SET NEXT_ID = 4294967294 WHERE TABLE_NAME
> = 'EVENT'
>
> Hmmm.....
>
> >3) Check your foreign key relationships to the table.
> >
> MySQL doesn't actually support foreign key relations in the version I'm
> using.
>
> >4) Run it in a memory profiler and see how many of each object is being
> >created.
> >
> Yes - did that already. It's where I saw the TorqueExceptions being
> created. What do you use as a profiler? I've found it difficult to
> find good open source ones.
>
> CHEERS> SAM
>
>
>
> --
> To unsubscribe, e-mail: <ma...@jakarta.apache.org>
> For additional commands, e-mail: <ma...@jakarta.apache.org>
>
Re: Torque fails on BasePeer.doInsert() [was Re: recursive save]
Posted by Sam Joseph <ga...@yha.att.ne.jp>.
Hi Peter,
Thanks for your mail.
Peter S. Hamlen wrote:
>I've had a similar problem - if I recall correctly, my base object would
>load a related object (eg, an order object loading it's customer object)
>which in turn have ALL the order objects for the customer, each of which
>would then end up loading the customer again. So essentially, for every
>order, I had a distinct customer object and all the order objects.
>
>I basically had a poorly defined collection which ended up creating
>
... ended up creating ...?
>Admittedly, I didn't see any "TorqueExceptions" being called so my
>experience could be completely worthless.
>
Ah, but I didn't see any Torque Exceptions either, except when I ran a
memory profiler (your suggestion 4 below) and could see that a large
number of TorqueException objects were being created.
>Some debugging hints:
>1) Put a breakpoint on the executeSQL in the Mysql jdbc driver (I use
>postgresql and use this technique a lot.) It will show you what objects
>are getting saved.
>
You mean recompile the jdbc driver with some debug code in it?
>2) If you can't do 1, check out which SELECT statements are being
>logged (ie, set Torque logging to DEBUG). This might help seeing what's
>being loaded. (Again, assumes you run out of memory because objects are
>being created.)
>
Ah, this sounds like a good idea - I've never known there was any
logging in Torque. I guess I'll want something like this:
log4j.category.org.apache.torque = DEBUG, org.apache.torque
Interesting. Before my JVM memory consumption spirals out of control I
get this log output:
[junit] 2003-01-16 08:50:39,451 INFO [main] (IDBroker.java:440) -
Forced id retrieval - no available list
[junit] 2003-01-16 08:50:39,641 DEBUG [Finalizer]
(BasePeer.java:1548) - Elapsed time=220 ms
[junit] 2003-01-16 08:50:40,602 DEBUG [main] (IDBroker.java:921) -
updateQuantity: UPDATE ID_TABLE SET QUANTITY = 2147483647 WHERE
TABLE_NAME = 'EVENT'
[junit] 2003-01-16 08:50:40,993 DEBUG [main] (IDBroker.java:879) -
updateNextId: UPDATE ID_TABLE SET NEXT_ID = 4294967294 WHERE TABLE_NAME
= 'EVENT'
Hmmm.....
>3) Check your foreign key relationships to the table.
>
MySQL doesn't actually support foreign key relations in the version I'm
using.
>4) Run it in a memory profiler and see how many of each object is being
>created.
>
Yes - did that already. It's where I saw the TorqueExceptions being
created. What do you use as a profiler? I've found it difficult to
find good open source ones.
CHEERS> SAM
Re: Torque fails on BasePeer.doInsert() [was Re: recursive save]
Posted by "Peter S. Hamlen" <ph...@mail.com>.
Sam,
I've had a similar problem - if I recall correctly, my base object would
load a related object (eg, an order object loading it's customer object)
which in turn have ALL the order objects for the customer, each of which
would then end up loading the customer again. So essentially, for every
order, I had a distinct customer object and all the order objects.
I basically had a poorly defined collection which ended up creating
Admittedly, I didn't see any "TorqueExceptions" being called so my
experience could be completely worthless.
Some debugging hints:
1) Put a breakpoint on the executeSQL in the Mysql jdbc driver (I use
postgresql and use this technique a lot.) It will show you what objects
are getting saved.
2) If you can't do 1, check out which SELECT statements are being
logged (ie, set Torque logging to DEBUG). This might help seeing what's
being loaded. (Again, assumes you run out of memory because objects are
being created.)
3) Check your foreign key relationships to the table.
4) Run it in a memory profiler and see how many of each object is being
created.
-Peter
On Wed, 2003-01-15 at 03:14, Sam Joseph wrote:
> Hi
>
> Replying to my own post (which I sent to dev and should have sent here -
> sorry), further investigation suggests that I do not a recursive save
> problem. I have now been able to replicate the problem in my test
> environment and I have determined that the save failure occurs on one
> database and not on another. Both are MySQL databases, and the major
> difference is the size of the table in question. In the smaller
> database there are 9000 rows in the table we are trying to insert into.
> In the larger database there are 30000 or so.
>
> The difference could not be more severe. The 9000 row table receives
> inserts no problem. The 30000 row table leads to a OutOfMemory error
> after BasePeer.doInsert() is called.
>
> Profiling makes it look like a succession of TorqueExceptions are being
> called. I can imagine that the database is throwing an exception, but
> Torque is getting in a lot of trouble handling it.
>
> Has anyone else ever had this kind of problem?
>
> I guess I'm going to try and check the latest version of Torque out of
> CVS and see if that helps.
>
> CHEERS> SAM
>
> Sam Joseph wrote:
>
> > Hi,
> >
> > I seem to be experiencing something that seems like a recursive save.
> > At least I am getting java.lang.OutOfMemory errors when I am trying to
> > perform a save() operation.
> > The odd thing is that it doesn't seem to happen when I run an
> > independent test, but only when I am running the code from within
> > Tomcat. Well, I think in the independent mode the JVM just terminates
> > itself (it's running within ant). Whereas in the Tomcat environment,
> > the JVM doesn't crash out, but the memory consumption spirals up and
> > up until I get OutOfMemoryErrors.
> >
> > Under these circumstances a recursive bit of code would fit the bill
> > as culprit, however looking at my OM classes I see that after the
> > save() operation in called in my Event object that extends BaseEvent
> > the following functions are called:
> >
> > [Event] save()
> > [BaseEvent] save(String dbName)
> > [BaseEvent] save(DBConnection dbCon)
> > [BaseEventPeer] doInsert( Criteria criteria, DBConnection dbCon )
> > [BasePeer] doInsert( Criteria criteria, DBConnection dbCon )
> >
> > It is after calling BasePeer.doInsert() that the code hangs - and I
> > get OutOfMemory errors in a Tomcat environment, and the JVM terminates
> > in the ant test environment.
> >
> > I haven't placed debug statements with the BasePeer code yet, as that
> > will require re-compiling the jar etc., but superficially there does
> > not seem to be any recursion taking place in the OM classes, although
> > conceivably my bugging operations are not telling the whole story.
> >
> > I have read the emails regarding the recursive saving problem, and
> > been looking at the latest code in Torque CVS but I can't fathom what
> > is actually causing the recursive problem being talked about, and
> > whether it might be the same problem I am experiencing.
> >
> > Could anyone explain to me what the existing recursive save problem
> > was? Or rather which are the methods that are called recursively and
> > what triggers them to be called so, a flag or something?
>
>
>
>
> --
> To unsubscribe, e-mail: <ma...@jakarta.apache.org>
> For additional commands, e-mail: <ma...@jakarta.apache.org>
>