0 Replies Latest reply on Sep 14, 2010 9:14 PM by Nick Cuneo

    Delay in Ajax Request Hitting Server

    Nick Cuneo Newbie

      Architecture: Tivoli Access Manager for security

                         4 node load balanced Weblogic 10.3.0 cluster

                         Seam 2.2.0

                         RichFaces 3.3.1

       

       

      After releasing our ajax heavy app to production we are noticing a behaviour where clients will use the app fine for 95% of the time, but then a random ajax request will just show the loading graphic on the client browser and spin for 5mins and then the request eventually comes back.

       

      Examining the server logs we can see that the client request didnt actually hit the server until the end of the 5min wait and we serviced the request almost instantly.

       

      Just shooting in the dark at the moment, but we do have the global queue enabled. Don't think this would have anything to do with it though.

       

      <context-param>
         <param-name>org.richfaces.queue.global.enabled</param-name>
         <param-value>true</param-value>
      </context-param>

       

       

      And here is an example of a link which generated an ajax request we know took a long time to process:

       

      <a:commandLink id="modelHistoryCancel" action="#{modelHistory.close()}" ajaxSingle="true" immediate="true" oncomplete="#{closeMe}" styleClass="sml-scndry-button" status="waitPanelStatus">

       

       

       

      Here is a snapshot of the request we know took 5mins on the client side, but only 488ms to process on the server side.

       

      14-Sep  15:13:16,778 [19] [26715466] INFO  [HttpRequestDebugFilter] BEGIN  [1284440651295|ba2d1439-172b-4cb1-b59a-c8664a9d3bf2]----------------------------------------
      14-Sep  15:13:16,810 [19] [26715466] DEBUG [ManagedInvestmentSearch] Executing managed  investment search using criteria [U]...
      14-Sep 15:13:16,811 [19] [26715466]  DEBUG [ModelPortfolioServiceFacadeImpl] Finding managed investments that meet  criteria [U]...
      14-Sep 15:13:16,812 [19] [26715466] DEBUG  [ModelPortfolioServiceFacadeImpl] returning cached allowable funds for bv MPM /  dealer 0001
      14-Sep 15:13:16,812 [19] [26715466] DEBUG [SecuritiesManager]  dealerRestrictions size: 1
      14-Sep 15:13:16,812 [19] [26715466] DEBUG  [SecuritiesManager] found 0 restrictions in cache with key BVDealerKey [bv=MPM,  dealer=0001]
      14-Sep 15:13:16,812 [19] [26715466] DEBUG  [ModelPortfolioServiceFacadeImpl] adding 0 restricted dealer securities for  model owner 0001
      14-Sep 15:13:16,812 [19] [26715466] DEBUG  [ModelPortfolioServiceFacadeImpl] no restrictions, gonna use cache
      14-Sep  15:13:16,813 [19] [26715466] DEBUG [ModelPortfolioServiceFacadeImpl] returning  cached entity restrictions for entity type V / entity BSPT
      14-Sep  15:13:16,813 [19] [26715466] DEBUG [SecuritiesManager] found entity restrictions  in cache for key EntityKey [entityCode=BSPT, entityType=V] now going to  filter
      14-Sep 15:13:16,813 [19] [26715466] DEBUG [SecuritiesManager] Using  queryString: U
      14-Sep 15:13:16,813 [19] [26715466] DEBUG [SecuritiesManager]  returning 0 matches
      14-Sep 15:13:16,813 [19] [26715466] DEBUG  [ModelPortfolioServiceFacadeImpl] retain 0 filtered restricted funds for model  owner BSPT entity type V
      14-Sep 15:13:16,813 [19] [26715466] DEBUG  [ModelPortfolioServiceFacadeImpl] added 0 filtered restricted funds
      14-Sep  15:13:16,813 [19] [26715466] DEBUG [ModelPortfolioServiceFacadeImpl] Executing  additional filtering on [17] managed investment securities...
      14-Sep  15:13:16,813 [19] [26715466] DEBUG [ModelPortfolioServiceFacadeImpl] Existing  instrument filter removed [0] managed investment securities.
      14-Sep  15:13:16,815 [19] [26715466] DEBUG [ModelPortfolioServiceFacadeImpl] Model  managed investment filter removed [4] managed investment securities.
      14-Sep  15:13:16,815 [19] [26715466] DEBUG [ModelPortfolioServiceFacadeImpl] Found [13]  managed investments.
      14-Sep 15:13:16,815 [19] [26715466] DEBUG  [ManagedInvestmentSearch] Found [13] managed investments.
      14-Sep 15:13:17,266  [19] [26715466] INFO  [HttpRequestDebugFilter] END  [1284440651295|ba2d1439-172b-4cb1-b59a-c8664a9d3bf2][488ms]-----------------------------------

       

       

      Any suggestions appreciated.