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

          Attachments

            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