2 Replies Latest reply on Sep 26, 2006 8:10 AM by Dieter Cailliau

    slow remote communication

    Dieter Cailliau Newbie

      I have a stateless facade bean that fetches a deep hierarchic structure from my database using ejb3 with eager-mapped relations. This takes 2 seconds (timed with an ejb interceptor).

      On the client, i wrapped the ejb-proxy in a dynamic proxy, to time remote calls: 11 seconds.

      What is going on, in between the ejb-interceptor, and the client?

      Java-serialisation: i timed this, by serialising the fetched data into a byte-array-stream (and deserialising it again): 140ms.

      (using 4.0.4, rc8 and rc9, hsqldb or mysql, all the same)

        • 1. Re: slow remote communication
          Dieter Cailliau Newbie

          Appearently it takes 9 seconds to process flush-time cascades... whatever that may be? I'm only fetching data, it's a query.

          2006-09-26 12:29:47,308 INFO [STDOUT] 2218 ms: findLayout ([/Default/giant2.layout]) = null
          2006-09-26 12:29:47,308 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
          2006-09-26 12:29:56,808 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections

          • 2. Re: slow remote communication
            Dieter Cailliau Newbie

            I was able to skip this useless processing of cascades, by clearing the session (entitymanager.clear()) before returning.

            Using trace logging, i found out that the 9 seconds were all used to handle about 400 entities. Hibernate, i think you got a little problem here. Note: with trace logging enabled it took over 2 minutes.

            2006-09-26 13:01:10,410 TRACE [org.hibernate.transaction.CacheSynchronization] transaction before completion callback
            2006-09-26 13:01:10,410 TRACE [org.hibernate.jdbc.JDBCContext] before transaction completion
            2006-09-26 13:01:10,410 TRACE [org.hibernate.impl.SessionImpl] before transaction completion
            2006-09-26 13:01:10,410 TRACE [org.hibernate.ejb.AbstractEntityManagerImpl] automatically flushing session
            2006-09-26 13:01:10,410 TRACE [org.hibernate.impl.SessionImpl] automatically flushing session
            2006-09-26 13:01:10,410 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] flushing session
            2006-09-26 13:01:10,410 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
            ...
            2006-09-26 13:03:49,101 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] Processing unreferenced collections
            2006-09-26 13:03:49,101 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] Scheduling collection removes/(re)creates/updates
            2006-09-26 13:03:49,101 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 418 objects
            2006-09-26 13:03:49,101 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 417 collections
            2006-09-26 13:03:49,101 DEBUG [org.hibernate.pretty.Printer] listing entities: