4 Replies Latest reply on Mar 15, 2007 9:48 PM by Shane Bryzak

    @Restrict preventing @Asynchronous method from execution

    Chris Lowe Apprentice

      Hi,

      I have a simple asynchronous call which is failing with the following message:

      21:59:44,765 ERROR [TimerImpl] Error invoking ejbTimeout: javax.ejb.EJBException: java.lang.NullPointerException: facesContext


      The error is thrown when the @Restrict annotation is present. If I remove it then the method executes fine.

      The async bean has been stripped down to the following (and still exhibits the error):
      @Local
      public interface PaymentHandler {
       @Asynchronous
       void processOrderPayment();
      }
      
      @Stateless
      @Name("paymentHandler")
      @Restrict("#{identity.loggedIn}")
      public class PaymentHandlerHome implements PaymentHandler, Serializable {
       private static final long serialVersionUID = -1727810612672179507L;
      
       public void processOrderPayment() {
       System.out.println("****** processOrderPayment");
       }
      }


      Invocation is from the following action:

      @Name("paymentBean")
      @Stateful
      @Restrict("#{identity.loggedIn}")
      public class PaymentBeanHome implements PaymentBean, Serializable {
      
       @In(create = true)
       private PaymentHandler paymentHandler;
      
       @In
       private FacesContext facesContext;
      
       @Create
       public void initialise() {
       }
      
       @Destroy
       @Remove
       public void destroy() {
       }
      
      
       public String submitPayment(final String outcome) {
       ...
      
       // attempt to submit the payment for processing.
       submitPaymentRequest();
      
       ...
      
       return outcome;
       }
      
       private void submitPaymentRequest() {
       paymentHandler.processOrderPayment();
       }
      
      }


      I am logged in at this point and the bean that invokes the asynch method has the same @Restrict present. For obvious reasons, I would really like to guard this action. Am I doing anything wrong?

      Cheers,

      Chris.

        • 1. Re: @Restrict preventing @Asynchronous method from execution
          Chris Lowe Apprentice

          Here is some detailed log output leading to the error:

          21:59:33,359 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:33,406 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
          21:59:33,406 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_event]
          21:59:33,406 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
          21:59:33,406 DEBUG [ConnectionManager] opening JDBC connection
          21:59:33,406 DEBUG [SQL] insert into ripuk.order_event (timestamp, event_type_id, order_id, collection_time, collection_date, actual_quantity, return_quantity, tracking_number, tracking_url, estimated_delivery) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
          21:59:33,468 INFO [STDOUT] Hibernate: insert into ripuk.order_event (timestamp, event_type_id, order_id, collection_time, collection_date, actual_quantity, return_quantity, tracking_number, tracking_url, estimated_delivery) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
          21:59:33,484 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 5
          21:59:33,484 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
          21:59:33,484 DEBUG [ConnectionManager] aggressively releasing JDBC connection
          21:59:34,265 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:34,265 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
          21:59:34,265 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_quantity]
          21:59:34,265 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
          21:59:34,265 DEBUG [ConnectionManager] opening JDBC connection
          21:59:34,281 DEBUG [SQL] insert into ripuk.order_quantity (name, order_id, price, quantity, is_buddy) values (?, ?, ?, ?, 0)
          21:59:34,312 INFO [STDOUT] Hibernate: insert into ripuk.order_quantity (name, order_id, price, quantity, is_buddy) values (?, ?, ?, ?, 0)
          21:59:34,312 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 7
          21:59:34,312 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
          21:59:34,312 DEBUG [ConnectionManager] aggressively releasing JDBC connection
          21:59:34,312 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:34,390 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
          21:59:34,390 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_format]
          21:59:34,390 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
          21:59:34,390 DEBUG [ConnectionManager] opening JDBC connection
          21:59:34,390 DEBUG [SQL] insert into ripuk.order_format (order_id, price, audio_format_option_id, is_default) values (?, ?, ?, ?)
          21:59:34,390 INFO [STDOUT] Hibernate: insert into ripuk.order_format (order_id, price, audio_format_option_id, is_default) values (?, ?, ?, ?)
          21:59:34,468 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 6
          21:59:34,468 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
          21:59:34,468 DEBUG [ConnectionManager] aggressively releasing JDBC connection
          21:59:34,468 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:34,468 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
          21:59:34,468 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_media]
          21:59:34,515 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
          21:59:34,515 DEBUG [ConnectionManager] opening JDBC connection
          21:59:34,515 DEBUG [SQL] insert into ripuk.order_media (order_id, price, media_hard_disk_id, media_option_id, player_model) values (?, ?, ?, ?, ?)
          21:59:34,515 INFO [STDOUT] Hibernate: insert into ripuk.order_media (order_id, price, media_hard_disk_id, media_option_id, player_model) values (?, ?, ?, ?, ?)
          21:59:34,531 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 9
          21:59:34,578 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
          21:59:34,578 DEBUG [ConnectionManager] aggressively releasing JDBC connection
          21:59:34,578 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:34,578 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.interpolator
          21:59:34,578 DEBUG [Component] initializing new instance of: org.jboss.seam.core.interpolator
          21:59:34,671 DEBUG [Component] done initializing: org.jboss.seam.core.interpolator
          21:59:34,671 DEBUG [OrderHome] persist successful
          21:59:34,671 DEBUG [RootInterceptor] intercepted: paymentHandler.processOrderPayment
          21:59:34,671 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.dispatcher
          21:59:34,671 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:34,671 DEBUG [RootInterceptor] intercepted: org.jboss.seam.core.dispatcher.scheduleInvocation
          21:59:34,718 DEBUG [SessionBeanInterceptor] post construct phase for instance of component: org.jboss.seam.core.dispatcher
          21:59:34,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.dispatcher
          21:59:34,718 DEBUG [Component] done initializing: org.jboss.seam.core.dispatcher
          21:59:34,718 DEBUG [RootInterceptor] intercepted: org.jboss.seam.core.dispatcher.POST_CONSTRUCT
          21:59:34,718 DEBUG [RootInterceptor] intercepted: org.jboss.seam.core.dispatcher.scheduleInvocation
          21:59:34,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:34,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:34,796 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:34,796 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:34,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:34,796 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:34,812 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.dispatcher
          21:59:34,890 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:34,890 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.dispatcher
          21:59:34,968 DEBUG [TimerImpl] setTimerState: created
          21:59:35,015 DEBUG [TimerImpl] setTimerState: started_in_tx
          21:59:35,015 DEBUG [Component] outjecting dependencies of: paymentBean
          21:59:35,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:35,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:35,015 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:35,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:35,046 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:35,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:35,046 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.billingAddress
          21:59:35,046 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:35,046 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:35,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:35,125 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:35,125 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:35,125 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:35,125 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.billingAddress
          21:59:35,125 DEBUG [Component] disinjecting dependencies of: paymentBean
          21:59:35,125 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:35,187 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:35,187 DEBUG [Navigator] rendering: /secure/payment-processing.xhtml
          21:59:35,187 DEBUG [SeamPhaseListener] after phase: INVOKE_APPLICATION(5)
          21:59:35,187 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:35,187 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:35,187 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:35,187 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
          21:59:35,250 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:35,250 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:35,250 DEBUG [AbstractSeamPhaseListener] committing transaction after phase: INVOKE_APPLICATION(5)
          21:59:35,250 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:35,343 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
          21:59:35,343 DEBUG [AbstractFlushingEventListener] dirty checking collections
          21:59:35,343 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#11], was: [com.ripuk.model.Address.orderAddresses#11] (uninitialized)
          21:59:35,343 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#12], was: [com.ripuk.model.Address.orderAddresses#12] (uninitialized)
          21:59:35,343 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#52], was: [com.ripuk.model.Address.orderAddresses#52] (uninitialized)
          21:59:35,390 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#53], was: [com.ripuk.model.Address.orderAddresses#53] (uninitialized)
          21:59:35,390 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#54], was: [com.ripuk.model.Address.orderAddresses#54] (uninitialized)
          21:59:35,390 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#56], was: [com.ripuk.model.Address.orderAddresses#56] (uninitialized)
          21:59:35,390 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#57], was: [com.ripuk.model.Address.orderAddresses#57] (uninitialized)
          21:59:35,468 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#60], was: [com.ripuk.model.Address.orderAddresses#60] (uninitialized)
          21:59:35,468 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#61], was: [com.ripuk.model.Address.orderAddresses#61] (uninitialized)
          21:59:35,468 DEBUG [Collections] Collection found: [com.ripuk.model.AddressType.orderAddresses#1], was: [com.ripuk.model.AddressType.orderAddresses#1] (uninitialized)
          21:59:35,468 DEBUG [Collections] Collection found: [com.ripuk.model.EventType.orderEvents#1], was: [com.ripuk.model.EventType.orderEvents#1] (uninitialized)
          21:59:35,546 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderAddresses#6], was: [<unreferenced>] (initialized)
          21:59:35,546 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderEvents#6], was: [<unreferenced>] (initialized)
          21:59:35,546 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderQuantities#6], was: [<unreferenced>] (initialized)
          21:59:35,546 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderFormats#6], was: [<unreferenced>] (initialized)
          21:59:35,593 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderMedia#6], was: [<unreferenced>] (initialized)
          21:59:35,593 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 1 updates, 0 deletions to 27 objects
          21:59:35,593 DEBUG [AbstractFlushingEventListener] Flushed: 5 (re)creations, 0 updates, 0 removals to 16 collections
          21:59:35,593 DEBUG [Printer] listing entities:
          21:59:35,593 DEBUG [Printer] com.ripuk.model.Address{id=12, phoneNumber=null, county=Gloucestershire, organisation=Cheltenham Clocks, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 2LB, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=16a Lansdown Place Lane}
          21:59:35,656 DEBUG [Printer] com.ripuk.model.Address{id=11, phoneNumber=null, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=1 Imperial Gate}
          21:59:35,656 DEBUG [Printer] com.ripuk.model.OrderQuantity{id=7, price=67.5, order=com.ripuk.model.Order#6, name=You, quantity=50}
          21:59:35,656 DEBUG [Printer] com.ripuk.model.Order{id=6, totalQuantity=50, orderFormats=[com.ripuk.model.OrderFormat#6], created=2007-03-14 21:55:59, orderEvents=[com.ripuk.model.OrderEvent#5], unitRate=1.35, orderMedia=[com.ripuk.model.OrderMedia#9], orderAddresses=[com.ripuk.model.OrderAddress#9, com.ripuk.model.OrderAddress#10], lastOrderEvent=com.ripuk.model.OrderEvent#5, orderQuantities=[com.ripuk.model.AbstractOrderQuantity#7], user=com.ripuk.model.User#1, totalPrice=67.5}
          21:59:35,734 DEBUG [Printer] com.ripuk.model.OrderEvent{collectionTime=null, timestamp=2007-03-14 21:59:32, id=5, estimatedDelivery=null, trackingUrl=null, trackingNumber=null, order=com.ripuk.model.Order#6, actualQuantity=null, eventType=com.ripuk.model.EventType#1, collectionDate=null, returnQuantity=null}
          21:59:35,734 DEBUG [Printer] com.ripuk.model.OrderAddress{id=9, order=com.ripuk.model.Order#6, address=com.ripuk.model.Address#11, addressType=com.ripuk.model.AddressType#2}
          21:59:35,734 DEBUG [Printer] com.ripuk.model.Address{id=54, phoneNumber=07967 56 56 42, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=12 Imperial Gate}
          21:59:35,781 DEBUG [Printer] com.ripuk.model.Address{id=53, phoneNumber=07967 56 56 42, county=Addresshire, organisation=Manual Address, orderAddresses=<uninitialized>, town=Address Town, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=123 Address Land}
          21:59:35,781 DEBUG [Printer] com.ripuk.model.Address{id=52, phoneNumber=07967 56 56 42, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=8 Imperial Gate}
          21:59:35,859 DEBUG [Printer] com.ripuk.model.OrderAddress{id=10, order=com.ripuk.model.Order#6, address=com.ripuk.model.Address#11, addressType=com.ripuk.model.AddressType#1}
          21:59:35,859 DEBUG [Printer] com.ripuk.model.OrderFormat{id=6, price=0.0, order=com.ripuk.model.Order#6, isDefault=true, audioFormatOption=com.ripuk.model.AudioFormatOption#15}
          21:59:35,859 DEBUG [Printer] com.ripuk.model.AddressType{id=1, orderAddresses=<uninitialized>, descr=Billing}
          21:59:35,859 DEBUG [Printer] com.ripuk.model.OrderMedia{id=9, price=0.0, order=com.ripuk.model.Order#6, playerModel=null, mediaOption=com.ripuk.model.MediaOption#1, mediaHardDisk=null}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.CardType{id=9, name=Delta}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.CardType{id=8, name=Visa Electron}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.CardType{id=7, name=Diners}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.CardType{id=6, name=Switch/Maestro}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.CardType{id=5, name=Solo}
          21:59:35,937 DEBUG [Printer] com.ripuk.model.Address{id=60, phoneNumber=null, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=1 Imperial Gate}
          21:59:35,984 DEBUG [Printer] com.ripuk.model.CardType{id=4, name=JCB}
          21:59:35,984 DEBUG [Printer] com.ripuk.model.Address{id=61, phoneNumber=null, county=Gloucestershire, organisation=Cheltenham Clocks, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 2LB, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=16a Lansdown Place Lane}
          21:59:35,984 DEBUG [Printer] more......
          21:59:35,984 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.`order`]
          21:59:36,078 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
          21:59:36,078 DEBUG [ConnectionManager] opening JDBC connection
          21:59:36,078 DEBUG [SQL] update ripuk.`order` set user_id=?, total_quantity=?, unit_rate=?, last_order_event_id=?, created=?, total_price=? where id=?
          21:59:36,078 INFO [STDOUT] Hibernate: update ripuk.`order` set user_id=?, total_quantity=?, unit_rate=?, last_order_event_id=?, created=?, total_price=? where id=?
          21:59:36,093 DEBUG [AbstractBatcher] Executing batch size: 1
          21:59:36,156 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
          21:59:36,156 DEBUG [ConnectionManager] skipping aggressive-release due to flush cycle
          21:59:36,156 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_address]
          21:59:36,156 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_event]
          21:59:36,156 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_quantity]
          21:59:36,156 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_format]
          21:59:36,187 DEBUG [UpdateTimestampsCache] Pre-invalidating space [ripuk.order_media]
          21:59:36,187 DEBUG [ConnectionManager] aggressively releasing JDBC connection
          21:59:36,187 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
          21:59:36,187 WARN [TxConnectionManager] Prepare called on a local tx. Use of local transactions on a jta transaction with more than one branch may result in inconsistent data in some cases of failure.
          21:59:36,296 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.`order`], timestamp: 4808333624508416
          21:59:36,296 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_address], timestamp: 4808333624508417
          21:59:36,296 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_address], timestamp: 4808333624508418
          21:59:36,296 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_event], timestamp: 4808333624508419
          21:59:36,296 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_quantity], timestamp: 4808333624508420
          21:59:36,343 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_format], timestamp: 4808333624700928
          21:59:36,343 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_media], timestamp: 4808333624700929
          21:59:36,343 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.`order`], timestamp: 4808333624700930
          21:59:36,343 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_address], timestamp: 4808333624700931
          21:59:36,343 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_event], timestamp: 4808333624700932
          21:59:36,390 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_quantity], timestamp: 4808333624893440
          21:59:36,390 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_format], timestamp: 4808333624893441
          21:59:36,390 DEBUG [UpdateTimestampsCache] Invalidating space [ripuk.order_media], timestamp: 4808333624893442
          21:59:36,390 DEBUG [TimerImpl] commit: [id=1,target=[target=jboss.j2ee:service=EJB3,ear=ripuk.ear,jar=jboss-seam.jar,name=Dispatcher],remaining=-1437,periode=0,started_in_tx]
          21:59:36,453 DEBUG [TimerImpl] setTimerState: active
          21:59:36,453 DEBUG [TimerImpl] run: [id=1,target=[target=jboss.j2ee:service=EJB3,ear=ripuk.ear,jar=jboss-seam.jar,name=Dispatcher],remaining=-1500,periode=0,active]
          21:59:36,453 DEBUG [TimerImpl] setTimerState: in_timeout
          21:59:36,453 DEBUG [SeamPhaseListener] before phase: RENDER_RESPONSE(6)
          21:59:36,453 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:36,468 DEBUG [SessionBeanInterceptor] post construct phase for component instantiated outside Seam, assuming default role: org.jboss.seam.core.dispatcher
          21:59:36,531 DEBUG [AbstractSeamPhaseListener] beginning transaction prior to phase: RENDER_RESPONSE(6)
          21:59:36,531 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:36,531 DEBUG [Component] initializing new instance of: org.jboss.seam.core.dispatcher
          21:59:36,531 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,578 DEBUG [Component] done initializing: org.jboss.seam.core.dispatcher
          21:59:36,578 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,578 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,578 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,578 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,640 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,578 DEBUG [Lifecycle] >>> Begin call
          21:59:36,640 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.conversationList
          21:59:36,640 DEBUG [RootInterceptor] intercepted: org.jboss.seam.core.dispatcher.POST_CONSTRUCT
          21:59:36,640 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,640 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,640 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,765 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,765 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.conversationList
          21:59:36,765 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,765 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,765 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.SESSION
          21:59:36,765 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,921 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,921 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,921 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.SESSION
          21:59:36,921 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,921 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.switcher
          21:59:36,921 DEBUG [Lifecycle] destroying business process context
          21:59:36,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:36,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,031 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.switcher
          21:59:37,031 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
          21:59:37,078 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,078 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,078 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,078 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,078 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,078 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,218 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,234 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.conversationStack
          21:59:37,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,312 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,312 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,312 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.BUSINESS_PROCESS
          21:59:37,312 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.manager
          21:59:37,375 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,375 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,375 DEBUG [Component] initializing new instance of: org.jboss.seam.core.manager
          21:59:37,375 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,375 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.conversationStack
          21:59:37,375 DEBUG [Component] done initializing: org.jboss.seam.core.manager
          21:59:37,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,484 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,484 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,484 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,562 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.manager
          21:59:37,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,500 DEBUG [DTDEntityResolver] trying to resolve system-id [http://jboss.com/products/seam/pages-1.1.dtd]
          21:59:37,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,625 DEBUG [DTDEntityResolver] recognized Seam namespace; attempting to resolve on classpath under org/jboss/seam/
          21:59:37,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,625 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.manager
          21:59:37,625 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,703 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.manager
          21:59:37,625 DEBUG [DTDEntityResolver] unable to locate [http://jboss.com/products/seam/pages-1.1.dtd] on classpath
          21:59:37,781 DEBUG [Lifecycle] destroying conversation context
          21:59:37,781 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,781 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,781 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,781 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,843 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:37,843 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.CONVERSATION
          21:59:37,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:37,843 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:37,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:38,781 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.facesPage
          21:59:38,796 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:38,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.facesPage
          21:59:38,796 DEBUG [Component] done initializing: org.jboss.seam.core.facesPage
          21:59:38,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:38,812 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:38,812 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:38,890 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.CONVERSATION
          21:59:38,890 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:38,890 DEBUG [Lifecycle] flushing server-side conversation context
          21:59:38,890 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:38,890 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:38,890 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.conversationEntries
          21:59:38,890 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:38,937 DEBUG [Component] initializing new instance of: org.jboss.seam.core.conversationEntries
          21:59:38,937 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:38,937 DEBUG [Component] done initializing: org.jboss.seam.core.conversationEntries
          21:59:38,937 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.facesPage
          21:59:38,937 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:38,937 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,093 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,093 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,093 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.facesPage
          21:59:39,093 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,093 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,093 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.conversationEntries
          21:59:39,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,203 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,203 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,203 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.facesPage
          21:59:39,203 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,203 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:39,203 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,281 DEBUG [Component] seam component not found: org.jboss.seam.persistence.persistenceProvider
          21:59:39,281 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,281 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,281 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.conversationEntries
          21:59:39,281 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
          21:59:39,281 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,343 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,437 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,437 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.conversationEntries
          21:59:39,437 DEBUG [Lifecycle] flushing session context
          21:59:39,437 DEBUG [Lifecycle] destroying event context
          21:59:39,437 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,437 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,437 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,531 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,531 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,531 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,531 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.EVENT
          21:59:39,531 DEBUG [Contexts] destroying: org.jboss.seam.core.manager
          21:59:39,531 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,531 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,546 DEBUG [SeamVariableResolver] resolving name: bodyonload
          21:59:39,578 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,578 DEBUG [Component] seam component not found: bodyonload
          21:59:39,578 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,578 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,578 DEBUG [SeamVariableResolver] could not resolve name
          21:59:39,578 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,593 DEBUG [SeamVariableResolver] resolving name: identity
          21:59:39,656 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.manager
          21:59:39,656 DEBUG [SeamVariableResolver] resolving name: org
          21:59:39,656 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,656 DEBUG [Component] seam component not found: org
          21:59:39,656 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,656 DEBUG [SeamVariableResolver] could not resolve name
          21:59:39,656 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,750 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.EVENT
          21:59:39,750 DEBUG [Lifecycle] <<< End call
          21:59:39,750 DEBUG [Component] seam component not found: org.jboss
          21:59:39,750 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:39,750 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:39,750 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:39,750 DEBUG [Lifecycle] >>> Begin call
          21:59:39,750 DEBUG [SeamVariableResolver] resolved name to Seam component
          21:59:39,750 DEBUG [SeamVariableResolver] resolving name: identity
          21:59:39,750 DEBUG [SeamVariableResolver] resolving name: org
          21:59:39,750 DEBUG [Component] seam component not found: org
          21:59:39,750 DEBUG [SeamVariableResolver] could not resolve name
          21:59:39,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,750 DEBUG [Component] seam component not found: org.jboss
          21:59:39,750 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:39,812 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:39,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,812 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:39,812 DEBUG [SeamVariableResolver] resolved name to Seam component
          21:59:39,812 DEBUG [SeamVariableResolver] resolving name: identity
          21:59:39,812 DEBUG [SeamVariableResolver] resolving name: org
          21:59:39,812 DEBUG [Component] seam component not found: org
          21:59:39,812 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,890 DEBUG [SeamVariableResolver] could not resolve name
          21:59:39,890 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,890 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,890 DEBUG [Component] seam component not found: org.jboss
          21:59:39,890 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,890 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:39,890 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.executingAsynchronousCall
          21:59:39,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:39,968 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:39,968 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:39,968 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:39,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,015 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,015 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.executingAsynchronousCall
          21:59:39,968 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:40,015 DEBUG [SeamVariableResolver] resolved name to Seam component
          21:59:40,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,109 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,109 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,031 DEBUG [SeamVariableResolver] resolving name: identity
          21:59:40,109 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,109 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,109 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,109 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.timer
          21:59:40,187 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,187 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,187 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,109 DEBUG [SeamVariableResolver] resolving name: org
          21:59:40,187 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,187 DEBUG [Component] seam component not found: org
          21:59:40,187 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,187 DEBUG [SeamVariableResolver] could not resolve name
          21:59:40,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,234 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.timer
          21:59:40,234 DEBUG [Component] seam component not found: org.jboss
          21:59:40,234 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:40,234 DEBUG [Component] instantiating Seam component: paymentHandler
          21:59:40,234 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:40,234 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:40,296 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:40,296 DEBUG [SeamVariableResolver] resolved name to Seam component
          21:59:40,296 DEBUG [SeamVariableResolver] resolving name: identity
          21:59:40,296 DEBUG [RootInterceptor] intercepted: paymentHandler.processOrderPayment
          21:59:40,296 DEBUG [SeamVariableResolver] resolving name: org
          21:59:40,375 DEBUG [Component] seam component not found: org
          21:59:40,375 DEBUG [Component] instantiating Seam component: org.jboss.seam.security.identity
          21:59:40,375 DEBUG [SeamVariableResolver] could not resolve name
          21:59:40,375 DEBUG [Component] initializing new instance of: org.jboss.seam.security.identity
          21:59:40,375 DEBUG [Component] done initializing: org.jboss.seam.security.identity
          21:59:40,375 DEBUG [Component] seam component not found: org.jboss
          21:59:40,375 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,421 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:40,421 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,421 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:40,421 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,421 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:40,421 DEBUG [SeamVariableResolver] resolved name to Seam component
          21:59:40,421 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,500 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,500 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,500 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.security.identity
          21:59:40,500 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,500 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,500 DEBUG [SeamPhaseListener] after phase: RENDER_RESPONSE(6)
          21:59:40,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,609 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
          21:59:40,609 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.security.identity
          21:59:40,609 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:40,609 DEBUG [Component] seam component not found: securityRules
          21:59:40,687 WARN [RuleBasedIdentity] no security rule base available - please install a RuleBase with the name 'securityRules' if permission checks are required.
          21:59:40,609 DEBUG [AbstractSeamPhaseListener] committing transaction after phase: RENDER_RESPONSE(6)
          21:59:40,687 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,687 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:40,687 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,750 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.security.identity
          21:59:40,750 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:40,796 DEBUG [Manager] Storing conversation state: 4
          21:59:40,796 DEBUG [Lifecycle] After render response, destroying contexts
          21:59:40,796 DEBUG [Lifecycle] destroying business process context
          21:59:40,796 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,796 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,796 DEBUG [Component] seam component not found: org
          21:59:40,875 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,875 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,875 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,875 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
          21:59:40,875 DEBUG [Component] seam component not found: org.jboss
          21:59:40,875 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,875 DEBUG [Component] seam component not found: org.jboss.seam
          21:59:40,953 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,953 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:40,953 DEBUG [Component] seam component not found: org.jboss.seam.security
          21:59:40,953 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:40,953 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:40,953 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
          21:59:40,953 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,000 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.BUSINESS_PROCESS
          21:59:41,000 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,000 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,000 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,000 DEBUG [Lifecycle] flushing server-side conversation context
          21:59:41,000 DEBUG [Events] Processing event:org.jboss.seam.notLoggedIn
          21:59:41,000 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:41,078 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:41,078 DEBUG [RepositoryClassLoader] setRepository, repository=org.jboss.mx.loading.HeirarchicalLoaderRepository3@1578426, cl=org.jboss.mx.loading.HeirarchicalLoaderRepository3$CacheClassLoader@6288ed{ url=null ,addedOrder=0}
          21:59:41,078 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:41,156 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:41,156 DEBUG [RepositoryClassLoader] setRepository, repository=org.jboss.mx.loading.HeirarchicalLoaderRepository3@1578426, cl=org.jboss.mx.loading.HeirarchicalLoaderRepository3$CacheClassLoader@10b81da{ url=null ,addedOrder=0}
          21:59:41,156 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:41,203 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,203 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
          21:59:41,203 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,203 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,203 DEBUG [Lifecycle] flushing session context
          21:59:41,281 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,281 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,281 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,281 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.executingAsynchronousCall
          21:59:41,281 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,281 DEBUG [Lifecycle] destroying event context
          21:59:41,359 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,359 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,406 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,406 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.executingAsynchronousCall
          21:59:41,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,406 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,406 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.EVENT
          21:59:41,468 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,468 DEBUG [Contexts] destroying: org.ajax4jsf.framework.HEADER_PROCESSED
          21:59:41,546 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.SESSION
          21:59:41,546 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.webapp.AdfacesFilterImpl.EXECUTED
          21:59:41,546 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.uinode.RenderingContext
          21:59:41,546 DEBUG [Contexts] destroying: org.jboss.seam.security.identity
          21:59:41,546 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.dispatch.DispatchResponseConfiguratorImpl.APPLIED
          21:59:41,546 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,593 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.renderkit._pprActiveOnPage
          21:59:41,593 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,593 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.AdfFacesPhaseListener.CREATED_CONTEXT
          21:59:41,593 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,593 DEBUG [Contexts] destroying: facelets.Encoding
          21:59:41,593 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Contexts] destroying: org.jboss.seam.core.validation
          21:59:41,671 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,671 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.security.identity
          21:59:41,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,796 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.validation
          21:59:41,796 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,796 DEBUG [Contexts] destroying: org.jboss.seam.core.manager
          21:59:41,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,796 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,796 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,859 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,859 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,859 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.SESSION
          21:59:41,859 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:41,875 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:41,875 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:41,875 DEBUG [Lifecycle] destroying business process context
          21:59:42,625 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.manager
          21:59:42,625 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,625 DEBUG [Contexts] destroying: org.ajax4jsf.framework.HEADER_SCRIPTS
          21:59:42,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,625 DEBUG [Contexts] destroying: org.ajax4jsf.VIEW_STATE_SAVED
          21:59:42,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:42,625 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.renderkit.CACHED_SERIALIZED_VIEW
          21:59:42,671 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,671 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.InitialViewRoot
          21:59:42,671 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,671 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.GlobalConfiguratorImpl.IN_REQUEST
          21:59:42,671 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:42,671 DEBUG [Contexts] destroying: com.sun.facelets.legacy.ELCONTEXT
          21:59:42,750 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
          21:59:42,750 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.application.CachedSerializedView
          21:59:42,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,750 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.CachedRequestContext
          21:59:42,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,750 DEBUG [Contexts] destroying: com.exade.vcp.Filter.done
          21:59:42,828 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:42,828 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.GlobalConfiguratorImpl.REQUEST_TYPE
          21:59:42,828 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,828 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.PageFlowScope
          21:59:42,828 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,828 DEBUG [Contexts] destroying: ajaxContext
          21:59:42,875 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:42,875 DEBUG [Contexts] destroying: com.exade.vcp.Filter.ResponseWrapper
          21:59:42,875 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.BUSINESS_PROCESS
          21:59:42,875 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,875 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.manager
          21:59:42,875 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,937 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:42,875 DEBUG [Component] initializing new instance of: org.jboss.seam.core.manager
          21:59:42,937 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,937 DEBUG [Component] done initializing: org.jboss.seam.core.manager
          21:59:42,937 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:42,937 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:42,937 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,015 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,015 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.EVENT
          21:59:43,015 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,015 DEBUG [Lifecycle] <<< End web request
          21:59:43,015 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,015 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
          21:59:43,062 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,062 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.manager
          21:59:43,062 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,062 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,171 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,171 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,171 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,171 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,171 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.manager
          21:59:43,171 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,265 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,265 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,265 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,281 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,281 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,281 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.manager
          21:59:43,328 DEBUG [Lifecycle] destroying conversation context
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.CONVERSATION
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.CONVERSATION
          21:59:43,328 DEBUG [Lifecycle] flushing server-side conversation context
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.conversationEntries
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.conversationEntries
          21:59:43,328 DEBUG [Component] done initializing: org.jboss.seam.core.conversationEntries
          21:59:43,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
          21:59:43,328 DEBUG [Component] done ini


          • 2. Re: @Restrict preventing @Asynchronous method from execution
            Shane Bryzak Master

            Do you not get a stack trace when this happens?

            • 3. Re: @Restrict preventing @Asynchronous method from execution
              Chris Lowe Apprentice

              Hi Shane,

              Sorry, the output was truncated. As far as I can tell, there is no stack trace. Here the log around the error:

              08:17:25,453 DEBUG [Manager] Restoring conversation with id: 4
              08:17:25,453 DEBUG [AbstractSeamPhaseListener] After restoring conversation context: ConversationContext(4)
              08:17:25,453 DEBUG [SeamPhaseListener] before phase: APPLY_REQUEST_VALUES(2)
              08:17:25,453 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,453 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,453 DEBUG [Lifecycle] flushing session context
              08:17:25,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,562 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
              08:17:25,562 DEBUG [Lifecycle] destroying event context
              08:17:25,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,562 DEBUG [SeamVariableResolver] resolving name: identity
              08:17:25,640 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,640 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,640 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,640 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.EVENT
              08:17:25,640 DEBUG [SeamVariableResolver] resolving name: org
              08:17:25,640 DEBUG [Contexts] destroying: org.jboss.seam.core.manager
              08:17:25,640 DEBUG [Component] seam component not found: org
              08:17:25,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,718 DEBUG [SeamVariableResolver] could not resolve name
              08:17:25,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,718 DEBUG [Component] seam component not found: org.jboss
              08:17:25,718 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,718 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:25,734 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,828 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,828 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,828 DEBUG [Component] seam component not found: org.jboss.seam.security
              08:17:25,828 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.manager
              08:17:25,828 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
              08:17:25,828 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,937 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,937 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:25,937 DEBUG [SeamVariableResolver] resolved name to Seam component
              08:17:25,937 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:25,937 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:25,937 DEBUG [SeamPhaseListener] after phase: APPLY_REQUEST_VALUES(2)
              08:17:25,937 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,031 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,031 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.EVENT
              08:17:26,031 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,031 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,031 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
              08:17:26,031 DEBUG [Lifecycle] <<< End call
              08:17:26,031 DEBUG [SeamPhaseListener] before phase: PROCESS_VALIDATIONS(3)
              08:17:26,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,140 ERROR [TimerImpl] Error invoking ejbTimeout: javax.ejb.EJBException: java.lang.NullPointerException: facesContext
              08:17:26,140 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
              08:17:26,140 DEBUG [TimerImpl] Timer was not registered with Tx, resetting state: [id=1,target=[target=jboss.j2ee:service=EJB3,ear=ripuk.ear,jar=jboss-seam.jar,name=Dispatcher],remaining=-12250,periode=0,in_timeout]
              08:17:26,218 DEBUG [TimerImpl] setTimerState: expired
              08:17:26,218 DEBUG [TimerImpl] killTimer: [id=1,target=[target=jboss.j2ee:service=EJB3,ear=ripuk.ear,jar=jboss-seam.jar,name=Dispatcher],remaining=-12328,periode=0,expired]
              08:17:26,218 DEBUG [SeamVariableResolver] resolving name: identity
              08:17:26,296 DEBUG [SeamVariableResolver] resolving name: org
              08:17:26,296 DEBUG [Component] seam component not found: org
              08:17:26,296 DEBUG [SeamVariableResolver] could not resolve name
              08:17:26,296 DEBUG [Component] seam component not found: org.jboss
              08:17:26,296 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:26,296 DEBUG [Component] seam component not found: org.jboss.seam.security
              08:17:26,296 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
              08:17:26,296 DEBUG [SeamVariableResolver] resolved name to Seam component
              08:17:26,375 DEBUG [SeamPhaseListener] after phase: PROCESS_VALIDATIONS(3)
              08:17:26,375 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,375 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,375 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,375 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
              08:17:26,375 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.validation
              08:17:26,375 DEBUG [Component] initializing new instance of: org.jboss.seam.core.validation
              08:17:26,453 DEBUG [Component] done initializing: org.jboss.seam.core.validation
              08:17:26,453 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,453 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,453 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,453 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,453 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,531 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,531 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.validation
              08:17:26,531 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,531 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,531 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,531 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,640 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.validation
              08:17:26,640 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,640 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,640 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,718 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,718 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,718 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.validation
              08:17:26,718 DEBUG [SeamPhaseListener] before phase: UPDATE_MODEL_VALUES(4)
              08:17:26,718 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,796 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,796 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,796 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
              08:17:26,796 DEBUG [SeamVariableResolver] resolving name: identity
              08:17:26,796 DEBUG [SeamVariableResolver] resolving name: org
              08:17:26,796 DEBUG [Component] seam component not found: org
              08:17:26,796 DEBUG [SeamVariableResolver] could not resolve name
              08:17:26,796 DEBUG [Component] seam component not found: org.jboss
              08:17:26,875 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:26,875 DEBUG [Component] seam component not found: org.jboss.seam.security
              08:17:26,875 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
              08:17:26,875 DEBUG [SeamVariableResolver] resolved name to Seam component
              08:17:26,875 DEBUG [SeamPhaseListener] after phase: UPDATE_MODEL_VALUES(4)
              08:17:26,875 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,875 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,968 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,968 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
              08:17:26,968 DEBUG [SeamPhaseListener] before phase: INVOKE_APPLICATION(5)
              08:17:26,968 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:26,968 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:26,968 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:26,968 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
              08:17:27,046 DEBUG [SeamVariableResolver] resolving name: paymentBean
              08:17:27,046 DEBUG [Contexts] found in conversation context: paymentBean
              08:17:27,046 DEBUG [SeamVariableResolver] resolved name to Seam component
              08:17:27,046 DEBUG [RootInterceptor] intercepted: paymentBean.pollPaymentStatus
              08:17:27,046 DEBUG [SeamVariableResolver] resolving name: org
              08:17:27,046 DEBUG [Component] seam component not found: org
              08:17:27,046 DEBUG [SeamVariableResolver] could not resolve name
              08:17:27,046 DEBUG [Component] seam component not found: org.jboss
              08:17:27,140 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:27,140 DEBUG [Component] seam component not found: org.jboss.seam.security
              08:17:27,140 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
              08:17:27,140 DEBUG [ExtendedPersistenceContextPropagationInterceptor] ++++ LongLivedSessionPropagationInterceptor
              08:17:27,140 DEBUG [AbstractEntityManagerImpl] Looking for a JTA transaction to join
              08:17:27,140 DEBUG [JDBCContext] successfully registered Synchronization
              08:17:27,218 DEBUG [RootInterceptor] intercepted: paymentBean.pollPaymentStatus
              08:17:27,218 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:27,218 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:27,218 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:27,218 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:27,218 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.paymentBean
              08:17:27,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:27,312 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:27,390 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:27,390 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.paymentBean
              08:17:27,390 DEBUG [Component] injecting dependencies of: paymentBean
              08:17:27,390 DEBUG [Component] trying to inject with hierarchical context search: cardTypeDao
              08:17:27,390 DEBUG [Component] instantiating Seam component: cardTypeDao
              08:17:27,390 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,468 DEBUG [Component] trying to inject with hierarchical context search: orderDao
              08:17:27,468 DEBUG [Component] instantiating Seam component: orderDao
              08:17:27,468 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,468 DEBUG [Component] trying to inject with hierarchical context search: eventTypeDao
              08:17:27,468 DEBUG [Component] instantiating Seam component: eventTypeDao
              08:17:27,546 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,546 DEBUG [Component] trying to inject with hierarchical context search: addressDao
              08:17:27,546 DEBUG [Component] instantiating Seam component: addressDao
              08:17:27,546 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,671 DEBUG [Component] trying to inject with hierarchical context search: addressTypeDao
              08:17:27,671 DEBUG [Component] instantiating Seam component: addressTypeDao
              08:17:27,671 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,671 DEBUG [Component] trying to inject with hierarchical context search: paymentHandler
              08:17:27,671 DEBUG [Component] instantiating Seam component: paymentHandler
              08:17:27,750 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:27,750 DEBUG [Component] trying to inject with hierarchical context search: facesContext
              08:17:27,750 DEBUG [SeamVariableResolver] resolving name: org
              08:17:27,750 DEBUG [Component] seam component not found: org
              08:17:27,750 DEBUG [SeamVariableResolver] could not resolve name
              08:17:27,750 DEBUG [Component] seam component not found: org.jboss
              08:17:27,828 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:27,828 DEBUG [Component] seam component not found: org.jboss.seam.core
              08:17:27,828 DEBUG [Contexts] found in application context: org.jboss.seam.core.facesContext
              08:17:27,828 DEBUG [Component] trying to inject with hierarchical context search: currentUser
              08:17:27,828 DEBUG [Contexts] found in session context: currentUser
              08:17:27,828 DEBUG [Component] trying to inject with hierarchical context search: order
              08:17:27,828 DEBUG [Contexts] found in conversation context: order
              08:17:28,437 DEBUG [Component] trying to inject with hierarchical context search: billingAddress
              08:17:28,437 DEBUG [Contexts] found in conversation context: billingAddress
              08:17:28,437 DEBUG [Component] selected row: com.ripuk.model.CardType@16bbe53
              08:17:28,437 DEBUG [Component] selected row: 01
              08:17:28,437 DEBUG [Component] selected row: 2007
              08:17:28,437 DEBUG [Component] outjecting dependencies of: paymentBean
              08:17:28,437 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:28,546 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.billingAddress
              08:17:28,625 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:28,625 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.billingAddress
              08:17:28,734 DEBUG [Component] disinjecting dependencies of: paymentBean
              08:17:28,734 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:28,734 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:28,734 DEBUG [SeamPhaseListener] after phase: INVOKE_APPLICATION(5)
              08:17:28,734 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:28,812 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:28,812 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:28,812 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
              08:17:28,812 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:28,812 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:28,890 DEBUG [AbstractSeamPhaseListener] committing transaction after phase: INVOKE_APPLICATION(5)
              08:17:28,890 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:28,890 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
              08:17:28,890 DEBUG [AbstractFlushingEventListener] dirty checking collections
              08:17:28,890 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#11], was: [com.ripuk.model.Address.orderAddresses#11] (uninitialized)
              08:17:28,984 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#12], was: [com.ripuk.model.Address.orderAddresses#12] (uninitialized)
              08:17:28,984 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#52], was: [com.ripuk.model.Address.orderAddresses#52] (uninitialized)
              08:17:28,984 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#53], was: [com.ripuk.model.Address.orderAddresses#53] (uninitialized)
              08:17:28,984 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#54], was: [com.ripuk.model.Address.orderAddresses#54] (uninitialized)
              08:17:29,062 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#56], was: [com.ripuk.model.Address.orderAddresses#56] (uninitialized)
              08:17:29,062 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#57], was: [com.ripuk.model.Address.orderAddresses#57] (uninitialized)
              08:17:29,062 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#60], was: [com.ripuk.model.Address.orderAddresses#60] (uninitialized)
              08:17:29,062 DEBUG [Collections] Collection found: [com.ripuk.model.Address.orderAddresses#61], was: [com.ripuk.model.Address.orderAddresses#61] (uninitialized)
              08:17:29,140 DEBUG [Collections] Collection found: [com.ripuk.model.AddressType.orderAddresses#1], was: [com.ripuk.model.AddressType.orderAddresses#1] (uninitialized)
              08:17:29,140 DEBUG [Collections] Collection found: [com.ripuk.model.EventType.orderEvents#1], was: [com.ripuk.model.EventType.orderEvents#1] (uninitialized)
              08:17:29,140 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderAddresses#10], was: [com.ripuk.model.Order.orderAddresses#10] (initialized)
              08:17:29,140 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderEvents#10], was: [com.ripuk.model.Order.orderEvents#10] (initialized)
              08:17:29,218 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderQuantities#10], was: [com.ripuk.model.Order.orderQuantities#10] (initialized)
              08:17:29,218 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderFormats#10], was: [com.ripuk.model.Order.orderFormats#10] (initialized)
              08:17:29,218 DEBUG [Collections] Collection found: [com.ripuk.model.Order.orderMedia#10], was: [com.ripuk.model.Order.orderMedia#10] (initialized)
              08:17:29,218 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 27 objects
              08:17:29,312 DEBUG [AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 16 collections
              08:17:29,312 DEBUG [Printer] listing entities:
              08:17:29,312 DEBUG [Printer] com.ripuk.model.Address{id=12, phoneNumber=null, county=Gloucestershire, organisation=Cheltenham Clocks, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 2LB, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=16a Lansdown Place Lane}
              08:17:29,312 DEBUG [Printer] com.ripuk.model.Address{id=11, phoneNumber=null, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=1 Imperial Gate}
              08:17:29,421 DEBUG [Printer] com.ripuk.model.OrderQuantity{id=11, price=67.5, order=com.ripuk.model.Order#10, name=You, quantity=50}
              08:17:29,421 DEBUG [Printer] com.ripuk.model.Order{id=10, totalQuantity=50, orderFormats=[com.ripuk.model.OrderFormat#10], created=2007-03-15 08:10:46, orderEvents=[com.ripuk.model.OrderEvent#9], unitRate=1.35, orderMedia=[com.ripuk.model.OrderMedia#13], orderAddresses=[com.ripuk.model.OrderAddress#17, com.ripuk.model.OrderAddress#18], lastOrderEvent=com.ripuk.model.OrderEvent#9, orderQuantities=[com.ripuk.model.AbstractOrderQuantity#11], user=com.ripuk.model.User#1, totalPrice=67.5}
              08:17:29,500 DEBUG [Printer] com.ripuk.model.Address{id=54, phoneNumber=07967 56 56 42, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=12 Imperial Gate}
              08:17:29,500 DEBUG [Printer] com.ripuk.model.Address{id=53, phoneNumber=07967 56 56 42, county=Addresshire, organisation=Manual Address, orderAddresses=<uninitialized>, town=Address Town, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=123 Address Land}
              08:17:29,578 DEBUG [Printer] com.ripuk.model.OrderFormat{id=10, price=0.0, order=com.ripuk.model.Order#10, isDefault=true, audioFormatOption=com.ripuk.model.AudioFormatOption#15}
              08:17:29,578 DEBUG [Printer] com.ripuk.model.Address{id=52, phoneNumber=07967 56 56 42, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=8 Imperial Gate}
              08:17:29,593 DEBUG [Printer] com.ripuk.model.OrderAddress{id=17, order=com.ripuk.model.Order#10, address=com.ripuk.model.Address#11, addressType=com.ripuk.model.AddressType#2}
              08:17:29,671 DEBUG [Printer] com.ripuk.model.OrderAddress{id=18, order=com.ripuk.model.Order#10, address=com.ripuk.model.Address#11, addressType=com.ripuk.model.AddressType#1}
              08:17:29,671 DEBUG [Printer] com.ripuk.model.OrderEvent{collectionTime=null, timestamp=2007-03-15 08:17:11, id=9, estimatedDelivery=null, trackingUrl=null, trackingNumber=null, order=com.ripuk.model.Order#10, actualQuantity=null, eventType=com.ripuk.model.EventType#1, collectionDate=null, returnQuantity=null}
              08:17:29,671 DEBUG [Printer] com.ripuk.model.AddressType{id=1, orderAddresses=<uninitialized>, descr=Billing}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.CardType{id=9, name=Delta}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.CardType{id=8, name=Visa Electron}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.CardType{id=7, name=Diners}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.OrderMedia{id=13, price=0.0, order=com.ripuk.model.Order#10, playerModel=null, mediaOption=com.ripuk.model.MediaOption#1, mediaHardDisk=null}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.CardType{id=6, name=Switch/Maestro}
              08:17:29,796 DEBUG [Printer] com.ripuk.model.CardType{id=5, name=Solo}
              08:17:29,890 DEBUG [Printer] com.ripuk.model.Address{id=60, phoneNumber=null, county=Gloucestershire, organisation=, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 1PR, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=1 Imperial Gate}
              08:17:29,890 DEBUG [Printer] com.ripuk.model.CardType{id=4, name=JCB}
              08:17:29,890 DEBUG [Printer] com.ripuk.model.Address{id=61, phoneNumber=null, county=Gloucestershire, organisation=Cheltenham Clocks, orderAddresses=<uninitialized>, town=CHELTENHAM, addressLine4=null, postcode=GL50 2LB, addressLine3=null, addressLine2=null, user=com.ripuk.model.User#1, addressLine1=16a Lansdown Place Lane}
              08:17:29,968 DEBUG [Printer] more......
              08:17:29,968 DEBUG [ConnectionManager] aggressively releasing JDBC connection
              08:17:29,968 DEBUG [SeamPhaseListener] before phase: RENDER_RESPONSE(6)
              08:17:29,968 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:29,968 DEBUG [AbstractSeamPhaseListener] beginning transaction prior to phase: RENDER_RESPONSE(6)
              08:17:29,968 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:30,046 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,046 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.conversationList
              08:17:30,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,140 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.conversationList
              08:17:30,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,234 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.switcher
              08:17:30,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,328 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.switcher
              08:17:30,421 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,421 DEBUG [Events] Processing event:org.jboss.seam.preRemoveVariable.org.jboss.seam.core.conversationStack
              08:17:30,515 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,515 DEBUG [Events] Processing event:org.jboss.seam.postRemoveVariable.org.jboss.seam.core.conversationStack
              08:17:30,593 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:30,593 DEBUG [Component] seam component not found: org.jboss.seam.persistence.persistenceProvider
              08:17:30,593 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,593 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,593 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,593 DEBUG [Events] Processing event:org.jboss.seam.beforePhase
              08:17:30,687 DEBUG [SeamVariableResolver] resolving name: identity
              08:17:30,687 DEBUG [SeamVariableResolver] resolving name: org
              08:17:30,687 DEBUG [Component] seam component not found: org
              08:17:30,687 DEBUG [SeamVariableResolver] could not resolve name
              08:17:30,687 DEBUG [Component] seam component not found: org.jboss
              08:17:30,687 DEBUG [Component] seam component not found: org.jboss.seam
              08:17:30,687 DEBUG [Component] seam component not found: org.jboss.seam.security
              08:17:30,687 DEBUG [Contexts] found in session context: org.jboss.seam.security.identity
              08:17:30,750 DEBUG [SeamVariableResolver] resolved name to Seam component
              08:17:30,750 DEBUG [SeamPhaseListener] after phase: RENDER_RESPONSE(6)
              08:17:30,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,750 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,750 DEBUG [Events] Processing event:org.jboss.seam.afterPhase
              08:17:30,750 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:30,875 DEBUG [AbstractSeamPhaseListener] committing transaction after phase: RENDER_RESPONSE(6)
              08:17:30,875 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:30,875 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:30,875 DEBUG [Manager] Storing conversation state: 4
              08:17:30,875 DEBUG [Lifecycle] After render response, destroying contexts
              08:17:30,953 DEBUG [Lifecycle] destroying business process context
              08:17:30,953 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,953 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,953 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:30,953 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:30,953 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:30,953 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,031 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
              08:17:31,031 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,031 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,031 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,031 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,031 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,125 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,125 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.BUSINESS_PROCESS
              08:17:31,125 DEBUG [Lifecycle] flushing server-side conversation context
              08:17:31,125 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:31,125 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:31,218 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:31,218 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:31,218 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:17:31,218 DEBUG [Contexts] found in conversation context: org.jboss.seam.core.persistenceContexts
              08:17:31,312 DEBUG [Lifecycle] flushing session context
              08:17:31,312 DEBUG [Lifecycle] destroying event context
              08:17:31,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,312 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,312 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,312 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,312 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,390 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,390 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.EVENT
              08:17:31,390 DEBUG [Contexts] destroying: org.ajax4jsf.framework.HEADER_PROCESSED
              08:17:31,390 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.webapp.AdfacesFilterImpl.EXECUTED
              08:17:31,390 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.dispatch.DispatchResponseConfiguratorImpl.APPLIED
              08:17:31,390 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.AdfFacesPhaseListener.CREATED_CONTEXT
              08:17:31,468 DEBUG [Contexts] destroying: facelets.Encoding
              08:17:31,468 DEBUG [Contexts] destroying: org.jboss.seam.core.validation
              08:17:31,468 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,468 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,468 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,468 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,468 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,546 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,546 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.validation
              08:17:31,546 DEBUG [Contexts] destroying: org.jboss.seam.core.manager
              08:17:31,546 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,546 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,546 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,546 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:31,625 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:31,625 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:31,625 DEBUG [Events] Processing event:org.jboss.seam.preDestroy.org.jboss.seam.core.manager
              08:17:31,625 DEBUG [Contexts] destroying: org.ajax4jsf.framework.HEADER_SCRIPTS
              08:17:31,625 DEBUG [Contexts] destroying: org.ajax4jsf.VIEW_STATE_SAVED
              08:17:31,625 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.renderkit.CACHED_SERIALIZED_VIEW
              08:17:31,718 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.InitialViewRoot
              08:17:31,718 DEBUG [Contexts] destroying: com.sun.facelets.legacy.ELCONTEXT
              08:17:31,718 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.GlobalConfiguratorImpl.IN_REQUEST
              08:17:31,718 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.application.CachedSerializedView
              08:17:31,718 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.CachedRequestContext
              08:17:31,718 DEBUG [Contexts] destroying: com.exade.vcp.Filter.done
              08:17:32,406 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.config.GlobalConfiguratorImpl.REQUEST_TYPE
              08:17:32,406 DEBUG [Contexts] destroying: org.ajax4jsf.areas.rendered
              08:17:32,406 DEBUG [Contexts] destroying: org.apache.myfaces.trinidadinternal.context.PageFlowScope
              08:17:32,406 DEBUG [Contexts] destroying: ajaxContext
              08:17:32,406 DEBUG [Contexts] destroying: com.exade.vcp.Filter.ResponseWrapper
              08:17:32,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:17:32,515 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.EVENT
              08:17:32,515 DEBUG [Lifecycle] <<< End web request
              08:17:32,640 DEBUG [Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
              08:19:31,812 DEBUG [StatefulSessionFilePersistenceManager] Attempting to passivate; id=5c4o21e-lxeado-ezax6u4j-1-ezaxahf4-k
              08:19:31,812 DEBUG [Lifecycle] >>> Begin call
              08:19:31,812 DEBUG [RootInterceptor] intercepted: orderFormatBean.PRE_PASSIVATE
              08:19:31,812 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:31,812 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:31,812 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:31,812 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:31,812 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.SESSION
              08:19:31,906 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:31,906 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:31,984 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:31,984 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.SESSION
              08:19:31,984 DEBUG [Lifecycle] destroying business process context
              08:19:31,984 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:31,984 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:31,984 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:31,984 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,062 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,062 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,062 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
              08:19:32,062 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,062 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,062 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,140 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.BUSINESS_PROCESS
              08:19:32,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.manager
              08:19:32,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.manager
              08:19:32,234 DEBUG [Component] done initializing: org.jboss.seam.core.manager
              08:19:32,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,328 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.manager
              08:19:32,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,406 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,406 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,406 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.manager
              08:19:32,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,406 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,406 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,484 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,484 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,484 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.manager
              08:19:32,484 DEBUG [Lifecycle] destroying conversation context
              08:19:32,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,484 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,562 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.CONVERSATION
              08:19:32,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,656 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.CONVERSATION
              08:19:32,750 DEBUG [Lifecycle] flushing server-side conversation context
              08:19:32,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.conversationEntries
              08:19:32,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.conversationEntries
              08:19:32,750 DEBUG [Component] done initializing: org.jboss.seam.core.conversationEntries
              08:19:32,750 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,750 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,843 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,843 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,843 DEBUG [Events] Processing event:org.jboss.seam.preSetVariable.org.jboss.seam.core.conversationEntries
              08:19:32,843 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,906 DEBUG [StatefulSessionFilePersistenceManager] Attempting to passivate; id=5c4o21e-lxeado-ezax6u4j-1-ezaxa9a5-i
              08:19:32,937 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:32,953 DEBUG [Lifecycle] >>> Begin call
              08:19:32,953 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:32,953 DEBUG [RootInterceptor] intercepted: orderQuantityBean.PRE_PASSIVATE
              08:19:32,953 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,953 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:32,953 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,046 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,046 DEBUG [Events] Processing event:org.jboss.seam.postSetVariable.org.jboss.seam.core.conversationEntries
              08:19:33,046 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,046 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,046 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,140 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.SESSION
              08:19:33,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,234 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,234 DEBUG [Events] Processing event:org.jboss.seam.postCreate.org.jboss.seam.core.conversationEntries
              08:19:33,234 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,234 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,234 DEBUG [Lifecycle] flushing session context
              08:19:33,328 DEBUG [Lifecycle] destroying event context
              08:19:33,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,328 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,328 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,328 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,406 DEBUG [Events] Processing event:org.jboss.seam.postDestroyContext.SESSION
              08:19:33,406 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,406 DEBUG [Lifecycle] destroying business process context
              08:19:33,406 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,406 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,421 DEBUG [StatefulSessionFilePersistenceManager] Attempting to passivate; id=5c4o21e-lxeado-ezax6u4j-1-ezaxakvo-l
              08:19:33,406 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.EVENT
              08:19:33,484 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,484 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,484 DEBUG [Lifecycle] >>> Begin call
              08:19:33,484 DEBUG [Contexts] destroying: org.jboss.seam.core.manager
              08:19:33,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,484 DEBUG [RootInterceptor] intercepted: orderStorageBean.PRE_PASSIVATE
              08:19:33,484 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] initializing new instance of: org.jboss.seam.core.events
              08:19:33,562 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,656 DEBUG [Component] done initializing: org.jboss.seam.core.events
              08:19:33,656 DEBUG [Events] Processing event:org.jboss.seam.preDestroyContext.BUSINESS_PROCESS
              08:19:33,656 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,656 DEBUG [Component] instantiating Seam component: org.jboss.seam.core.events
              08:19:33,656 DEBUG [Component] initializing new instance of: org.jboss.seam.core.


              • 4. Re: @Restrict preventing @Asynchronous method from execution
                Shane Bryzak Master

                Those logs don't really help. I suggest you raise an issue in JIRA (assign it to me) with a working example if possible.