AEM Dispatcher - Different Response Time for same Request | Community
Skip to main content
Rohan_Garg
Rohan_Garg
New Participant
November 29, 2022
Solved

AEM Dispatcher - Different Response Time for same Request

  • November 29, 2022
  • 2 replies
  • 2588 views

Hi All,

 

I have the below scenario occurring for the STAGE environment -

The response time & its caching action from dispatcher for home page requests varies greatly.

 

From the AEM dispatcher logs we have the below info -

[29/Nov/2022:01:31:49] [I] "GET /content/brandA/us/en/home.html" -7728ms [publishfarm/0] [actionmiss] stage.brandA.com
[29/Nov/2022:02:16:19] [I] "GET /content/brandA/us/en/home.html" -5857ms [publishfarm/0] [actionmiss] stage.brandA.com
[29/Nov/2022:02:16:23] [I] "GET /content/brandA/us/en/home.html" [publishfarm/0] [actionnone] stage.brandA.com
[29/Nov/2022:02:16:56] [I] "GET /content/brandA/us/en/home.html" -3ms [publishfarm/-] [actionhit] stage.brandA.com
[29/Nov/2022:02:28:02] [I] "GET /content/brandA/us/en/home.html" -3ms [publishfarm/-] [actionhit] stage.brandA.com
[29/Nov/2022:02:31:26] [I] "GET /content/brandA/us/en/home.html" -1886ms [publishfarm/0] [actionmiss] stage.brandA.com
[29/Nov/2022:05:05:41] [I] "GET /content/brandA/us/en/home.html" -5ms [publishfarm/-] [actionhit] stage.brandA.com
[29/Nov/2022:06:32:48] [I] "GET /content/brandA/us/en/home.html" -3ms [publishfarm/-] [actionhit] stage.brandA.com
[29/Nov/2022:07:35:17] [I] "GET /content/brandA/us/en/home.html" 2002280ms [publishfarm/0] [actionnone] stage.brandA.com

 

As you can see for the same domain the requests are getting served in 3 ways-

1. [actionhit] indicating 4/9 requests were cached are being served in 3-5ms by publishfarm/-

2. [actionmiss] indicating 3/9 requests were not cached taking varying time - 1.88s, 5.8s, 7.7s by publishfarm/0

3. [actionone] indicating 2/9 requests were not to be cached and took more than 2000s / 30m to be served by publishfarm/0.

 

Any help on why such a varying response time for the same request URL and for same domain stage.brandA.com ?

@mohit_kbansal, @joerghoh, @arunpatidar, @b_sravan, @kautuk_sahni 

 

Thanks,

Rohan Garg

    This post is no longer active and is closed to new replies. Need help? Start a new post to ask your question.
    Best answer by Rohan_Garg

    I am not sure, if this is responsible
    Try to get request log and rlog.jar utility in local, to see which are the time consuming request.


    @arunpatidar - The issue seems to be similar to the one with /favicon requests.

    The STAGE environment has higher % of long processing time requests but even that time might not be accurate as seen with /favicon.

     

    After our go live yesterday, I pulled in the logs for homepage requests and came up with below observations -

    #1. On PROD, The slow running requests are 40 out of total 1372 which accounts for like 3%. All these requests have [actionnone] and are showing response time of +2000000ms or 33.3 min.
    These requests have one similarity - All these requests are followed by really long query parameter strings which are most likely associated with couple of Google Tag Manager Scripts, Pixel Scripts and others which are embedded on our HTML.
    ?fbclid=, ?mm_campaign=,
    Only one request with simple query parameter had a long processing time -

    GET /content/brandsA/us/en/home.html?kdhfjdf" 2001428ms [publishfarm/0] [actionnone] brandsA.com

    This again might not be 100% accurate as seen in /favicon requests even though icon loads in seconds, the request gets logged as taking long time.

     

    #2. The other 1332 requests, are classified as below -

    1317 requests have [actionhit] and response time < 5 ms - That's 98.9%.


    #3. 14 requests have [actionmiss] and response time in range 1.4s to 2.8s which should be acceptable I think.

     

    Hence, I am marking this issue as closed for now. The number of requests which are slow is low and all seem to be associated with 3rd party tracking scripts which are expected to increase the page load time. Also, the 33.3m stat might not be the most reliable factor as there are instances when request got served in seconds but still got logged for 33.3m.

     

    Thank you for you help @arunpatidar !

     

    2 replies

    joerghoh
    joerghoh
    Employee
    December 3, 2022

    There could be many reasons for that, although 30min rather point to a more general problem. What about the performance of the other requests on the same dispatcher/AEM publish, were they slow in the same way?

      Rohan_Garg
      Rohan_GargAuthor
      New Participant
      December 8, 2022

      Hi @joerghoh - Yes, there is one other request which is behaving this way (/favicon based).

      Also, another interesting observation is when we hit the direct request from publish or even dispatcher, the icon takes 1-2 seconds to load but the request processing time is still shown as +30m.

      I think the stat for request processing time might be inaccurate but since we validated on local that the page is getting cached, it need not be a concern from performance point of view I think.

        arunpatidar
        arunpatidar
        New Participant
        November 29, 2022

        Hi,

        I would say, check the thread dumps and error logs to check why the publish instance is slow around 7:35. Also check the other requests respond time during same time.

        You can ask Adobe to check on new relic if there were load issue.

        Arun Patidar
          Rohan_Garg
          Rohan_GargAuthor
          New Participant
          November 29, 2022

          Hi Arun, thanks for the quick response. It's always highly appreciated.

          If you check the other query thread too, this is common to multiple requests such as /favicon.ico and other website page requests that the website response time is varying greatly.

          As for the error logs, we have already validated that there are no errors, but only warnings in the system - I will try to find a pattern for any particular warning that coincides with the higher response time.

          But as seen in /favicon.ico requests, the ratio of slow response time requests to fast ones is almost 1:6 maybe, so it does not seem to be a time specific issue.

          Let me know your thoughts on this.

            Terms & ConditionsAccessibility statement

            Loading footer...