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

Fix problems reported in apache logs before 4.0 release

    XMLWordPrintable

    Details

    • Affected Branches:
      MOODLE_400_STABLE
    • Fixed Branches:
      MOODLE_400_STABLE

      Description

      Preparations

      This is about to inspect apache logs for complete behat runs and fix as many notices / problems are shown there. Aggregating information from all supported themes.

      Used this regexp against goutte and chrome webserver logs, for reference:

      ag -v 'POST|GET|OPTIONS|\] (checking plan|(saving|calculating|loading|setting) controller|(applying|loading|instantiating) (backup|restore|plan)|(activity|section) skipped|setting file inclusion|processing file aliases|Unknown setting: (questionbank|overwrite_conf|course_shortname|course_fullname|course_startdate))|Failed Login: ' aggregated.txt > results.txt
      

      (where aggregated.txt is the union of goutte and chrome web server logs of all core themes)

      Trick: When it's difficult to find which exact behat test is causing the problem, it's useful to run the tests with the --pretty command, getting the date prepended, that way later can match them with the dates in apache error logs. To do so just add the following to your behat run command:

      vendor/bin/behat ......  --format pretty --no-colors | awk '{ print strftime("%Y-%m-%d %H:%M:%S"), $0; fflush(); }'
      

      You can see the actual results @ results.txt

      Trick: Always look to previous release issue to verify if the error already was detected there and considered ok.

      Summary:

      Problem A: Cannot find session record. It happens 2 times.

      Happens in scenario "As a student, request deletion of account and data"

      48953:[Fri Apr 09 21:59:24.170459 2021] [php7:notice] [pid 2042] [client 172.25.0.3:45028] Cannot find session record 2a6ab10f130092ec1d6cbfd42d026b93 for user 104000, creating new session., referer: http://webserver8561236a31f1d360/behatrun1/user/profile.php?id=104000

      Confirmed that it's testing exactly that the session becomes has expired (see prev. release). So 100% ignorable.

      Problem B: User id 'xxxxxx' already has a grade. It happens 2 times.

      MDL-68961
      Happens with scenario "Delete and restore a quiz with user data.

      136170:[Fri Apr 09 23:25:03.534388 2021] [php7:notice] [pid 4195] [client 172.25.0.4:54750] User id '105001' already has a grade entry for grade item id '255000', referer: http://webserver8561236a31f1d360/behatrun2/admin/tool/recyclebin/index.php?contextid=101002

      Confirmed that it's trying to recreate already existing course grade (see MDL-68961 and prev. release). So 100% ignorable.

      Problem C: Cannot find session record xxx for user xx, creating new session. It happens 2 times.

      Delegated to existing MDL-68996, together with next one.
      Happens in scenario: (not always!) --tags '@mod_data' --name 'View automatic completion items as a failing student'

      290219:[Sat Oct 30 05:51:38.022002 2021] [php:notice] [pid 1878] [client 172.29.0.5:36092] Cannot find session record 932da21ab341f5bcb512a3b1da1fd135 for user 110002, creating new session., referer: http://webserver768231fe5b483824/behatrun3/mod/data/templates.php?d=196000&mode=singletemplate

      Problem D: Default exception handler: Course or activity not accessible. It happens 2 times

      Delegated to existing MDL-68996, together with previous one
      Happens in scenario: (not always!) --tags '@mod_data' --name 'View automatic completion items as a failing student'

      290220:[Sat Oct 30 05:51:38.025686 2021] [php:notice] [pid 1878] [client 172.29.0.5:36092] Default exception handler: Course or activity not accessible. Debug: You are not logged in
      Error code: requireloginerror

      Problem E: Default exception handler: Exception - Warning: Trying to access array offset on value of type bool. It happens 20 times.

      MDL-72988
      Happens in scenario: --tags '@mod_lti&&@core_completion'

      22:378831:[Sat Oct 30 06:56:32.393254 2021] [php:notice] [pid 3779] [client 172.29.0.5:42592] Default exception handler: Exception - Warning: Trying to access array offset on value of type bool in [dirroot]/mod/lti/OAuth.php on line 455 Debug:
      Error code: generalexceptionmessage

      • line 157 of /lib/behat/lib.php: Exception thrown
      • line 455 of /mod/lti/OAuth.php: call to behat_error_handler()
      • line 431 of /mod/lti/OAuth.php: call to moodle\\mod\\lti
        OAuthRequest->get_normalized_http_url()
      • line 149 of /mod/lti/OAuth.php: call to moodle\\mod\\lti
        OAuthRequest->get_signature_base_string()
      • line 519 of /mod/lti/OAuth.php: call to moodle\\mod\\lti
        OAuthSignatureMethod_HMAC->build_signature()
      • line 514 of /mod/lti/OAuth.php: call to moodle\\mod\\lti
        OAuthRequest->build_signature()
      • line 3224 of /mod/lti/locallib.php: call to moodle\\mod\\lti
        OAuthRequest->sign_request()
      • line 680 of /mod/lti/locallib.php: call to lti_sign_parameters()
      • line 714 of /mod/lti/locallib.php: call to lti_get_launch_data()
      • line 88 of /mod/lti/launch.php: call to lti_launch_tool()
        , referer: http://webserver768231fe5b483824/behatrun3/mod/lti/view.php?id=188000

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              stronk7 Eloy Lafuente (stronk7)
              Reporter:
              stronk7 Eloy Lafuente (stronk7)
              Participants:
              Component watchers:
              Andrew Lyons, Dongsheng Cai, Huong Nguyen, Jun Pataleta, Michael Hawkins, Shamim Rezaie, Simey Lameze
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: