Jan, I have seen other describe this as well. Usually issue is the collection is modified through the accesser. when NH checks for dirty entities it will save them. so while you don't want an update, NH believes one is required and saves the changes. this may be what is slowing the system down.
for a better look at what is happening check out NH Profiler [www.nhprof.com]. This will provide a wealth of knowledge about what is happening. On Jul 2, 12:30 pm, Jan Limpens <[email protected]> wrote: > something weird as well... > > When I request a transaction decorated action, my log reads like this: > -- this repeats a lot of times! maybe for each returned row: > > 2009-07-02 13:18:39,665 [4] INFO NHibernate.Engine.Cascade - cascade > NHibernate.Engine.CascadingAction+SaveUpdateCascadingAction for collection: > Fex.Businesslayer.Theme.Articles > 2009-07-02 13:18:39,667 [4] INFO NHibernate.Engine.Cascade - done cascade > NHibernate.Engine.CascadingAction+SaveUpdateCascadingAction for collection: > Fex.Businesslayer.Theme.Articles > 2009-07-02 13:18:39,671 [4] INFO NHibernate.Engine.Cascade - done > processing cascade > NHibernate.Engine.CascadingAction+SaveUpdateCascadingAction for: > Fex.Businesslayer.Theme > > -- end loop > > 2009-07-02 13:18:39,689 [4] INFO Default - Request > forhttp://localhost:15968/trial/somethingtd.asprtook 1054ms. > > -- this was a distributed transaction, it takes even more time > > -- now the following is ok! > > 2009-07-02 13:19:19,035 [9] INFO NHibernate.Loader.Loader - SELECT > this_.ThemeID as ThemeID11_0_, this_.BusinessKey as Business2_11_0_, > this_.Name as Name11_0_, this_.Description as Descript4_11_0_, this_.Visible > as Visible11_0_, this_.KitID as KitID11_0_, this_.AdditionalGuestKitID as > Addition7_11_0_, this_.AdditionalDecorationID as Addition8_11_0_, > this_.PartyFavorID as PartyFav9_11_0_, this_.ConversationID as > Convers10_11_0_ FROM Fex2.dbo.[Theme] this_ WHERE (@p0 < (SELECT > count(articles1_.ArticleID) as y0_ FROM Fex2.dbo.[Theme] this_0_ left outer > join Fex2.dbo.ArticleTheme articles3_ on this_0_.ThemeID=articles3_.ThemeID > left outer join Fex2.dbo.[Article] articles1_ on > articles3_.ArticleID=articles1_.ArticleID WHERE this_.ThemeID = > this_0_.ThemeID) and this_.Visible = @p1) ORDER BY this_.Name asc > 2009-07-02 13:19:19,098 [9] INFO Default - Request > forhttp://localhost:15968/trial/something.asprtook 71ms. > > I find it strange this is logged at INFO (usually these are DEBUG), but it > might have something to do with the problem.... > > It also could be a sideeffect of the unwanted logging :) > > 2009/7/2 Jan Limpens <[email protected]> > > > > > I don't actually know how sql server (in which format) receives the actual > > query. > > but padding the test query in Query Analyzer with 'begin transaction' and > > 'commit transaction' does not yield any differences in execution time. > > > 2009/7/2 Jan Limpens <[email protected]> > > > I could privately send you a dot.trace file. Can you open those? > > >> 2009/7/2 Tuna Toksoz <[email protected]> > > >> Do you have a profiler? or can you share this sample project with us so > >>> that we can profile? > > >>> Tuna Toksöz > >>> Eternal sunshine of the open source mind. > > >>>http://devlicio.us/blogs/tuna_toksoz > >>>http://tunatoksoz.com > >>>http://twitter.com/tehlike > > >>> On Thu, Jul 2, 2009 at 6:06 PM, Jan Limpens <[email protected]>wrote: > > >>>> 2009-07-02 12:02:52,362 [4] INFO Default - Request for > >>>>http://localhost:15968/trial/something.asprtook 125ms. > >>>> 2009-07-02 12:02:54,371 [4] INFO Default - Request for > >>>>http://localhost:15968/trial/something.asprtook 124ms. > >>>> 2009-07-02 12:02:55,115 [8] INFO Default - Request for > >>>>http://localhost:15968/trial/something.asprtook 116ms. > >>>> 2009-07-02 12:02:58,838 [8] INFO Default - Request for > >>>>http://localhost:15968/trial/somethingt.asprtook 477ms. > >>>> 2009-07-02 12:03:00,215 [4] INFO Default - Request for > >>>>http://localhost:15968/trial/somethingt.asprtook 406ms. > >>>> 2009-07-02 12:03:01,227 [8] INFO Default - Request for > >>>>http://localhost:15968/trial/somethingt.asprtook 411ms. > > >> -- > >> Jan > > > -- > > Jan > > -- > Jan --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Castle Project Users" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/castle-project-users?hl=en -~----------~----~----~----~------~----~------~--~---
