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

Fix problems reported in apache logs before 3.7 release

XMLWordPrintable

    • MOODLE_37_STABLE
    • MOODLE_37_STABLE

      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.

      Note that we still have the 3.6 issue (MDL-64177) open, so some of the problems may belong there.

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

      ag '\[php7:' | ag -v 'backup\/(restore|backup|import)\.php|course\/(view|mod|delete)\.php|recyclebin\/index\.php

      Ciao

      Problem A: Running @atto_media tests have seen this in logs (also sometimes leading to failure in the behat run):

      [Sun May 05 11:55:58.598263 2019] [php7:notice] [pid 17415] [client 10.10.10.10:60111] Cannot find session record ou1o49le2kbgmd8pjcqsismsqe for user 2, creating new session., referer: http://10.10.10.10/~stronk7/behattesting/blog/edit.php?action=add&userid=2
      		 
      [Sun May 05 11:55:58.611778 2019] [php7:notice] [pid 17415] [client 10.10.10.10:60111] Default exception handler: Course or activity not accessible. Debug: You are not logged in\nError code: requireloginerror\n* line 2684 of /lib/moodlelib.php: require_login_exception thrown\n* line 33 of /draftfile.php: call to require_login()\n, referer: http://10.10.10.10/~stronk7/behattesting/blog/edit.php?action=add&userid=2
      		 
      [Sun May 05 11:55:58.764985 2019] [php7:notice] [pid 17860] [client 10.10.10.10:61657] Default exception handler: Course or activity not accessible. Debug: You are not logged in\nError code: requireloginerror\n* line 2684 of /lib/moodlelib.php: require_login_exception thrown\n* line 33 of /draftfile.php: call to require_login()\n, referer: http://10.10.10.10/~stronk7/behattesting/blog/edit.php?action=add&userid=2
      		 
      [Sun May 05 11:56:00.564956 2019] [php7:notice] [pid 17823] [client 10.10.10.10:61848] Default exception handler: Error writing to database Debug: ERROR:  duplicate key value violates unique constraint "q_sess_id_pk"\nDETAIL:  Key (id)=(228002) already exists.\nINSERT INTO q_sessions (state,sid,sessdata,userid,timemodified,timecreated,lastip,firstip) VALUES($1,$2,$3,$4,$5,$6,$7,$8) RETURNING id\n[array (\n  'state' => 0,\n  'sid' => 'ss15gf5os1lvt24oo6cstna4lh',\n  'sessdata' => NULL,\n  'userid' => '2',\n  'timemodified' => 1557050160,\n  'timecreated' => 1557050160,\n  'lastip' => '10.10.10.10',\n  'firstip' => '10.10.10.10',\n)]\nError code: dmlwriteexception\n* line 489 of /lib/dml/moodle_database.php: dml_write_exception thrown\n* line 248 of /lib/dml/pgsql_native_moodle_database.php: call to moodle_database->query_end()\n* line 969 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->query_end()\n* line 1017 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->insert_record_raw()\n* line 466 of /lib/classes/session/manager.php: call to pgsql_native_moodle_database->insert_record()\n* line 509 of /lib/classes/session/manager.php: call to core\\session\\manager::add_session_record()\n* line 4571 of /lib/moodlelib.php: call to core\\session\\manager::login_user()\n* line 199 of /login/index.php: call to complete_user_login()\n, referer: http://10.10.10.10/~stronk7/behattesting/login/index.php

      MDL-65594 - Problem B: Lots (>25) apache segmentation faults like:

      [Wed May 08 06:10:04.434451 2019] [core:notice] [pid 1] AH00052: child pid 399 exit signal Segmentation fault (11)

      MDL-65576 - Problem C: mod/scorm/player.php . Lots of:

      webserver_chrome:17669:[Wed May 08 06:55:07.932594 2019] [php7:notice] [pid 563] [client 172.21.0.21:35100] Default exception handler: Invalid course module ID Debug: \nError code: invalidcoursemodule\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 27 of /mod/scorm/datamodel.php: call to print_error()\n, referer: http://run2af307a796fecb0b/behatrun3/mod/scorm/player.php

      Problem D: badges/newbadge.php . A good number of:

      webserver_chrome:24931:[Wed May 08 07:16:49.244778 2019] [php7:notice] [pid 714] [client 172.21.0.20:35032] Default exception handler: A required parameter (type) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 30 of /badges/newbadge.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun2/badges/newbadge.php

      Problem E: mod/lesson/editpage.php . Lots of:

      webserver_chrome:32995:[Wed May 08 07:39:26.371033 2019] [php7:notice] [pid 865] [client 172.21.0.13:59634] Default exception handler: A required parameter (pageid) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 31 of /mod/lesson/editpage.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun1/mod/lesson/editpage.php

      Problem F: mod/workshop/submission.php and mod/workshop/assessment.php - A hand of:

      webserver_chrome:28407:[Wed May 08 07:27:43.866643 2019] [php7:notice] [pid 677] [client 172.21.0.13:53856] Default exception handler: A required parameter (cmid) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 28 of /mod/workshop/submission.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun1/mod/workshop/submission.php
      		 
       
      		 
      webserver_chrome:41159:[Wed May 08 08:03:52.887181 2019] [php7:notice] [pid 1022] [client 172.21.0.20:43176] Default exception handler: A required parameter (asid) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 40 of /mod/workshop/assessment.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun2/mod/workshop/assessment.php

      Problem G: mod/folder/edit.php - A hand of:

      webserver_chrome:49617:[Wed May 08 08:25:56.776088 2019] [php7:notice] [pid 1154] [client 172.21.0.13:37930] Default exception handler: A required parameter (id) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 31 of /mod/folder/edit.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun1/mod/folder/edit.php

      Problem H: mod/forum/post.php - One of:

      webserver_chrome:62787:[Wed May 08 08:58:26.359241 2019] [php7:notice] [pid 1390] [client 172.21.0.13:45864] Default exception handler: Unknown action! Debug: \nError code: unknowaction\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 664 of /mod/forum/post.php: call to print_error()\n, referer: http://run2af307a796fecb0b/behatrun1/mod/forum/post.php

      MDL-65540 - Problem I: Some invalid strings: 

      webserver_chrome:66651:[Wed May 08 09:08:41.057567 2019] [php7:notice] [pid 1432] [client 172.21.0.13:41828] Debugging: Invalid get_string() identifier: 'advanced' or component 'forum'. Perhaps you are missing $string['advanced'] = ''; in mod/forum/lang/en/forum.php?
      		 
       
      		 
      webserver_chrome:31375:[Wed May 08 07:34:58.521240 2019] [php7:notice] [pid 865] [client 172.21.0.13:54944] Debugging: Invalid get_string() identifier: 'strftimedatetime' or component 'core'. Perhaps you are missing $string['strftimedatetime'] = ''; in lang/en/core.php

      Problem J: backup/backupfilesedit.php - One of:

      webserver_chrome:65286:[Wed May 08 09:05:07.883171 2019] [php7:notice] [pid 1420] [client 172.21.0.21:42956] Default exception handler: A required parameter (contextid) was missing Debug: \nError code: missingparam\n* line 494 of /lib/setuplib.php: moodle_exception thrown\n* line 569 of /lib/moodlelib.php: call to print_error()\n* line 31 of /backup/backupfilesedit.php: call to required_param()\n, referer: http://run2af307a796fecb0b/behatrun3/backup/backupfilesedit.php

      Problem K: others, like failed logins... I don't know if these are errors or on-purpose:

      webserver_goutte:17545:[Wed May 08 09:44:42.050188 2019] [php7:notice] [pid 17] [client 172.19.0.4:33046] [client 172.19.0.4]  http://run01da8d786aa7fa69/behatrun2  Failed Login:  student  Symfony BrowserKit, referer: http://run01da8d786aa7fa69/behatrun2/login/index.php
      		 
       
      		 
      webserver_goutte:17766:[Wed May 08 09:44:56.052052 2019] [php7:notice] [pid 392] [client 172.19.0.4:35092] [client 172.19.0.4]  http://run01da8d786aa7fa69/behatrun1  Failed Login:  testuser  Symfony BrowserKit, referer: http://run01da8d786aa7fa69/behatrun1/login/index.php
      		 
       
      		 
      webserver_goutte:25866:[Wed May 08 09:53:12.604670 2019] [php7:notice] [pid 392] [client 172.19.0.4:42312] [client 172.19.0.4]  http://run01da8d786aa7fa69/behatrun1  Failed Login:  teacher1  Symfony BrowserKit, referer: http://run01da8d786aa7fa69/behatrun1/login/index.php
      		 
       
      		 
      webserver_goutte:25898:[Wed May 08 09:53:14.197402 2019] [php7:notice] [pid 392] [client 172.19.0.4:42312] [client 172.19.0.4]  http://run01da8d786aa7fa69/behatrun1  Failed Login:  admin  Symfony BrowserKit, referer: http://run01da8d786aa7fa69/behatrun1/login/index.php
      		 
       
      		 
      webserver_chrome:30834:[Wed May 08 07:33:29.728165 2019] [php7:notice] [pid 852] [client 172.21.0.13:44314] Cannot find session record b1ce448563956fc6e7f1ba40eb9668af for user 111000, creating new session., referer: http://run2af307a796fecb0b/behatrun1/user/profile.php?id=111000
      		 
       
      		 
      webserver_chrome:30847:[Wed May 08 07:33:31.110754 2019] [php7:notice] [pid 852] [client 172.21.0.13:44314] [client 172.21.0.13]  http://run2af307a796fecb0b/behatrun1  Failed Login:  victim  Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36, referer: http://run2af307a796fecb0b/behatrun1/login/index.php
      		 
       
      		 
      webserver_chrome:37297:[Wed May 08 07:51:17.890103 2019] [php7:notice] [pid 908] [client 172.21.0.20:58362] Default exception handler: Course or activity not accessible. Debug: You are not logged in\nError code: requireloginerror\n* line 2684 of /lib/moodlelib.php: require_login_exception thrown\n* line 69 of /lib/editor/atto/autosave-ajax.php: call to require_login()\n, referer: http://run2af307a796fecb0b/behatrun2/course/edit.php?id=102000

      And that's all I've found. Some seem real!

        There are no Sub-Tasks for this issue.

            dobedobedoh Andrew Lyons
            stronk7 Eloy Lafuente (stronk7)
            Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved:

                Estimated:
                Original Estimate - 0 minutes
                0m
                Remaining:
                Remaining Estimate - 0 minutes
                0m
                Logged:
                Time Spent - 3 days, 4 hours, 42 minutes
                3d 4h 42m

                  Error rendering 'clockify-timesheets-time-tracking-reports:timer-sidebar'. Please contact your Jira administrators.