Home » Modeling » EMF "Technology" (Ecore Tools, EMFatic, etc) » teneo - performance problem with new impl of HibernatePersistableEList.isLoaded()
| | |
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #66233 is a reply to message #66212] |
Wed, 03 January 2007 00:54   |
 Andre Pareis
Messages: 113
Registered: July 2009 |
Senior Member |
|
|
Hi Martin,
I've turned on debug output and found that is definitely something wrong with
that code. Here is the output from the expansion of a tree node in the editor
which will expand to having just one(!) child:
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
The same list is loaded 6 or 7 times. I used the debugger and could see that it
was not initiated by some notification mechanism. Here is the stack of the first
load() call taken from the debugger:
Thread [main] (Suspended)
HibernatePersistableEList.isLoaded() line: 70
HibernatePersistableEList(PersistableEList).load() line: 176
HibernatePersistableEList(PersistableEList).delegateSize() line: 400
HibernatePersistableEList(DelegatingEList).size() line: 214
DelegatingEList$EIterator.hasNext() line: 1000
SystemItemProvider(ItemProviderAdapter).getChildren(Object) line: 339
AdapterFactoryContentProvider.getChildren(Object) line: 167
TreeViewer(AbstractTreeViewer).getRawChildren(Object) line: 1166
TreeViewer.getRawChildren(Object) line: 768
TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line: 543
AbstractTreeViewer$1.run() line: 728
BusyIndicator.showWhile(Display, Runnable) line: 67
TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
TreeViewer.createChildren(Widget) line: 892
TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line: 1251
AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
TypedListener.handleEvent(Event) line: 181
EventTable.sendEvent(Event) line: 66
Tree(Widget).sendEvent(Event) line: 928
Tree(Widget).sendEvent(int, Event, boolean) line: 952
Tree(Widget).sendEvent(int, Event) line: 937
Tree.wmNotifyChild(int, int) line: 6315
ViewForm(Control).WM_NOTIFY(int, int) line: 3794
ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
ViewForm(Control).windowProc(int, int, int, int) line: 3298
Display.windowProc(int, int, int, int) line: 4025
OS.CallWindowProcW(int, int, int, int, int) line: not available [native method]
OS.CallWindowProc(int, int, int, int, int) line: 1844
Tree.callWindowProc(int, int, int, int) line: 1321
Tree.WM_LBUTTONDOWN(int, int) line: 5206
Tree(Control).windowProc(int, int, int, int) line: 3279
Tree.windowProc(int, int, int, int) line: 4785
Display.windowProc(int, int, int, int) line: 4025
OS.DispatchMessageW(MSG) line: not available [native method]
OS.DispatchMessage(MSG) line: 1925
Display.readAndDispatch() line: 2966
Workbench.runEventLoop(Window$IExceptionHandler, Display) line: 1914
Workbench.runUI() line: 1878
Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 149
TradingEditorAdvisor$Application.run(Object) line: 99
PlatformActivator$1.run(Object) line: 78
EclipseAppLauncher.runApplication(Object) line: 92
EclipseAppLauncher.start(Object) line: 68
EclipseStarter.run(Object) line: 400
EclipseStarter.run(String[], Runnable) line: 177
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available
[native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
Method.invoke(Object, Object...) line: 585
Main.invokeFramework(String[], URL[]) line: 336
Main.basicRun(String[]) line: 280
Main.run(String[]) line: 977
Main.main(String[]) line: 952
And here is the list variable:
this HibernatePersistableEList (id=95)
delegate PersistentList (id=185)
eFeaturePath ""
estructuralFeature EReferenceImpl (id=163)
isLoaded true
isLoading false
logString "EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList"
modCount 0
owner System (id=183)
May be the reason is the isLoaded() call here:
protected void load() {
if (isLoaded())
return;
This does not test the isLoaded variable but calls isLoading() which calls
doLoad() but then without having the isLoading flag set to true? I'm really only
quickly guessing...
Thanks
Andre
Andre Pareis wrote:
> Hi Martin,
>
> Ok, this method has been called frequently I think. In particular, I
> have seen calls initiated by this line:
>
> Object[] objs = delegate.toArray(); // this forces the load
>
> (frequently) which results in System.arrayCopy() calls which I also saw
> often.
>
> I haven't tried to disable the notifications but I will do that. But I
> think it has more to do with the arrayCopy invocation because I saw
> these very often when I suspended execution in the debugger occasionally
> during the long running operation.
>
> Thanks
> Andre
>
>
>
> Martin Taal wrote:
>> Hi Andre,
>> Hmm the isLoaded does not load the objects from the db (as this has
>> already been done), the only difference is that isloaded will now
>> attach loaded objects to the resource using the method:
>> addToContentOrAttach. Can the issue be in this last method? The
>> hibernate resource now also sends out load notifications as a default,
>> did you disable that?
>>
>> gr. Martin
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> your new implementation of HibernatePersistableEList.isLoaded() gives
>>> me a huge performance drop. Before this change it took < 1 min for a
>>> particular load, afterwards it takes several hours.
>>>
>>> I don't know what has changed but I just wanted to let you know about
>>> this. I think it cascades too deep and too early now. Or may be it is
>>> now correct behavior and I have to completely change my code...
>>>
>>> Regards
>>> Andre
>>
>>
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #66278 is a reply to message #66233] |
Wed, 03 January 2007 09:06 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
Hi Andre,
Yes this is not good at all. Afaics it always calls doLoad when you call isLoaded and the load
method calls isLoaded.
I have changed the isLoaded method in HibernatePersistableEList and the load() method in
PersistableEList (in org.eclipse.emf.teneo).
Can you try this (is in cvs)?
If a build is easier to test I can make one for you so you can try that out.
gr. Martin
Andre Pareis wrote:
> Hi Martin,
>
> I've turned on debug output and found that is definitely something wrong
> with that code. Here is the output from the expansion of a tree node in
> the editor which will expand to having just one(!) child:
>
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
>
> The same list is loaded 6 or 7 times. I used the debugger and could see
> that it was not initiated by some notification mechanism. Here is the
> stack of the first load() call taken from the debugger:
>
> Thread [main] (Suspended)
> HibernatePersistableEList.isLoaded() line: 70
> HibernatePersistableEList(PersistableEList).load() line: 176
> HibernatePersistableEList(PersistableEList).delegateSize() line: 400
> HibernatePersistableEList(DelegatingEList).size() line: 214
> DelegatingEList$EIterator.hasNext() line: 1000
> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
> 339
> AdapterFactoryContentProvider.getChildren(Object) line: 167
> TreeViewer(AbstractTreeViewer).getRawChildren(Object) line: 1166
> TreeViewer.getRawChildren(Object) line: 768
> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
> TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line: 543
> AbstractTreeViewer$1.run() line: 728
> BusyIndicator.showWhile(Display, Runnable) line: 67
> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
> TreeViewer.createChildren(Widget) line: 892
> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
> 1251
> AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
> TypedListener.handleEvent(Event) line: 181
> EventTable.sendEvent(Event) line: 66
> Tree(Widget).sendEvent(Event) line: 928
> Tree(Widget).sendEvent(int, Event, boolean) line: 952
> Tree(Widget).sendEvent(int, Event) line: 937
> Tree.wmNotifyChild(int, int) line: 6315
> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
> ViewForm(Control).windowProc(int, int, int, int) line: 3298
> Display.windowProc(int, int, int, int) line: 4025
> OS.CallWindowProcW(int, int, int, int, int) line: not available
> [native method]
> OS.CallWindowProc(int, int, int, int, int) line: 1844
> Tree.callWindowProc(int, int, int, int) line: 1321
> Tree.WM_LBUTTONDOWN(int, int) line: 5206
> Tree(Control).windowProc(int, int, int, int) line: 3279
> Tree.windowProc(int, int, int, int) line: 4785
> Display.windowProc(int, int, int, int) line: 4025
> OS.DispatchMessageW(MSG) line: not available [native method]
> OS.DispatchMessage(MSG) line: 1925
> Display.readAndDispatch() line: 2966
> Workbench.runEventLoop(Window$IExceptionHandler, Display) line: 1914
> Workbench.runUI() line: 1878
> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
> PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
> 149
> TradingEditorAdvisor$Application.run(Object) line: 99
> PlatformActivator$1.run(Object) line: 78
> EclipseAppLauncher.runApplication(Object) line: 92
> EclipseAppLauncher.start(Object) line: 68
> EclipseStarter.run(Object) line: 400
> EclipseStarter.run(String[], Runnable) line: 177
> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
> available [native method]
> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
> Method.invoke(Object, Object...) line: 585
> Main.invokeFramework(String[], URL[]) line: 336
> Main.basicRun(String[]) line: 280
> Main.run(String[]) line: 977
> Main.main(String[]) line: 952
>
> And here is the list variable:
>
> this HibernatePersistableEList (id=95)
> delegate PersistentList (id=185)
> eFeaturePath ""
> estructuralFeature EReferenceImpl (id=163)
> isLoaded true
> isLoading false
> logString "EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList"
> modCount 0
> owner System (id=183)
>
> May be the reason is the isLoaded() call here:
>
> protected void load() {
> if (isLoaded())
> return;
>
> This does not test the isLoaded variable but calls isLoading() which
> calls doLoad() but then without having the isLoading flag set to true?
> I'm really only quickly guessing...
>
> Thanks
> Andre
>
>
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> Ok, this method has been called frequently I think. In particular, I
>> have seen calls initiated by this line:
>>
>> Object[] objs = delegate.toArray(); // this forces the load
>>
>> (frequently) which results in System.arrayCopy() calls which I also
>> saw often.
>>
>> I haven't tried to disable the notifications but I will do that. But I
>> think it has more to do with the arrayCopy invocation because I saw
>> these very often when I suspended execution in the debugger
>> occasionally during the long running operation.
>>
>> Thanks
>> Andre
>>
>>
>>
>> Martin Taal wrote:
>>> Hi Andre,
>>> Hmm the isLoaded does not load the objects from the db (as this has
>>> already been done), the only difference is that isloaded will now
>>> attach loaded objects to the resource using the method:
>>> addToContentOrAttach. Can the issue be in this last method? The
>>> hibernate resource now also sends out load notifications as a
>>> default, did you disable that?
>>>
>>> gr. Martin
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>> gives me a huge performance drop. Before this change it took < 1 min
>>>> for a particular load, afterwards it takes several hours.
>>>>
>>>> I don't know what has changed but I just wanted to let you know
>>>> about this. I think it cascades too deep and too early now. Or may
>>>> be it is now correct behavior and I have to completely change my
>>>> code...
>>>>
>>>> Regards
>>>> Andre
>>>
>>>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #66796 is a reply to message #66278] |
Fri, 05 January 2007 18:18 |
Andre Pareis
Messages: 113
Registered: July 2009 |
Senior Member |
|
|
Hi Martin,
this is perfectly working now, it is even much faster than my quick fix ...
which is no wonder as you know what you're doing ;)
This bug must have always been in the code. I always had huge problems when I
wanted to manipulate/browse my database on a remote server over a 3mbit link. It
was unacceptably slow. I always had to replicate the database to my local
instance first. I always blamed it on the slow link assuming that all the
traffic was necessary.
Now that this is all solved, I can work with the remote DB as if it were local.
Thanks, man! This is a huge benefit.
Thanks & Regards & Nice weekend
Andre
Martin Taal wrote:
> Hi Andre,
> Yes this is not good at all. Afaics it always calls doLoad when you call
> isLoaded and the load method calls isLoaded.
> I have changed the isLoaded method in HibernatePersistableEList and the
> load() method in PersistableEList (in org.eclipse.emf.teneo).
>
> Can you try this (is in cvs)?
>
> If a build is easier to test I can make one for you so you can try that
> out.
>
> gr. Martin
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> I've turned on debug output and found that is definitely something
>> wrong with that code. Here is the output from the expansion of a tree
>> node in the editor which will expand to having just one(!) child:
>>
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>>
>> The same list is loaded 6 or 7 times. I used the debugger and could
>> see that it was not initiated by some notification mechanism. Here is
>> the stack of the first load() call taken from the debugger:
>>
>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>> line: 70 HibernatePersistableEList(PersistableEList).load()
>> line: 176
>> HibernatePersistableEList(PersistableEList).delegateSize() line: 400
>> HibernatePersistableEList(DelegatingEList).size() line: 214
>> DelegatingEList$EIterator.hasNext() line: 1000
>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object) line:
>> 1166 TreeViewer.getRawChildren(Object) line: 768
>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
>> TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line:
>> 543 AbstractTreeViewer$1.run() line: 728
>> BusyIndicator.showWhile(Display, Runnable) line: 67
>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
>> TreeViewer.createChildren(Widget) line: 892
>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>> TypedListener.handleEvent(Event) line: 181
>> EventTable.sendEvent(Event) line: 66
>> Tree(Widget).sendEvent(Event) line: 928
>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>> Tree(Widget).sendEvent(int, Event) line: 937
>> Tree.wmNotifyChild(int, int) line: 6315
>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>> Display.windowProc(int, int, int, int) line: 4025
>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>> [native method] OS.CallWindowProc(int, int, int, int, int) line:
>> 1844 Tree.callWindowProc(int, int, int, int) line: 1321
>> Tree.WM_LBUTTONDOWN(int, int) line: 5206
>> Tree(Control).windowProc(int, int, int, int) line: 3279
>> Tree.windowProc(int, int, int, int) line: 4785
>> Display.windowProc(int, int, int, int) line: 4025
>> OS.DispatchMessageW(MSG) line: not available [native method]
>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>> Display) line: 1914 Workbench.runUI() line: 1878
>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
>> PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>> 149 TradingEditorAdvisor$Application.run(Object) line: 99
>> PlatformActivator$1.run(Object) line: 78
>> EclipseAppLauncher.runApplication(Object) line: 92
>> EclipseAppLauncher.start(Object) line: 68
>> EclipseStarter.run(Object) line: 400
>> EclipseStarter.run(String[], Runnable) line: 177
>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>> available [native method]
>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>> Method.invoke(Object, Object...) line: 585
>> Main.invokeFramework(String[], URL[]) line: 336
>> Main.basicRun(String[]) line: 280 Main.run(String[]) line: 977
>> Main.main(String[]) line: 952
>> And here is the list variable:
>>
>> this HibernatePersistableEList (id=95) delegate
>> PersistentList (id=185) eFeaturePath ""
>> estructuralFeature EReferenceImpl (id=163) isLoaded
>> true isLoading false logString "EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList" modCount 0
>> owner System (id=183)
>> May be the reason is the isLoaded() call here:
>>
>> protected void load() {
>> if (isLoaded())
>> return;
>>
>> This does not test the isLoaded variable but calls isLoading() which
>> calls doLoad() but then without having the isLoading flag set to true?
>> I'm really only quickly guessing...
>>
>> Thanks
>> Andre
>>
>>
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> Ok, this method has been called frequently I think. In particular, I
>>> have seen calls initiated by this line:
>>>
>>> Object[] objs = delegate.toArray(); // this forces the load
>>>
>>> (frequently) which results in System.arrayCopy() calls which I also
>>> saw often.
>>>
>>> I haven't tried to disable the notifications but I will do that. But
>>> I think it has more to do with the arrayCopy invocation because I saw
>>> these very often when I suspended execution in the debugger
>>> occasionally during the long running operation.
>>>
>>> Thanks
>>> Andre
>>>
>>>
>>>
>>> Martin Taal wrote:
>>>> Hi Andre,
>>>> Hmm the isLoaded does not load the objects from the db (as this has
>>>> already been done), the only difference is that isloaded will now
>>>> attach loaded objects to the resource using the method:
>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>> hibernate resource now also sends out load notifications as a
>>>> default, did you disable that?
>>>>
>>>> gr. Martin
>>>>
>>>> Andre Pareis wrote:
>>>>> Hi Martin,
>>>>>
>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>> min for a particular load, afterwards it takes several hours.
>>>>>
>>>>> I don't know what has changed but I just wanted to let you know
>>>>> about this. I think it cascades too deep and too early now. Or may
>>>>> be it is now correct behavior and I have to completely change my
>>>>> code...
>>>>>
>>>>> Regards
>>>>> Andre
>>>>
>>>>
>
>
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #66811 is a reply to message #66796] |
Fri, 05 January 2007 18:34 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
Hi Andre,
Yes, let's hope that I know what I was doing ('the proof of the pudding is in the eating' is an
english term I think ;-). I am happy that this works (better) for you.
Note that there is a problem with the current teneo build. It appears that the build scripts
sometimes 'forget' to include external jars in the build. Luckily the current Teneo builds contains
almost no other jars (only two: log4j and commons-logging). It appears that commons-logging.jar is
not being included in the org.eclipse.emf.teneo.libraries plugin. If you already have
commons-logging somewhere else (which is very likely) then this issue is probably not a problem.
gr. Martin
Andre Pareis wrote:
> Hi Martin,
>
> this is perfectly working now, it is even much faster than my quick fix
> ... which is no wonder as you know what you're doing ;)
>
> This bug must have always been in the code. I always had huge problems
> when I wanted to manipulate/browse my database on a remote server over a
> 3mbit link. It was unacceptably slow. I always had to replicate the
> database to my local instance first. I always blamed it on the slow link
> assuming that all the traffic was necessary.
>
> Now that this is all solved, I can work with the remote DB as if it were
> local. Thanks, man! This is a huge benefit.
>
> Thanks & Regards & Nice weekend
> Andre
>
>
>
>
>
>
>
> Martin Taal wrote:
>> Hi Andre,
>> Yes this is not good at all. Afaics it always calls doLoad when you
>> call isLoaded and the load method calls isLoaded.
>> I have changed the isLoaded method in HibernatePersistableEList and
>> the load() method in PersistableEList (in org.eclipse.emf.teneo).
>>
>> Can you try this (is in cvs)?
>>
>> If a build is easier to test I can make one for you so you can try
>> that out.
>>
>> gr. Martin
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> I've turned on debug output and found that is definitely something
>>> wrong with that code. Here is the output from the expansion of a tree
>>> node in the editor which will expand to having just one(!) child:
>>>
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>>
>>> The same list is loaded 6 or 7 times. I used the debugger and could
>>> see that it was not initiated by some notification mechanism. Here is
>>> the stack of the first load() call taken from the debugger:
>>>
>>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>>> line: 70 HibernatePersistableEList(PersistableEList).load()
>>> line: 176
>>> HibernatePersistableEList(PersistableEList).delegateSize() line:
>>> 400 HibernatePersistableEList(DelegatingEList).size() line:
>>> 214 DelegatingEList$EIterator.hasNext() line: 1000
>>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object) line:
>>> 1166 TreeViewer.getRawChildren(Object) line: 768
>>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line:
>>> 574 TreeViewer(AbstractTreeViewer).getSortedChildren(Object)
>>> line: 543 AbstractTreeViewer$1.run() line: 728
>>> BusyIndicator.showWhile(Display, Runnable) line: 67
>>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
>>> TreeViewer.createChildren(Widget) line: 892
>>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>>> TypedListener.handleEvent(Event) line: 181
>>> EventTable.sendEvent(Event) line: 66
>>> Tree(Widget).sendEvent(Event) line: 928
>>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>>> Tree(Widget).sendEvent(int, Event) line: 937
>>> Tree.wmNotifyChild(int, int) line: 6315
>>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>>> Display.windowProc(int, int, int, int) line: 4025
>>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>>> [native method] OS.CallWindowProc(int, int, int, int, int)
>>> line: 1844 Tree.callWindowProc(int, int, int, int) line:
>>> 1321 Tree.WM_LBUTTONDOWN(int, int) line: 5206
>>> Tree(Control).windowProc(int, int, int, int) line: 3279
>>> Tree.windowProc(int, int, int, int) line: 4785
>>> Display.windowProc(int, int, int, int) line: 4025
>>> OS.DispatchMessageW(MSG) line: not available [native method]
>>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>>> Display) line: 1914 Workbench.runUI() line: 1878
>>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>>> 419 PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor)
>>> line: 149 TradingEditorAdvisor$Application.run(Object) line:
>>> 99 PlatformActivator$1.run(Object) line: 78
>>> EclipseAppLauncher.runApplication(Object) line: 92
>>> EclipseAppLauncher.start(Object) line: 68
>>> EclipseStarter.run(Object) line: 400
>>> EclipseStarter.run(String[], Runnable) line: 177
>>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>>> available [native method]
>>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>>> Method.invoke(Object, Object...) line: 585
>>> Main.invokeFramework(String[], URL[]) line: 336
>>> Main.basicRun(String[]) line: 280 Main.run(String[]) line:
>>> 977 Main.main(String[]) line: 952 And here is the list variable:
>>>
>>> this HibernatePersistableEList (id=95) delegate
>>> PersistentList (id=185) eFeaturePath ""
>>> estructuralFeature EReferenceImpl (id=163) isLoaded
>>> true isLoading false logString "EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList" modCount 0
>>> owner System (id=183) May be the reason is the isLoaded()
>>> call here:
>>>
>>> protected void load() {
>>> if (isLoaded())
>>> return;
>>>
>>> This does not test the isLoaded variable but calls isLoading() which
>>> calls doLoad() but then without having the isLoading flag set to
>>> true? I'm really only quickly guessing...
>>>
>>> Thanks
>>> Andre
>>>
>>>
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> Ok, this method has been called frequently I think. In particular, I
>>>> have seen calls initiated by this line:
>>>>
>>>> Object[] objs = delegate.toArray(); // this forces the load
>>>>
>>>> (frequently) which results in System.arrayCopy() calls which I also
>>>> saw often.
>>>>
>>>> I haven't tried to disable the notifications but I will do that. But
>>>> I think it has more to do with the arrayCopy invocation because I
>>>> saw these very often when I suspended execution in the debugger
>>>> occasionally during the long running operation.
>>>>
>>>> Thanks
>>>> Andre
>>>>
>>>>
>>>>
>>>> Martin Taal wrote:
>>>>> Hi Andre,
>>>>> Hmm the isLoaded does not load the objects from the db (as this has
>>>>> already been done), the only difference is that isloaded will now
>>>>> attach loaded objects to the resource using the method:
>>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>>> hibernate resource now also sends out load notifications as a
>>>>> default, did you disable that?
>>>>>
>>>>> gr. Martin
>>>>>
>>>>> Andre Pareis wrote:
>>>>>> Hi Martin,
>>>>>>
>>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>>> min for a particular load, afterwards it takes several hours.
>>>>>>
>>>>>> I don't know what has changed but I just wanted to let you know
>>>>>> about this. I think it cascades too deep and too early now. Or may
>>>>>> be it is now correct behavior and I have to completely change my
>>>>>> code...
>>>>>>
>>>>>> Regards
>>>>>> Andre
>>>>>
>>>>>
>>
>>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #67223 is a reply to message #66811] |
Fri, 05 January 2007 20:52 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
The latest build should solve this issue of missing jars.
gr. Martin
Martin Taal wrote:
> Hi Andre,
> Yes, let's hope that I know what I was doing ('the proof of the pudding
> is in the eating' is an english term I think ;-). I am happy that this
> works (better) for you.
>
> Note that there is a problem with the current teneo build. It appears
> that the build scripts sometimes 'forget' to include external jars in
> the build. Luckily the current Teneo builds contains almost no other
> jars (only two: log4j and commons-logging). It appears that
> commons-logging.jar is not being included in the
> org.eclipse.emf.teneo.libraries plugin. If you already have
> commons-logging somewhere else (which is very likely) then this issue is
> probably not a problem.
>
> gr. Martin
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> this is perfectly working now, it is even much faster than my quick
>> fix ... which is no wonder as you know what you're doing ;)
>>
>> This bug must have always been in the code. I always had huge problems
>> when I wanted to manipulate/browse my database on a remote server over
>> a 3mbit link. It was unacceptably slow. I always had to replicate the
>> database to my local instance first. I always blamed it on the slow
>> link assuming that all the traffic was necessary.
>>
>> Now that this is all solved, I can work with the remote DB as if it
>> were local. Thanks, man! This is a huge benefit.
>>
>> Thanks & Regards & Nice weekend
>> Andre
>>
>>
>>
>>
>>
>>
>>
>> Martin Taal wrote:
>>> Hi Andre,
>>> Yes this is not good at all. Afaics it always calls doLoad when you
>>> call isLoaded and the load method calls isLoaded.
>>> I have changed the isLoaded method in HibernatePersistableEList and
>>> the load() method in PersistableEList (in org.eclipse.emf.teneo).
>>>
>>> Can you try this (is in cvs)?
>>>
>>> If a build is easier to test I can make one for you so you can try
>>> that out.
>>>
>>> gr. Martin
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> I've turned on debug output and found that is definitely something
>>>> wrong with that code. Here is the output from the expansion of a
>>>> tree node in the editor which will expand to having just one(!) child:
>>>>
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>>
>>>> The same list is loaded 6 or 7 times. I used the debugger and could
>>>> see that it was not initiated by some notification mechanism. Here
>>>> is the stack of the first load() call taken from the debugger:
>>>>
>>>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>>>> line: 70 HibernatePersistableEList(PersistableEList).load()
>>>> line: 176
>>>> HibernatePersistableEList(PersistableEList).delegateSize() line:
>>>> 400 HibernatePersistableEList(DelegatingEList).size() line:
>>>> 214 DelegatingEList$EIterator.hasNext() line: 1000
>>>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>>>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>>>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object)
>>>> line: 1166 TreeViewer.getRawChildren(Object) line: 768
>>>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line:
>>>> 574 TreeViewer(AbstractTreeViewer).getSortedChildren(Object)
>>>> line: 543 AbstractTreeViewer$1.run() line: 728
>>>> BusyIndicator.showWhile(Display, Runnable) line: 67
>>>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line:
>>>> 705 TreeViewer.createChildren(Widget) line: 892
>>>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>>>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>>>> TypedListener.handleEvent(Event) line: 181
>>>> EventTable.sendEvent(Event) line: 66
>>>> Tree(Widget).sendEvent(Event) line: 928
>>>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>>>> Tree(Widget).sendEvent(int, Event) line: 937
>>>> Tree.wmNotifyChild(int, int) line: 6315
>>>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>>>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>>>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>>>> Display.windowProc(int, int, int, int) line: 4025
>>>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>>>> [native method] OS.CallWindowProc(int, int, int, int, int)
>>>> line: 1844 Tree.callWindowProc(int, int, int, int) line:
>>>> 1321 Tree.WM_LBUTTONDOWN(int, int) line: 5206
>>>> Tree(Control).windowProc(int, int, int, int) line: 3279
>>>> Tree.windowProc(int, int, int, int) line: 4785
>>>> Display.windowProc(int, int, int, int) line: 4025
>>>> OS.DispatchMessageW(MSG) line: not available [native method]
>>>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>>>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>>>> Display) line: 1914 Workbench.runUI() line: 1878
>>>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>>>> 419 PlatformUI.createAndRunWorkbench(Display,
>>>> WorkbenchAdvisor) line: 149
>>>> TradingEditorAdvisor$Application.run(Object) line: 99
>>>> PlatformActivator$1.run(Object) line: 78
>>>> EclipseAppLauncher.runApplication(Object) line: 92
>>>> EclipseAppLauncher.start(Object) line: 68
>>>> EclipseStarter.run(Object) line: 400
>>>> EclipseStarter.run(String[], Runnable) line: 177
>>>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>>>> available [native method]
>>>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>>>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>>>> Method.invoke(Object, Object...) line: 585
>>>> Main.invokeFramework(String[], URL[]) line: 336
>>>> Main.basicRun(String[]) line: 280 Main.run(String[]) line:
>>>> 977 Main.main(String[]) line: 952 And here is the list variable:
>>>>
>>>> this HibernatePersistableEList (id=95) delegate
>>>> PersistentList (id=185) eFeaturePath ""
>>>> estructuralFeature EReferenceImpl (id=163) isLoaded
>>>> true isLoading false logString "EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList" modCount 0
>>>> owner System (id=183) May be the reason is the isLoaded()
>>>> call here:
>>>>
>>>> protected void load() {
>>>> if (isLoaded())
>>>> return;
>>>>
>>>> This does not test the isLoaded variable but calls isLoading() which
>>>> calls doLoad() but then without having the isLoading flag set to
>>>> true? I'm really only quickly guessing...
>>>>
>>>> Thanks
>>>> Andre
>>>>
>>>>
>>>>
>>>> Andre Pareis wrote:
>>>>> Hi Martin,
>>>>>
>>>>> Ok, this method has been called frequently I think. In particular,
>>>>> I have seen calls initiated by this line:
>>>>>
>>>>> Object[] objs = delegate.toArray(); // this forces the load
>>>>>
>>>>> (frequently) which results in System.arrayCopy() calls which I also
>>>>> saw often.
>>>>>
>>>>> I haven't tried to disable the notifications but I will do that.
>>>>> But I think it has more to do with the arrayCopy invocation because
>>>>> I saw these very often when I suspended execution in the debugger
>>>>> occasionally during the long running operation.
>>>>>
>>>>> Thanks
>>>>> Andre
>>>>>
>>>>>
>>>>>
>>>>> Martin Taal wrote:
>>>>>> Hi Andre,
>>>>>> Hmm the isLoaded does not load the objects from the db (as this
>>>>>> has already been done), the only difference is that isloaded will
>>>>>> now attach loaded objects to the resource using the method:
>>>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>>>> hibernate resource now also sends out load notifications as a
>>>>>> default, did you disable that?
>>>>>>
>>>>>> gr. Martin
>>>>>>
>>>>>> Andre Pareis wrote:
>>>>>>> Hi Martin,
>>>>>>>
>>>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>>>> min for a particular load, afterwards it takes several hours.
>>>>>>>
>>>>>>> I don't know what has changed but I just wanted to let you know
>>>>>>> about this. I think it cascades too deep and too early now. Or
>>>>>>> may be it is now correct behavior and I have to completely change
>>>>>>> my code...
>>>>>>>
>>>>>>> Regards
>>>>>>> Andre
>>>>>>
>>>>>>
>>>
>>>
>
>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
| | |
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #600508 is a reply to message #66212] |
Wed, 03 January 2007 00:54 |
Andre Pareis
Messages: 113
Registered: July 2009 |
Senior Member |
|
|
Hi Martin,
I've turned on debug output and found that is definitely something wrong with
that code. Here is the output from the expansion of a tree node in the editor
which will expand to having just one(!) child:
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Persistentlist already initialized, probably eagerly loaded: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Started loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Reconnecting session to read a lazy collection, elist: EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Loaded 1 from backend store for EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
2007-01-03 01:42:41,297 [main] DEBUG
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList -
Finished loading elist EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList
The same list is loaded 6 or 7 times. I used the debugger and could see that it
was not initiated by some notification mechanism. Here is the stack of the first
load() call taken from the debugger:
Thread [main] (Suspended)
HibernatePersistableEList.isLoaded() line: 70
HibernatePersistableEList(PersistableEList).load() line: 176
HibernatePersistableEList(PersistableEList).delegateSize() line: 400
HibernatePersistableEList(DelegatingEList).size() line: 214
DelegatingEList$EIterator.hasNext() line: 1000
SystemItemProvider(ItemProviderAdapter).getChildren(Object) line: 339
AdapterFactoryContentProvider.getChildren(Object) line: 167
TreeViewer(AbstractTreeViewer).getRawChildren(Object) line: 1166
TreeViewer.getRawChildren(Object) line: 768
TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line: 543
AbstractTreeViewer$1.run() line: 728
BusyIndicator.showWhile(Display, Runnable) line: 67
TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
TreeViewer.createChildren(Widget) line: 892
TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line: 1251
AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
TypedListener.handleEvent(Event) line: 181
EventTable.sendEvent(Event) line: 66
Tree(Widget).sendEvent(Event) line: 928
Tree(Widget).sendEvent(int, Event, boolean) line: 952
Tree(Widget).sendEvent(int, Event) line: 937
Tree.wmNotifyChild(int, int) line: 6315
ViewForm(Control).WM_NOTIFY(int, int) line: 3794
ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
ViewForm(Control).windowProc(int, int, int, int) line: 3298
Display.windowProc(int, int, int, int) line: 4025
OS.CallWindowProcW(int, int, int, int, int) line: not available [native method]
OS.CallWindowProc(int, int, int, int, int) line: 1844
Tree.callWindowProc(int, int, int, int) line: 1321
Tree.WM_LBUTTONDOWN(int, int) line: 5206
Tree(Control).windowProc(int, int, int, int) line: 3279
Tree.windowProc(int, int, int, int) line: 4785
Display.windowProc(int, int, int, int) line: 4025
OS.DispatchMessageW(MSG) line: not available [native method]
OS.DispatchMessage(MSG) line: 1925
Display.readAndDispatch() line: 2966
Workbench.runEventLoop(Window$IExceptionHandler, Display) line: 1914
Workbench.runUI() line: 1878
Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 149
TradingEditorAdvisor$Application.run(Object) line: 99
PlatformActivator$1.run(Object) line: 78
EclipseAppLauncher.runApplication(Object) line: 92
EclipseAppLauncher.start(Object) line: 68
EclipseStarter.run(Object) line: 400
EclipseStarter.run(String[], Runnable) line: 177
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available
[native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
Method.invoke(Object, Object...) line: 585
Main.invokeFramework(String[], URL[]) line: 336
Main.basicRun(String[]) line: 280
Main.run(String[]) line: 977
Main.main(String[]) line: 952
And here is the list variable:
this HibernatePersistableEList (id=95)
delegate PersistentList (id=185)
eFeaturePath ""
estructuralFeature EReferenceImpl (id=163)
isLoaded true
isLoading false
logString "EList of type:
org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList of
member clients owned by com.pareis.trading.System with delegate list
org.hibernate.collection.PersistentList"
modCount 0
owner System (id=183)
May be the reason is the isLoaded() call here:
protected void load() {
if (isLoaded())
return;
This does not test the isLoaded variable but calls isLoading() which calls
doLoad() but then without having the isLoading flag set to true? I'm really only
quickly guessing...
Thanks
Andre
Andre Pareis wrote:
> Hi Martin,
>
> Ok, this method has been called frequently I think. In particular, I
> have seen calls initiated by this line:
>
> Object[] objs = delegate.toArray(); // this forces the load
>
> (frequently) which results in System.arrayCopy() calls which I also saw
> often.
>
> I haven't tried to disable the notifications but I will do that. But I
> think it has more to do with the arrayCopy invocation because I saw
> these very often when I suspended execution in the debugger occasionally
> during the long running operation.
>
> Thanks
> Andre
>
>
>
> Martin Taal wrote:
>> Hi Andre,
>> Hmm the isLoaded does not load the objects from the db (as this has
>> already been done), the only difference is that isloaded will now
>> attach loaded objects to the resource using the method:
>> addToContentOrAttach. Can the issue be in this last method? The
>> hibernate resource now also sends out load notifications as a default,
>> did you disable that?
>>
>> gr. Martin
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> your new implementation of HibernatePersistableEList.isLoaded() gives
>>> me a huge performance drop. Before this change it took < 1 min for a
>>> particular load, afterwards it takes several hours.
>>>
>>> I don't know what has changed but I just wanted to let you know about
>>> this. I think it cascades too deep and too early now. Or may be it is
>>> now correct behavior and I have to completely change my code...
>>>
>>> Regards
>>> Andre
>>
>>
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #600529 is a reply to message #66233] |
Wed, 03 January 2007 09:06 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
Hi Andre,
Yes this is not good at all. Afaics it always calls doLoad when you call isLoaded and the load
method calls isLoaded.
I have changed the isLoaded method in HibernatePersistableEList and the load() method in
PersistableEList (in org.eclipse.emf.teneo).
Can you try this (is in cvs)?
If a build is easier to test I can make one for you so you can try that out.
gr. Martin
Andre Pareis wrote:
> Hi Martin,
>
> I've turned on debug output and found that is definitely something wrong
> with that code. Here is the output from the expansion of a tree node in
> the editor which will expand to having just one(!) child:
>
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Persistentlist already initialized, probably eagerly loaded: EList of
> type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Started loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Reconnecting session to read a lazy collection, elist: EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Loaded 1 from backend store for EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
> 2007-01-03 01:42:41,297 [main] DEBUG
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> - Finished loading elist EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList
>
> The same list is loaded 6 or 7 times. I used the debugger and could see
> that it was not initiated by some notification mechanism. Here is the
> stack of the first load() call taken from the debugger:
>
> Thread [main] (Suspended)
> HibernatePersistableEList.isLoaded() line: 70
> HibernatePersistableEList(PersistableEList).load() line: 176
> HibernatePersistableEList(PersistableEList).delegateSize() line: 400
> HibernatePersistableEList(DelegatingEList).size() line: 214
> DelegatingEList$EIterator.hasNext() line: 1000
> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
> 339
> AdapterFactoryContentProvider.getChildren(Object) line: 167
> TreeViewer(AbstractTreeViewer).getRawChildren(Object) line: 1166
> TreeViewer.getRawChildren(Object) line: 768
> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
> TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line: 543
> AbstractTreeViewer$1.run() line: 728
> BusyIndicator.showWhile(Display, Runnable) line: 67
> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
> TreeViewer.createChildren(Widget) line: 892
> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
> 1251
> AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
> TypedListener.handleEvent(Event) line: 181
> EventTable.sendEvent(Event) line: 66
> Tree(Widget).sendEvent(Event) line: 928
> Tree(Widget).sendEvent(int, Event, boolean) line: 952
> Tree(Widget).sendEvent(int, Event) line: 937
> Tree.wmNotifyChild(int, int) line: 6315
> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
> ViewForm(Control).windowProc(int, int, int, int) line: 3298
> Display.windowProc(int, int, int, int) line: 4025
> OS.CallWindowProcW(int, int, int, int, int) line: not available
> [native method]
> OS.CallWindowProc(int, int, int, int, int) line: 1844
> Tree.callWindowProc(int, int, int, int) line: 1321
> Tree.WM_LBUTTONDOWN(int, int) line: 5206
> Tree(Control).windowProc(int, int, int, int) line: 3279
> Tree.windowProc(int, int, int, int) line: 4785
> Display.windowProc(int, int, int, int) line: 4025
> OS.DispatchMessageW(MSG) line: not available [native method]
> OS.DispatchMessage(MSG) line: 1925
> Display.readAndDispatch() line: 2966
> Workbench.runEventLoop(Window$IExceptionHandler, Display) line: 1914
> Workbench.runUI() line: 1878
> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
> PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
> 149
> TradingEditorAdvisor$Application.run(Object) line: 99
> PlatformActivator$1.run(Object) line: 78
> EclipseAppLauncher.runApplication(Object) line: 92
> EclipseAppLauncher.start(Object) line: 68
> EclipseStarter.run(Object) line: 400
> EclipseStarter.run(String[], Runnable) line: 177
> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
> available [native method]
> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
> Method.invoke(Object, Object...) line: 585
> Main.invokeFramework(String[], URL[]) line: 336
> Main.basicRun(String[]) line: 280
> Main.run(String[]) line: 977
> Main.main(String[]) line: 952
>
> And here is the list variable:
>
> this HibernatePersistableEList (id=95)
> delegate PersistentList (id=185)
> eFeaturePath ""
> estructuralFeature EReferenceImpl (id=163)
> isLoaded true
> isLoading false
> logString "EList of type:
> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
> of member clients owned by com.pareis.trading.System with delegate list
> org.hibernate.collection.PersistentList"
> modCount 0
> owner System (id=183)
>
> May be the reason is the isLoaded() call here:
>
> protected void load() {
> if (isLoaded())
> return;
>
> This does not test the isLoaded variable but calls isLoading() which
> calls doLoad() but then without having the isLoading flag set to true?
> I'm really only quickly guessing...
>
> Thanks
> Andre
>
>
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> Ok, this method has been called frequently I think. In particular, I
>> have seen calls initiated by this line:
>>
>> Object[] objs = delegate.toArray(); // this forces the load
>>
>> (frequently) which results in System.arrayCopy() calls which I also
>> saw often.
>>
>> I haven't tried to disable the notifications but I will do that. But I
>> think it has more to do with the arrayCopy invocation because I saw
>> these very often when I suspended execution in the debugger
>> occasionally during the long running operation.
>>
>> Thanks
>> Andre
>>
>>
>>
>> Martin Taal wrote:
>>> Hi Andre,
>>> Hmm the isLoaded does not load the objects from the db (as this has
>>> already been done), the only difference is that isloaded will now
>>> attach loaded objects to the resource using the method:
>>> addToContentOrAttach. Can the issue be in this last method? The
>>> hibernate resource now also sends out load notifications as a
>>> default, did you disable that?
>>>
>>> gr. Martin
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>> gives me a huge performance drop. Before this change it took < 1 min
>>>> for a particular load, afterwards it takes several hours.
>>>>
>>>> I don't know what has changed but I just wanted to let you know
>>>> about this. I think it cascades too deep and too early now. Or may
>>>> be it is now correct behavior and I have to completely change my
>>>> code...
>>>>
>>>> Regards
>>>> Andre
>>>
>>>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #600807 is a reply to message #66278] |
Fri, 05 January 2007 18:18 |
Andre Pareis
Messages: 113
Registered: July 2009 |
Senior Member |
|
|
Hi Martin,
this is perfectly working now, it is even much faster than my quick fix ...
which is no wonder as you know what you're doing ;)
This bug must have always been in the code. I always had huge problems when I
wanted to manipulate/browse my database on a remote server over a 3mbit link. It
was unacceptably slow. I always had to replicate the database to my local
instance first. I always blamed it on the slow link assuming that all the
traffic was necessary.
Now that this is all solved, I can work with the remote DB as if it were local.
Thanks, man! This is a huge benefit.
Thanks & Regards & Nice weekend
Andre
Martin Taal wrote:
> Hi Andre,
> Yes this is not good at all. Afaics it always calls doLoad when you call
> isLoaded and the load method calls isLoaded.
> I have changed the isLoaded method in HibernatePersistableEList and the
> load() method in PersistableEList (in org.eclipse.emf.teneo).
>
> Can you try this (is in cvs)?
>
> If a build is easier to test I can make one for you so you can try that
> out.
>
> gr. Martin
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> I've turned on debug output and found that is definitely something
>> wrong with that code. Here is the output from the expansion of a tree
>> node in the editor which will expand to having just one(!) child:
>>
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Persistentlist already initialized, probably eagerly loaded: EList
>> of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Started loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Reconnecting session to read a lazy collection, elist: EList of
>> type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Loaded 1 from backend store for EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>> 2007-01-03 01:42:41,297 [main] DEBUG
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> - Finished loading elist EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList
>>
>> The same list is loaded 6 or 7 times. I used the debugger and could
>> see that it was not initiated by some notification mechanism. Here is
>> the stack of the first load() call taken from the debugger:
>>
>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>> line: 70 HibernatePersistableEList(PersistableEList).load()
>> line: 176
>> HibernatePersistableEList(PersistableEList).delegateSize() line: 400
>> HibernatePersistableEList(DelegatingEList).size() line: 214
>> DelegatingEList$EIterator.hasNext() line: 1000
>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object) line:
>> 1166 TreeViewer.getRawChildren(Object) line: 768
>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line: 574
>> TreeViewer(AbstractTreeViewer).getSortedChildren(Object) line:
>> 543 AbstractTreeViewer$1.run() line: 728
>> BusyIndicator.showWhile(Display, Runnable) line: 67
>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
>> TreeViewer.createChildren(Widget) line: 892
>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>> TypedListener.handleEvent(Event) line: 181
>> EventTable.sendEvent(Event) line: 66
>> Tree(Widget).sendEvent(Event) line: 928
>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>> Tree(Widget).sendEvent(int, Event) line: 937
>> Tree.wmNotifyChild(int, int) line: 6315
>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>> Display.windowProc(int, int, int, int) line: 4025
>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>> [native method] OS.CallWindowProc(int, int, int, int, int) line:
>> 1844 Tree.callWindowProc(int, int, int, int) line: 1321
>> Tree.WM_LBUTTONDOWN(int, int) line: 5206
>> Tree(Control).windowProc(int, int, int, int) line: 3279
>> Tree.windowProc(int, int, int, int) line: 4785
>> Display.windowProc(int, int, int, int) line: 4025
>> OS.DispatchMessageW(MSG) line: not available [native method]
>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>> Display) line: 1914 Workbench.runUI() line: 1878
>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 419
>> PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>> 149 TradingEditorAdvisor$Application.run(Object) line: 99
>> PlatformActivator$1.run(Object) line: 78
>> EclipseAppLauncher.runApplication(Object) line: 92
>> EclipseAppLauncher.start(Object) line: 68
>> EclipseStarter.run(Object) line: 400
>> EclipseStarter.run(String[], Runnable) line: 177
>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>> available [native method]
>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>> Method.invoke(Object, Object...) line: 585
>> Main.invokeFramework(String[], URL[]) line: 336
>> Main.basicRun(String[]) line: 280 Main.run(String[]) line: 977
>> Main.main(String[]) line: 952
>> And here is the list variable:
>>
>> this HibernatePersistableEList (id=95) delegate
>> PersistentList (id=185) eFeaturePath ""
>> estructuralFeature EReferenceImpl (id=163) isLoaded
>> true isLoading false logString "EList of type:
>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>> of member clients owned by com.pareis.trading.System with delegate
>> list org.hibernate.collection.PersistentList" modCount 0
>> owner System (id=183)
>> May be the reason is the isLoaded() call here:
>>
>> protected void load() {
>> if (isLoaded())
>> return;
>>
>> This does not test the isLoaded variable but calls isLoading() which
>> calls doLoad() but then without having the isLoading flag set to true?
>> I'm really only quickly guessing...
>>
>> Thanks
>> Andre
>>
>>
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> Ok, this method has been called frequently I think. In particular, I
>>> have seen calls initiated by this line:
>>>
>>> Object[] objs = delegate.toArray(); // this forces the load
>>>
>>> (frequently) which results in System.arrayCopy() calls which I also
>>> saw often.
>>>
>>> I haven't tried to disable the notifications but I will do that. But
>>> I think it has more to do with the arrayCopy invocation because I saw
>>> these very often when I suspended execution in the debugger
>>> occasionally during the long running operation.
>>>
>>> Thanks
>>> Andre
>>>
>>>
>>>
>>> Martin Taal wrote:
>>>> Hi Andre,
>>>> Hmm the isLoaded does not load the objects from the db (as this has
>>>> already been done), the only difference is that isloaded will now
>>>> attach loaded objects to the resource using the method:
>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>> hibernate resource now also sends out load notifications as a
>>>> default, did you disable that?
>>>>
>>>> gr. Martin
>>>>
>>>> Andre Pareis wrote:
>>>>> Hi Martin,
>>>>>
>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>> min for a particular load, afterwards it takes several hours.
>>>>>
>>>>> I don't know what has changed but I just wanted to let you know
>>>>> about this. I think it cascades too deep and too early now. Or may
>>>>> be it is now correct behavior and I have to completely change my
>>>>> code...
>>>>>
>>>>> Regards
>>>>> Andre
>>>>
>>>>
>
>
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #600810 is a reply to message #66796] |
Fri, 05 January 2007 18:34 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
Hi Andre,
Yes, let's hope that I know what I was doing ('the proof of the pudding is in the eating' is an
english term I think ;-). I am happy that this works (better) for you.
Note that there is a problem with the current teneo build. It appears that the build scripts
sometimes 'forget' to include external jars in the build. Luckily the current Teneo builds contains
almost no other jars (only two: log4j and commons-logging). It appears that commons-logging.jar is
not being included in the org.eclipse.emf.teneo.libraries plugin. If you already have
commons-logging somewhere else (which is very likely) then this issue is probably not a problem.
gr. Martin
Andre Pareis wrote:
> Hi Martin,
>
> this is perfectly working now, it is even much faster than my quick fix
> ... which is no wonder as you know what you're doing ;)
>
> This bug must have always been in the code. I always had huge problems
> when I wanted to manipulate/browse my database on a remote server over a
> 3mbit link. It was unacceptably slow. I always had to replicate the
> database to my local instance first. I always blamed it on the slow link
> assuming that all the traffic was necessary.
>
> Now that this is all solved, I can work with the remote DB as if it were
> local. Thanks, man! This is a huge benefit.
>
> Thanks & Regards & Nice weekend
> Andre
>
>
>
>
>
>
>
> Martin Taal wrote:
>> Hi Andre,
>> Yes this is not good at all. Afaics it always calls doLoad when you
>> call isLoaded and the load method calls isLoaded.
>> I have changed the isLoaded method in HibernatePersistableEList and
>> the load() method in PersistableEList (in org.eclipse.emf.teneo).
>>
>> Can you try this (is in cvs)?
>>
>> If a build is easier to test I can make one for you so you can try
>> that out.
>>
>> gr. Martin
>>
>> Andre Pareis wrote:
>>> Hi Martin,
>>>
>>> I've turned on debug output and found that is definitely something
>>> wrong with that code. Here is the output from the expansion of a tree
>>> node in the editor which will expand to having just one(!) child:
>>>
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>> of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Started loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Reconnecting session to read a lazy collection, elist: EList of
>>> type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Loaded 1 from backend store for EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> - Finished loading elist EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList
>>>
>>> The same list is loaded 6 or 7 times. I used the debugger and could
>>> see that it was not initiated by some notification mechanism. Here is
>>> the stack of the first load() call taken from the debugger:
>>>
>>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>>> line: 70 HibernatePersistableEList(PersistableEList).load()
>>> line: 176
>>> HibernatePersistableEList(PersistableEList).delegateSize() line:
>>> 400 HibernatePersistableEList(DelegatingEList).size() line:
>>> 214 DelegatingEList$EIterator.hasNext() line: 1000
>>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object) line:
>>> 1166 TreeViewer.getRawChildren(Object) line: 768
>>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line:
>>> 574 TreeViewer(AbstractTreeViewer).getSortedChildren(Object)
>>> line: 543 AbstractTreeViewer$1.run() line: 728
>>> BusyIndicator.showWhile(Display, Runnable) line: 67
>>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line: 705
>>> TreeViewer.createChildren(Widget) line: 892
>>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>>> TypedListener.handleEvent(Event) line: 181
>>> EventTable.sendEvent(Event) line: 66
>>> Tree(Widget).sendEvent(Event) line: 928
>>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>>> Tree(Widget).sendEvent(int, Event) line: 937
>>> Tree.wmNotifyChild(int, int) line: 6315
>>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>>> Display.windowProc(int, int, int, int) line: 4025
>>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>>> [native method] OS.CallWindowProc(int, int, int, int, int)
>>> line: 1844 Tree.callWindowProc(int, int, int, int) line:
>>> 1321 Tree.WM_LBUTTONDOWN(int, int) line: 5206
>>> Tree(Control).windowProc(int, int, int, int) line: 3279
>>> Tree.windowProc(int, int, int, int) line: 4785
>>> Display.windowProc(int, int, int, int) line: 4025
>>> OS.DispatchMessageW(MSG) line: not available [native method]
>>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>>> Display) line: 1914 Workbench.runUI() line: 1878
>>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>>> 419 PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor)
>>> line: 149 TradingEditorAdvisor$Application.run(Object) line:
>>> 99 PlatformActivator$1.run(Object) line: 78
>>> EclipseAppLauncher.runApplication(Object) line: 92
>>> EclipseAppLauncher.start(Object) line: 68
>>> EclipseStarter.run(Object) line: 400
>>> EclipseStarter.run(String[], Runnable) line: 177
>>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>>> available [native method]
>>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>>> Method.invoke(Object, Object...) line: 585
>>> Main.invokeFramework(String[], URL[]) line: 336
>>> Main.basicRun(String[]) line: 280 Main.run(String[]) line:
>>> 977 Main.main(String[]) line: 952 And here is the list variable:
>>>
>>> this HibernatePersistableEList (id=95) delegate
>>> PersistentList (id=185) eFeaturePath ""
>>> estructuralFeature EReferenceImpl (id=163) isLoaded
>>> true isLoading false logString "EList of type:
>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>> of member clients owned by com.pareis.trading.System with delegate
>>> list org.hibernate.collection.PersistentList" modCount 0
>>> owner System (id=183) May be the reason is the isLoaded()
>>> call here:
>>>
>>> protected void load() {
>>> if (isLoaded())
>>> return;
>>>
>>> This does not test the isLoaded variable but calls isLoading() which
>>> calls doLoad() but then without having the isLoading flag set to
>>> true? I'm really only quickly guessing...
>>>
>>> Thanks
>>> Andre
>>>
>>>
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> Ok, this method has been called frequently I think. In particular, I
>>>> have seen calls initiated by this line:
>>>>
>>>> Object[] objs = delegate.toArray(); // this forces the load
>>>>
>>>> (frequently) which results in System.arrayCopy() calls which I also
>>>> saw often.
>>>>
>>>> I haven't tried to disable the notifications but I will do that. But
>>>> I think it has more to do with the arrayCopy invocation because I
>>>> saw these very often when I suspended execution in the debugger
>>>> occasionally during the long running operation.
>>>>
>>>> Thanks
>>>> Andre
>>>>
>>>>
>>>>
>>>> Martin Taal wrote:
>>>>> Hi Andre,
>>>>> Hmm the isLoaded does not load the objects from the db (as this has
>>>>> already been done), the only difference is that isloaded will now
>>>>> attach loaded objects to the resource using the method:
>>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>>> hibernate resource now also sends out load notifications as a
>>>>> default, did you disable that?
>>>>>
>>>>> gr. Martin
>>>>>
>>>>> Andre Pareis wrote:
>>>>>> Hi Martin,
>>>>>>
>>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>>> min for a particular load, afterwards it takes several hours.
>>>>>>
>>>>>> I don't know what has changed but I just wanted to let you know
>>>>>> about this. I think it cascades too deep and too early now. Or may
>>>>>> be it is now correct behavior and I have to completely change my
>>>>>> code...
>>>>>>
>>>>>> Regards
>>>>>> Andre
>>>>>
>>>>>
>>
>>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
|
| Re: teneo - performance problem with new impl of HibernatePersistableEList.isLoaded() [message #600833 is a reply to message #66811] |
Fri, 05 January 2007 20:52 |
Martin Taal
Messages: 5468
Registered: July 2009 |
Senior Member |
|
|
The latest build should solve this issue of missing jars.
gr. Martin
Martin Taal wrote:
> Hi Andre,
> Yes, let's hope that I know what I was doing ('the proof of the pudding
> is in the eating' is an english term I think ;-). I am happy that this
> works (better) for you.
>
> Note that there is a problem with the current teneo build. It appears
> that the build scripts sometimes 'forget' to include external jars in
> the build. Luckily the current Teneo builds contains almost no other
> jars (only two: log4j and commons-logging). It appears that
> commons-logging.jar is not being included in the
> org.eclipse.emf.teneo.libraries plugin. If you already have
> commons-logging somewhere else (which is very likely) then this issue is
> probably not a problem.
>
> gr. Martin
>
> Andre Pareis wrote:
>> Hi Martin,
>>
>> this is perfectly working now, it is even much faster than my quick
>> fix ... which is no wonder as you know what you're doing ;)
>>
>> This bug must have always been in the code. I always had huge problems
>> when I wanted to manipulate/browse my database on a remote server over
>> a 3mbit link. It was unacceptably slow. I always had to replicate the
>> database to my local instance first. I always blamed it on the slow
>> link assuming that all the traffic was necessary.
>>
>> Now that this is all solved, I can work with the remote DB as if it
>> were local. Thanks, man! This is a huge benefit.
>>
>> Thanks & Regards & Nice weekend
>> Andre
>>
>>
>>
>>
>>
>>
>>
>> Martin Taal wrote:
>>> Hi Andre,
>>> Yes this is not good at all. Afaics it always calls doLoad when you
>>> call isLoaded and the load method calls isLoaded.
>>> I have changed the isLoaded method in HibernatePersistableEList and
>>> the load() method in PersistableEList (in org.eclipse.emf.teneo).
>>>
>>> Can you try this (is in cvs)?
>>>
>>> If a build is easier to test I can make one for you so you can try
>>> that out.
>>>
>>> gr. Martin
>>>
>>> Andre Pareis wrote:
>>>> Hi Martin,
>>>>
>>>> I've turned on debug output and found that is definitely something
>>>> wrong with that code. Here is the output from the expansion of a
>>>> tree node in the editor which will expand to having just one(!) child:
>>>>
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Persistentlist already initialized, probably eagerly loaded: EList
>>>> of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Started loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Reconnecting session to read a lazy collection, elist: EList of
>>>> type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Loaded 1 from backend store for EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>> 2007-01-03 01:42:41,297 [main] DEBUG
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> - Finished loading elist EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList
>>>>
>>>> The same list is loaded 6 or 7 times. I used the debugger and could
>>>> see that it was not initiated by some notification mechanism. Here
>>>> is the stack of the first load() call taken from the debugger:
>>>>
>>>> Thread [main] (Suspended) HibernatePersistableEList.isLoaded()
>>>> line: 70 HibernatePersistableEList(PersistableEList).load()
>>>> line: 176
>>>> HibernatePersistableEList(PersistableEList).delegateSize() line:
>>>> 400 HibernatePersistableEList(DelegatingEList).size() line:
>>>> 214 DelegatingEList$EIterator.hasNext() line: 1000
>>>> SystemItemProvider(ItemProviderAdapter).getChildren(Object) line:
>>>> 339 AdapterFactoryContentProvider.getChildren(Object) line:
>>>> 167 TreeViewer(AbstractTreeViewer).getRawChildren(Object)
>>>> line: 1166 TreeViewer.getRawChildren(Object) line: 768
>>>> TreeViewer(AbstractTreeViewer).getFilteredChildren(Object) line:
>>>> 574 TreeViewer(AbstractTreeViewer).getSortedChildren(Object)
>>>> line: 543 AbstractTreeViewer$1.run() line: 728
>>>> BusyIndicator.showWhile(Display, Runnable) line: 67
>>>> TreeViewer(AbstractTreeViewer).createChildren(Widget) line:
>>>> 705 TreeViewer.createChildren(Widget) line: 892
>>>> TreeViewer(AbstractTreeViewer).handleTreeExpand(TreeEvent) line:
>>>> 1251 AbstractTreeViewer$4.treeExpanded(TreeEvent) line: 1263
>>>> TypedListener.handleEvent(Event) line: 181
>>>> EventTable.sendEvent(Event) line: 66
>>>> Tree(Widget).sendEvent(Event) line: 928
>>>> Tree(Widget).sendEvent(int, Event, boolean) line: 952
>>>> Tree(Widget).sendEvent(int, Event) line: 937
>>>> Tree.wmNotifyChild(int, int) line: 6315
>>>> ViewForm(Control).WM_NOTIFY(int, int) line: 3794
>>>> ViewForm(Composite).WM_NOTIFY(int, int) line: 1166
>>>> ViewForm(Control).windowProc(int, int, int, int) line: 3298
>>>> Display.windowProc(int, int, int, int) line: 4025
>>>> OS.CallWindowProcW(int, int, int, int, int) line: not available
>>>> [native method] OS.CallWindowProc(int, int, int, int, int)
>>>> line: 1844 Tree.callWindowProc(int, int, int, int) line:
>>>> 1321 Tree.WM_LBUTTONDOWN(int, int) line: 5206
>>>> Tree(Control).windowProc(int, int, int, int) line: 3279
>>>> Tree.windowProc(int, int, int, int) line: 4785
>>>> Display.windowProc(int, int, int, int) line: 4025
>>>> OS.DispatchMessageW(MSG) line: not available [native method]
>>>> OS.DispatchMessage(MSG) line: 1925 Display.readAndDispatch()
>>>> line: 2966 Workbench.runEventLoop(Window$IExceptionHandler,
>>>> Display) line: 1914 Workbench.runUI() line: 1878
>>>> Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line:
>>>> 419 PlatformUI.createAndRunWorkbench(Display,
>>>> WorkbenchAdvisor) line: 149
>>>> TradingEditorAdvisor$Application.run(Object) line: 99
>>>> PlatformActivator$1.run(Object) line: 78
>>>> EclipseAppLauncher.runApplication(Object) line: 92
>>>> EclipseAppLauncher.start(Object) line: 68
>>>> EclipseStarter.run(Object) line: 400
>>>> EclipseStarter.run(String[], Runnable) line: 177
>>>> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
>>>> available [native method]
>>>> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
>>>> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
>>>> Method.invoke(Object, Object...) line: 585
>>>> Main.invokeFramework(String[], URL[]) line: 336
>>>> Main.basicRun(String[]) line: 280 Main.run(String[]) line:
>>>> 977 Main.main(String[]) line: 952 And here is the list variable:
>>>>
>>>> this HibernatePersistableEList (id=95) delegate
>>>> PersistentList (id=185) eFeaturePath ""
>>>> estructuralFeature EReferenceImpl (id=163) isLoaded
>>>> true isLoading false logString "EList of type:
>>>> org.eclipse.emf.teneo.hibernate.mapping.elist.HibernatePersi stableEList
>>>> of member clients owned by com.pareis.trading.System with delegate
>>>> list org.hibernate.collection.PersistentList" modCount 0
>>>> owner System (id=183) May be the reason is the isLoaded()
>>>> call here:
>>>>
>>>> protected void load() {
>>>> if (isLoaded())
>>>> return;
>>>>
>>>> This does not test the isLoaded variable but calls isLoading() which
>>>> calls doLoad() but then without having the isLoading flag set to
>>>> true? I'm really only quickly guessing...
>>>>
>>>> Thanks
>>>> Andre
>>>>
>>>>
>>>>
>>>> Andre Pareis wrote:
>>>>> Hi Martin,
>>>>>
>>>>> Ok, this method has been called frequently I think. In particular,
>>>>> I have seen calls initiated by this line:
>>>>>
>>>>> Object[] objs = delegate.toArray(); // this forces the load
>>>>>
>>>>> (frequently) which results in System.arrayCopy() calls which I also
>>>>> saw often.
>>>>>
>>>>> I haven't tried to disable the notifications but I will do that.
>>>>> But I think it has more to do with the arrayCopy invocation because
>>>>> I saw these very often when I suspended execution in the debugger
>>>>> occasionally during the long running operation.
>>>>>
>>>>> Thanks
>>>>> Andre
>>>>>
>>>>>
>>>>>
>>>>> Martin Taal wrote:
>>>>>> Hi Andre,
>>>>>> Hmm the isLoaded does not load the objects from the db (as this
>>>>>> has already been done), the only difference is that isloaded will
>>>>>> now attach loaded objects to the resource using the method:
>>>>>> addToContentOrAttach. Can the issue be in this last method? The
>>>>>> hibernate resource now also sends out load notifications as a
>>>>>> default, did you disable that?
>>>>>>
>>>>>> gr. Martin
>>>>>>
>>>>>> Andre Pareis wrote:
>>>>>>> Hi Martin,
>>>>>>>
>>>>>>> your new implementation of HibernatePersistableEList.isLoaded()
>>>>>>> gives me a huge performance drop. Before this change it took < 1
>>>>>>> min for a particular load, afterwards it takes several hours.
>>>>>>>
>>>>>>> I don't know what has changed but I just wanted to let you know
>>>>>>> about this. I think it cascades too deep and too early now. Or
>>>>>>> may be it is now correct behavior and I have to completely change
>>>>>>> my code...
>>>>>>>
>>>>>>> Regards
>>>>>>> Andre
>>>>>>
>>>>>>
>>>
>>>
>
>
--
With Regards, Martin Taal
Springsite/Elver.org
Office: Hardwareweg 4, 3821 BV Amersfoort
Postal: Nassaulaan 7, 3941 EC Doorn
The Netherlands
Tel: +31 (0)84 420 2397
Fax: +31 (0)84 225 9307
Mail: mtaal@springsite.com - mtaal@elver.org
Web: www.springsite.com - www.elver.org
|
|
|
Goto Forum:
Current Time: Fri Dec 27 03:31:15 GMT 2024
Powered by FUDForum. Page generated in 0.04383 seconds |
] 
Search
Help
Register
Login
Home
