Announcement Announcement Module
Collapse
No announcement yet.
Multiple calls to DispatcherServlet for single web request Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • Multiple calls to DispatcherServlet for single web request

    Hi

    I have a deployment specific problem occuring when installing a web app on my hosting provider (www.kattare.com).

    I noticed that when deployed a request to do a site search was being logged multiple times for a single user web request. Looking further, a single user search resulted in the search being processed 3 or 4 times on the server. The search results page is rendered fine but behind the scenes, a lot of extra work is going on. This does not happen on my development machine.

    Enabling logging on the DispatcherServlet shows that for a single user request the DispatcherServlet is being called 3 or 4 times and therefore the associated controller is being called that many times.

    I cannot find any configuration or software issue that would cause this.

    Does anyone have any advice on how to track this problem down?

    I've included the logging output for the DispatcherServlet below. This shows 3 duplicate calls to the DispatcherServlet for a single user search.

    Thanks
    Nigel

    Code:
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler map [[email protected]6d228] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping] - Looking up handler for [/search]
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@18f7386]
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Last-Modified value for [/app/search] is [-1]
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.DispatcherServlet] - DispatcherServlet with name 'cms' received request for [/app/search]
    2005-10-26 08:20:17,373 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@18f7386]
    2005-10-26 08:20:17,373 DEBUG [com.zygal.cms.web.SearchController] - Creating new command of class [com.zygal.cms.web.SearchRequest]
    2005-10-26 08:20:17,374 DEBUG [com.zygal.cms.web.SearchController] - search request: nigel test 2
    2005-10-26 08:20:17,384 DEBUG [org.springframework.web.servlet.view.ResourceBundleViewResolver] - Cached view 'searchResult_en_GB'
    2005-10-26 08:20:17,385 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Rendering view [org.springframework.web.servlet.view.tiles.TilesJstlView: name 'searchResult'; URL [searchResult]] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:17,385 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Rendering view with name 'searchResult' with model {command=com.zygal.cms.web.SearchRequest@9bad5a, results=[com.zygal.cms.domain.SearchResult@91f005, com.zygal.cms.domain.SearchResult@1250ff2, com.zygal.cms.domain.SearchResult@3a0ab1, com.zygal.cms.domain.SearchResult@940f82, com.zygal.cms.domain.SearchResult@864e43, com.zygal.cms.domain.SearchResult@17c2891, com.zygal.cms.domain.SearchResult@4b82d2, com.zygal.cms.domain.SearchResult@179d854, com.zygal.cms.domain.SearchResult@69a4cb, com.zygal.cms.domain.SearchResult@1c20eb7]} and static attributes {}
    2005-10-26 08:20:17,385 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'results' of type [java.util.ArrayList] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:17,385 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'command' of type [com.zygal.cms.web.SearchRequest] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:17,403 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Forwarded to resource [searchResult] in InternalResourceView 'searchResult'
    2005-10-26 08:20:17,403 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Successfully completed request
    2005-10-26 08:20:18,226 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler map [[email protected]6d228] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:18,226 DEBUG [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping] - Looking up handler for [/search]
    2005-10-26 08:20:18,226 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.spri[email protected]6]
    2005-10-26 08:20:18,226 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Last-Modified value for [/app/search] is [-1]
    2005-10-26 08:20:18,226 DEBUG [org.springframework.web.servlet.DispatcherServlet] - DispatcherServlet with name 'cms' received request for [/app/search]
    2005-10-26 08:20:18,227 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@18f7386]
    2005-10-26 08:20:18,228 DEBUG [com.zygal.cms.web.SearchController] - Creating new command of class [com.zygal.cms.web.SearchRequest]
    2005-10-26 08:20:18,228 DEBUG [com.zygal.cms.web.SearchController] - search request: nigel test 2
    2005-10-26 08:20:18,234 DEBUG [org.springframework.web.servlet.view.ResourceBundleViewResolver] - Cached view 'searchResult_en_US'
    2005-10-26 08:20:18,234 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Rendering view [org.springframework.web.servlet.view.tiles.TilesJstlView: name 'searchResult'; URL [searchResult]] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:18,234 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Rendering view with name 'searchResult' with model {command=com.zygal.cms.web.SearchRequest@1867df9, results=[com.zygal.cms.domain.SearchResult@b86944, com.zygal.cms.domain.SearchResult@107108e, com.zygal.cms.domain.SearchResult@cfe049, com.zygal.cms.domain.SearchResult@18e18a3, com.zygal.cms.domain.SearchResult@1f38fc6, com.zygal.cms.domain.SearchResult@1642bd6, com.zygal.cms.domain.SearchResult@179f36b, com.zygal.cms.domain.SearchResult@15bfdbd, com.zygal.cms.domain.SearchResult@6f8b2b, com.zygal.cms.domain.SearchResult@119e583]} and static attributes {}
    2005-10-26 08:20:18,234 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'results' of type [java.util.ArrayList] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,234 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'command' of type [com.zygal.cms.web.SearchRequest] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,242 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Forwarded to resource [searchResult] in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,242 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Successfully completed request
    2005-10-26 08:20:18,821 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler map [[email protected]6d228] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:18,821 DEBUG [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping] - Looking up handler for [/search]
    2005-10-26 08:20:18,821 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@18f7386]
    2005-10-26 08:20:18,821 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Last-Modified value for [/app/search] is [-1]
    2005-10-26 08:20:18,822 DEBUG [org.springframework.web.servlet.DispatcherServlet] - DispatcherServlet with name 'cms' received request for [/app/search]
    2005-10-26 08:20:18,822 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@18f7386]
    2005-10-26 08:20:18,822 DEBUG [com.zygal.cms.web.SearchController] - Creating new command of class [com.zygal.cms.web.SearchRequest]
    2005-10-26 08:20:18,822 DEBUG [com.zygal.cms.web.SearchController] - search request: nigel test 2
    2005-10-26 08:20:18,827 DEBUG [org.springframework.web.servlet.view.ResourceBundleViewResolver] - Cached view 'searchResult_en_US'
    2005-10-26 08:20:18,827 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Rendering view [org.springframework.web.servlet.view.tiles.TilesJstlView: name 'searchResult'; URL [searchResult]] in DispatcherServlet with name 'cms'
    2005-10-26 08:20:18,828 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Rendering view with name 'searchResult' with model {command=com.zygal.cms.web.SearchRequest@1c6e818, results=[com.zygal.cms.domain.SearchResult@1afb0c7, com.zygal.cms.domain.SearchResult@17f1841, com.zygal.cms.domain.SearchResult@1117a20, com.zygal.cms.domain.SearchResult@68cd79, com.zygal.cms.domain.SearchResult@89e2f1, com.zygal.cms.domain.SearchResult@92668c, com.zygal.cms.domain.SearchResult@18a9fc8, com.zygal.cms.domain.SearchResult@2515, com.zygal.cms.domain.SearchResult@182c132, com.zygal.cms.domain.SearchResult@159d510]} and static attributes {}
    2005-10-26 08:20:18,828 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'results' of type [java.util.ArrayList] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,828 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Added model object 'command' of type [com.zygal.cms.web.SearchRequest] to request in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,835 DEBUG [org.springframework.web.servlet.view.tiles.TilesJstlView] - Forwarded to resource [searchResult] in InternalResourceView 'searchResult'
    2005-10-26 08:20:18,835 DEBUG [org.springframework.web.servlet.DispatcherServlet] - Successfully completed request

  • #2
    This sounds like a network or proxy issue of some sort. Are there any proxies or something that might be able to mess things up? I never ran into this when using Spring MVC up until now.

    Maybe you can isolate the problem by setting up a simple proxy (if there isn't one already) and analyzing the request logs?

    regards,
    Alef

    Comment


    • #3
      doh!

      Thanks for the response Alef.

      As I suspected nothing to do with Spring, but also nothing to do with the deployment environment as I had thought.

      I run Adsense on the search results page and their bot hits the same url as the user's query 2 or 3 times within a second of the query. Explains why I didn't see this problem on my development machine.

      Guess I need to filter the Google Adsense bot from from my search logging if I want accurate search stats.

      Thanks again.
      Nigel

      Comment

      Working...
      X