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

send_file_not_found() very inefficient - we should be able to bypass for some SCORM packages

    Details

    • Testing Instructions:
      Hide

      I have a commercial SCORM package provided from Skillsoft(thanks Martin) that can be shared with integrator/tester that purposely generates a bunch of 404 errors but this can't be shared publicly on the tracker issue - please contact me for details.

      Load the SCORM package provided that generates 404's during load.
      Check to see how long it takes to load without the patch in place and with the patch in place - load time should be a lot quicker with the patch in place.

      Show
      I have a commercial SCORM package provided from Skillsoft(thanks Martin) that can be shared with integrator/tester that purposely generates a bunch of 404 errors but this can't be shared publicly on the tracker issue - please contact me for details. Load the SCORM package provided that generates 404's during load. Check to see how long it takes to load without the patch in place and with the patch in place - load time should be a lot quicker with the patch in place.
    • Affected Branches:
      MOODLE_21_STABLE
    • Fixed Branches:
      MOODLE_21_STABLE, MOODLE_22_STABLE
    • Pull Master Branch:
      master_MDL-32147

      Description

      Reported and traced by Martin Holden from Skillsoft - thanks Martin!

      when print_error() is called inside send_file_not_found() this appears to make the 404 response insanely slow.
      commenting it out results in a much faster response to the server - I haven't looked at the code yet - does filelib do an ob_start() before calling send_file_not_found? - do we need to keep the friendly error at all?

      function send_file_not_found() {
         //global $CFG, $COURSE;
         header('HTTP/1.0 404 not found');
         //print_error('filenotfound', 'error', $CFG->wwwroot.'/course/view.php?id='.$COURSE->id);
        die;
      }

        Gliffy Diagrams

          Activity

          Hide
          skodak Petr Skoda added a comment -

          We could probably use bootstrap_renderer instead of full renderer. Hopefully there should not be many broken links pointing to new pluginfile.php because teachers can not copy/paste them any more.

          I am a bit afraid that some users might view it less user friendly if we did not displayed fully themed error page there. Alternatively we could make it optional via 'config-dist.php'...

          Show
          skodak Petr Skoda added a comment - We could probably use bootstrap_renderer instead of full renderer. Hopefully there should not be many broken links pointing to new pluginfile.php because teachers can not copy/paste them any more. I am a bit afraid that some users might view it less user friendly if we did not displayed fully themed error page there. Alternatively we could make it optional via 'config-dist.php'...
          Hide
          danmarsden Dan Marsden added a comment -

          Hi Petr - this was discovered while using a SCORM package that has some internal checks to see if a file exists in the package and failover to default if the files don't exist - if you load the package via an unzipped directory on apache it took 20sec to load the scorm - if you loaded it via pluginfile it took 52sec to load. This is a pretty big performance hit/delay on the server side which seems to be related to the call to print_error() - something funky is definitely going on there.

          Show
          danmarsden Dan Marsden added a comment - Hi Petr - this was discovered while using a SCORM package that has some internal checks to see if a file exists in the package and failover to default if the files don't exist - if you load the package via an unzipped directory on apache it took 20sec to load the scorm - if you loaded it via pluginfile it took 52sec to load. This is a pretty big performance hit/delay on the server side which seems to be related to the call to print_error() - something funky is definitely going on there.
          Hide
          danmarsden Dan Marsden added a comment -

          here's some stats from Martin on a single 404 response from moodle:
          ACTUAL PERFORMANCE
          --------------

          ClientConnected: 10:25:03.990
          ClientBeginRequest: 10:25:03.990
          GotRequestHeaders: 10:25:03.990
          ClientDoneRequest: 10:25:03.990
          Determine Gateway: 0ms
          DNS Lookup: 0ms
          TCP/IP Connect: 0ms
          HTTPS Handshake: 0ms
          ServerConnected: 10:20:40.922
          FiddlerBeginRequest: 10:25:03.990 <-- When request sent
          ServerGotRequest: 10:25:03.990
          ServerBeginResponse: 10:25:05.260
          GotResponseHeaders: 10:25:05.260
          ServerDoneResponse: 10:25:21.614 <-- When Server "closed" connection
          ClientBeginResponse: 10:25:05.260
          ClientDoneResponse: 10:25:21.614

          Overall Elapsed: 0:00:17.623

          Show
          danmarsden Dan Marsden added a comment - here's some stats from Martin on a single 404 response from moodle: ACTUAL PERFORMANCE -------------- ClientConnected: 10:25:03.990 ClientBeginRequest: 10:25:03.990 GotRequestHeaders: 10:25:03.990 ClientDoneRequest: 10:25:03.990 Determine Gateway: 0ms DNS Lookup: 0ms TCP/IP Connect: 0ms HTTPS Handshake: 0ms ServerConnected: 10:20:40.922 FiddlerBeginRequest: 10:25:03.990 <-- When request sent ServerGotRequest: 10:25:03.990 ServerBeginResponse: 10:25:05.260 GotResponseHeaders: 10:25:05.260 ServerDoneResponse: 10:25:21.614 <-- When Server "closed" connection ClientBeginResponse: 10:25:05.260 ClientDoneResponse: 10:25:21.614 Overall Elapsed: 0:00:17.623
          Hide
          danmarsden Dan Marsden added a comment -

          should point out those stats aren't from mine or Martins server so it's possible some tuning on the server would help, but the fact that commenting out print_error makes such a big changes points to Moodle as being part of the issue.

          Show
          danmarsden Dan Marsden added a comment - should point out those stats aren't from mine or Martins server so it's possible some tuning on the server would help, but the fact that commenting out print_error makes such a big changes points to Moodle as being part of the issue.
          Hide
          skodak Petr Skoda added a comment -

          Could I have some test package? I guess in case of SCORM we do not need any user friendliness at all, we might add a new $extra_fast_minimal_info parameter to send_file_not_found() and use it in SCORM and other places where we do not expect users to open the files directly in browser.

          We should also do something with perf of $OUTPUT->header().

          Show
          skodak Petr Skoda added a comment - Could I have some test package? I guess in case of SCORM we do not need any user friendliness at all, we might add a new $extra_fast_minimal_info parameter to send_file_not_found() and use it in SCORM and other places where we do not expect users to open the files directly in browser. We should also do something with perf of $OUTPUT->header().
          Hide
          danmarsden Dan Marsden added a comment -

          that sounds like a really good idea! - I'll check with Martin to see if he is able to share a package - may not be able to due to licensing etc.

          Show
          danmarsden Dan Marsden added a comment - that sounds like a really good idea! - I'll check with Martin to see if he is able to share a package - may not be able to due to licensing etc.
          Hide
          danmarsden Dan Marsden added a comment -

          Just took a closer look at the code - we should be able to handle 404s better in scorm_pluginfile - instead of returning false when a file isn't found we could check if it was a content request and just return a standard 404

          Show
          danmarsden Dan Marsden added a comment - Just took a closer look at the code - we should be able to handle 404s better in scorm_pluginfile - instead of returning false when a file isn't found we could check if it was a content request and just return a standard 404
          Hide
          danmarsden Dan Marsden added a comment -

          here's a possible patch - haven't tested it to see if it fixes the issue, but Petr could you please review it to make sure I'm not doing anything invalid here?

          Show
          danmarsden Dan Marsden added a comment - here's a possible patch - haven't tested it to see if it fixes the issue, but Petr could you please review it to make sure I'm not doing anything invalid here?
          Hide
          skodak Petr Skoda added a comment -

          The patch looks ok.

          Another idea: is it technically possible to add caching headers to 404 (do browsers support it)? The files can not appear in the future because we use revisions in file path.

          Show
          skodak Petr Skoda added a comment - The patch looks ok. Another idea: is it technically possible to add caching headers to 404 (do browsers support it)? The files can not appear in the future because we use revisions in file path.
          Hide
          danmarsden Dan Marsden added a comment -

          just went looking for caching headers on 404 (didn't find anything) - but did find we're supposed to use a different call for fastcgi - wonder if that is part of the issue...
          header("Status: 404 Not Found");

          http://php.net/manual/en/function.header.php

          Show
          danmarsden Dan Marsden added a comment - just went looking for caching headers on 404 (didn't find anything) - but did find we're supposed to use a different call for fastcgi - wonder if that is part of the issue... header("Status: 404 Not Found"); http://php.net/manual/en/function.header.php
          Hide
          danmarsden Dan Marsden added a comment -

          I've added a new function to filelib that checks if fastcgi is being used and if so, passes correct 404 header - if this is ok we should probably do a search through all uses of 404 and change them.

          But - I really want to get a patch for SCORM into this coming weeks integration, so if by changing core usage of 404 holds this up then we can push the original commit in first and then look at the 404 headers on a different bug.

          Show
          danmarsden Dan Marsden added a comment - I've added a new function to filelib that checks if fastcgi is being used and if so, passes correct 404 header - if this is ok we should probably do a search through all uses of 404 and change them. But - I really want to get a patch for SCORM into this coming weeks integration, so if by changing core usage of 404 holds this up then we can push the original commit in first and then look at the 404 headers on a different bug.
          Hide
          ankit_frenz Ankit Agarwal added a comment -

          Looks good
          +1 to integrate.

          The new APi changes should go in master only IMHO, will leave it to the integrators to decide.

          Thanks

          Show
          ankit_frenz Ankit Agarwal added a comment - Looks good +1 to integrate. The new APi changes should go in master only IMHO, will leave it to the integrators to decide. Thanks
          Hide
          samhemelryk Sam Hemelryk added a comment -

          Hi Dan, this has been integrated now.
          I did choose to backport this as the new function is stand alone and is fixing a fastcgi issue (without changing more code than required).

          Cheers
          Sam

          Show
          samhemelryk Sam Hemelryk added a comment - Hi Dan, this has been integrated now. I did choose to backport this as the new function is stand alone and is fixing a fastcgi issue (without changing more code than required). Cheers Sam
          Hide
          rwijaya Rossiani Wijaya added a comment -

          Hi Dan,

          I couldn't save the scorm setting with the file you sent me, while Ankit manages to save it within 2-3 minutes for integration and 4-5 minutes for stables.

          Then while he entered the scorm page, both branches stay on loading page for a long time.

          We are not quite sure how to test this or if we do this correctly.

          could you advise us on this?

          Thanks

          Show
          rwijaya Rossiani Wijaya added a comment - Hi Dan, I couldn't save the scorm setting with the file you sent me, while Ankit manages to save it within 2-3 minutes for integration and 4-5 minutes for stables. Then while he entered the scorm page, both branches stay on loading page for a long time. We are not quite sure how to test this or if we do this correctly. could you advise us on this? Thanks
          Hide
          ankit_frenz Ankit Agarwal added a comment -

          It takes around 12 seconds in my system to load with the patch and without the patch it just kept loading even after 2-3 mins

          So passing this.
          Thanks

          Show
          ankit_frenz Ankit Agarwal added a comment - It takes around 12 seconds in my system to load with the patch and without the patch it just kept loading even after 2-3 mins So passing this. Thanks
          Hide
          stronk7 Eloy Lafuente (stronk7) added a comment -

          And this has landed upstream, finally! Yay!

          תודה רבה && شكرا جزيلا



          Closing, ciao

          Show
          stronk7 Eloy Lafuente (stronk7) added a comment - And this has landed upstream, finally! Yay! תודה רבה && شكرا جزيلا Closing, ciao

            People

            • Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:
                Fix Release Date:
                14/May/12