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
    • Rank:
      38871

      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;
      }
      

        Activity

        Hide
        Petr Škoda 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
        Petr Škoda 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
        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
        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
        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
        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
        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
        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
        Petr Škoda 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
        Petr Škoda 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
        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
        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
        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
        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
        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
        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
        Petr Škoda 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
        Petr Škoda 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
        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
        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
        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
        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 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 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
        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
        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
        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
        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 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 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
        Eloy Lafuente (stronk7) added a comment -

        And this has landed upstream, finally! Yay!

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



        Closing, ciao

        Show
        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: