Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-64543

Have ability to conditionally profile only slow pages using xhprof / tideways

    XMLWordPrintable

    Details

    • Testing Instructions:
      Hide

      Requirements: The server must have the tideways xhprof extension installed.

      1) Go to /admin/settings.php?section=profiling and enable profiling and also Set profilingslow to 0.5 seconds

      2) Randomly click around and watch what gets stored in the profiling runs page: /admin/tool/profiling/index.php

      3) Also test the scenario where a page is slow, and so should be conditionally profiled, but also should be profiled for another reason such as profilingincluded. Make sure this doesn't throw errors

      Over time you should see various slow scripts appear, and you should only see worse ones appear for a particular script, ie the Execution time will only ever go up, and these will get less and less likely over time.

      Try clearing the cache or adding a sleep(5) somewhere to force a page to behave slowly and appear in the slow log.

       

      Show
      Requirements: The server must have the tideways xhprof extension installed. 1) Go to /admin/settings.php?section=profiling and enable profiling and also Set profilingslow to 0.5 seconds 2) Randomly click around and watch what gets stored in the profiling runs page: /admin/tool/profiling/index.php 3) Also test the scenario where a page is slow, and so should be conditionally profiled, but also should be profiled for another reason such as profilingincluded. Make sure this doesn't throw errors Over time you should see various slow scripts appear, and you should only see worse ones appear for a particular script, ie the Execution time will only ever go up, and these will get less and less likely over time. Try clearing the cache or adding a sleep(5) somewhere to force a page to behave slowly and appear in the slow log.  
    • Affected Branches:
      MOODLE_37_STABLE
    • Fixed Branches:
      MOODLE_37_STABLE
    • Pull Master Branch:
      MDL-64543-slow-profile

      Description

      The existing profiling stuff is awesome, but generally either only when you have a known bug, or in the case when you can reproduce something. It's not that useful for intermittent performance issues or when there is unknown conditions for the slowness and you want to discover these in production.

      So just like slow database logs I want to add a slow page profiling:

      1) Have an admin option with a min page load threshold X

      2) If this is non zero then always kick off profiling, but only if the page is slower than X do we store it at the end. I believe the overhead of the profiling is quite minimal and it is all in the storage and processing later, we will profile the profiling to confirm this

      3) We will still honor the profile blacklist and not start the profiling if it matches. The whitelist wont matter here

      4) Generally we only need a one or a small number of bad example profiles, and running this is prod with tons of traffic could make a ton of data, so I am proposing that we only store the slow profile if it wouldn't have been store for any other reason, and it also happens to be slower than all the existing profiles which we have on record for the same url. Typically I would expect to collect a couple instances of a particular bad url, and them maybe one really bad one and then it would probably be hard to beat and we wouldn't store any more.

       

       

        Attachments

        1. config.png
          82 kB
          Víctor Déniz Falcón
        2. decreasing_times.png
          89 kB
          Eloy Lafuente (stronk7)
        3. enabled_at_configphp_grrr.png
          44 kB
          Eloy Lafuente (stronk7)
        4. image-2019-01-10-16-32-56-345.png
          71 kB
          Brendan Heywood
        5. log.png
          84 kB
          Víctor Déniz Falcón

          Issue Links

            Activity

              People

              • Votes:
                3 Vote for this issue
                Watchers:
                7 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Fix Release Date:
                  20/May/19

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 4 hours, 42 minutes
                  4h 42m