how are you profiling? Do you count method invocations? (don't do that) just the cpu sampling is fine.
Can you send me ([EMAIL PROTECTED]) the zipped output of yourkit? because it is really not readable in my gmail inbox. johan On 3/8/07, Jan Vermeulen <[EMAIL PROTECTED]> wrote:
I commented our overwritten initModel() and did profiling on a few
(simple)
pages. Here are the profiling results for invocation of
wicket.Component.initModel() on 2 different pages:
Merged callees
#odd {background-color: #e9ecef;}
Merged callees
Name http://www.nabble.com/file/7040/desc.gif Time
(ms) Own Time (ms) Invocation
Count
http://www.nabble.com/file/7038/expanded.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.initModel()
7.078 100 % 2.656 644.503
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
6.906 98 % 1.218 36.343
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.menu.Menu.initModel()
4.812 68 % 109 43.361
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif <Recursive call of
Method[wicket.Component.initModel()]>
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif <Recursive call of
Method[wicket.Component.initModel()]>
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7044/leaf-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.model.ContextWrapModel.getNestedModel()
1.703 24 % 1.703 1.011.993
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.table.Table.getModel()
734 10 % 562 320.633
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
171 2 % 171 320.633
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7038/expanded.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.view.AbstractView.getModel()
656 9 % 531 322.187
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7038/expanded.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
125 2 % 125 322.187
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7041/leaf.gif <Recursive call of
Method[wicket.Component.initModel()]>
Generated by http://www.yourkit.com YourKit Java Profiler 6.0.12
08-mar-2007 14:19:22
Merged callees
#odd {background-color: #e9ecef;}
Merged callees
Name http://www.nabble.com/file/7040/desc.gif Time
(ms) Own Time (ms) Invocation
Count
http://www.nabble.com/file/7037/expanded.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.initModel()
11.484 100 % 3.656 637.192
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
11.421 99 % 1.968 29.736
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.menu.Menu.initModel()
7.828 68 % 62 25.452
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif <Recursive call of
Method[wicket.Component.initModel()]>
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif <Recursive call of
Method[wicket.Component.initModel()]>
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7044/leaf-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.model.ContextWrapModel.getNestedModel()
3.187 28 % 3.187 1.728.068
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.view.AbstractView.getModel()
1.687 15 % 1.062 635.244
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
625 5 % 625 635.244
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7036/expanded-with-sibling.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.field.AbstractField.getModel()
468 4 % 390 147.984
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7039/vertical.gif
http://www.nabble.com/file/7041/leaf.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
78 1 % 78 147.984
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7037/expanded.gif
http://www.nabble.com/file/7043/img1.gif
com.isencia.sherpa.web.table.Table.getModel()
453 4 % 328 147.722
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7037/empty.gif
http://www.nabble.com/file/7041/leaf.gif
http://www.nabble.com/file/7042/img0.gif wicket.Component.getModel()
125 1 % 125 147.722
Generated by http://www.yourkit.com YourKit Java Profiler 6.0.12
08-mar-2007 14:23:11
As can be seen, of the total time spent in initModel(), 98% to 99% is
spent
calling getModel(), of which 68% is lost doing recursive calls to
initModel().
Jan.
--
View this message in context:
http://www.nabble.com/Performance-problems-due-to-Component%3AinitModel%28%29-tf3362476.html#a9374177
Sent from the Wicket - Dev mailing list archive at Nabble.com.
