Details

    • Type: New Feature New Feature
    • Status: Open
    • Priority: Minor Minor
    • Resolution: Unresolved
    • Affects Version/s: 1.9.7
    • Fix Version/s: DEV backlog
    • Component/s: SCORM
    • Labels:
    • Environment:
      LAMP, PHP 5.2.12
    • Database:
      MySQL
    • Difficulty:
      Easy
    • Affected Branches:
      MOODLE_19_STABLE
    • Rank:
      5771

      Description

      Currently there's a really nice debug log feature for API based tracked items but nothing for HACP: while something similar could not be provided since everything is server side, it would be really useful to get some debug info during an AICC HACP session.

        Activity

        Hide
        Matteo Scaramuccia added a comment -

        Patch proposal:

        mod/scorm/aicc.php

        @@ -14,6 +14,24 @@
                  $_POST[$tempkey] = $value;
            }
         
        +    function addAICCDebugLogData($text)
        +    {
        +        global $CFG, $USER, $scoid;
        +
        +        $debugenablelog = debugging('', DEBUG_DEVELOPER);
        +        if (!$debugenablelog || empty($text)) {
        +            return ;
        +        }
        +
        +        $logpath = $CFG->dataroot.'/_aiccdebug_';
        +        if (!file_exists($logpath)) {
        +            @mkdir($logpath);
        +        }
        +
        +        $logfile = $logpath.'/aiccdebug_'.$USER->id.'_'.$scoid.'.log';
        +        @file_put_contents($logfile, date('Y/m/d H:i:s O')." DEBUG $text\r\n", FILE_APPEND);
        +    }
        +
             $command = required_param('command', PARAM_ALPHA);
             $sessionid = required_param('session_id', PARAM_ALPHANUM);
             $aiccdata = optional_param('aicc_data', '', PARAM_RAW);
        @@ -50,6 +68,15 @@
                     error('Invalid script call');
                 }
         
        +        addAICCDebugLogData("scoid: $scoid");
        +        addAICCDebugLogData("mode: $mode");
        +        addAICCDebugLogData("status: $status");
        +        addAICCDebugLogData("attempt: $attempt");
        +        addAICCDebugLogData("command: $command");
        +        addAICCDebugLogData("sessionid: $sessionid");
        +        addAICCDebugLogData("aiccdata:\r\n$aiccdata");
        +        ob_start();
        +
                 if ($scorm = get_record('scorm','id',$sco->scorm)) {
                     switch ($command) {
                         case 'getparam':
        @@ -372,4 +399,8 @@
                     echo "error=3\r\nerror_text=Invalid Session ID\r\n";
                 }
             }
        +
        +    $aiccresponse = ob_get_contents();
        +    addAICCDebugLogData("response:\r\n$aiccresponse");
        +    ob_end_flush();
         ?>
        
        Show
        Matteo Scaramuccia added a comment - Patch proposal: mod/scorm/aicc.php @@ -14,6 +14,24 @@ $_POST[$tempkey] = $value; } + function addAICCDebugLogData($text) + { + global $CFG, $USER, $scoid; + + $debugenablelog = debugging('', DEBUG_DEVELOPER); + if (!$debugenablelog || empty($text)) { + return ; + } + + $logpath = $CFG->dataroot.'/_aiccdebug_'; + if (!file_exists($logpath)) { + @mkdir($logpath); + } + + $logfile = $logpath.'/aiccdebug_'.$USER->id.'_'.$scoid.'.log'; + @file_put_contents($logfile, date('Y/m/d H:i:s O'). " DEBUG $text\r\n" , FILE_APPEND); + } + $command = required_param('command', PARAM_ALPHA); $sessionid = required_param('session_id', PARAM_ALPHANUM); $aiccdata = optional_param('aicc_data', '', PARAM_RAW); @@ -50,6 +68,15 @@ error('Invalid script call'); } + addAICCDebugLogData( "scoid: $scoid" ); + addAICCDebugLogData( "mode: $mode" ); + addAICCDebugLogData( "status: $status" ); + addAICCDebugLogData( "attempt: $attempt" ); + addAICCDebugLogData( "command: $command" ); + addAICCDebugLogData( "sessionid: $sessionid" ); + addAICCDebugLogData( "aiccdata:\r\n$aiccdata" ); + ob_start(); + if ($scorm = get_record('scorm','id',$sco->scorm)) { switch ($command) { case 'getparam': @@ -372,4 +399,8 @@ echo "error=3\r\nerror_text=Invalid Session ID\r\n" ; } } + + $aiccresponse = ob_get_contents(); + addAICCDebugLogData( "response:\r\n$aiccresponse" ); + ob_end_flush(); ?>
        Hide
        Dan Marsden added a comment -

        Hi Matteo,

        I've made a couple of changes and pushed a revised patch into HEAD - could you please check it out and make sure it satisfies your requirements - if it looks ok I'll push the change into 1.9 stable as well.

        Show
        Dan Marsden added a comment - Hi Matteo, I've made a couple of changes and pushed a revised patch into HEAD - could you please check it out and make sure it satisfies your requirements - if it looks ok I'll push the change into 1.9 stable as well.
        Hide
        Matteo Scaramuccia added a comment -

        Hi Dan,
        just copied (fs&db) and then updated my MOODLE_19_STABLE to HEAD: it seemed the upgrade to be OK but... I'm now getting some blocking errors on AICC HACP*, I'll be back when I'll found the reason for them.

        Matteo


        *The first error appeared twice (probably when I've checked and saved activity settings, the second 4 times and it is my blocking HACP issue:

        ...
        [25-Jun-2010 14:11:35] PHP Warning:  mkdir() [<a href='function.mkdir'>function.mkdir</a>]: File exists in <windows>\moodle-cvs-20\lib\moodlelib.php on line 9147
        ...
        [25-Jun-2010 14:19:15] PHP Catchable fatal error:  Argument 2 passed to moodle_database::get_record() must be an array, string given,
        called in <windows>\moodle-cvs-20\mod\scorm\aicc.php on line 52 and defined in <windows>\moodle-cvs-20\lib\dml\moodle_database.php on line 1166
        ...
        
        Show
        Matteo Scaramuccia added a comment - Hi Dan, just copied (fs&db) and then updated my MOODLE_19_STABLE to HEAD: it seemed the upgrade to be OK but... I'm now getting some blocking errors on AICC HACP*, I'll be back when I'll found the reason for them. Matteo — *The first error appeared twice (probably when I've checked and saved activity settings, the second 4 times and it is my blocking HACP issue: ... [25-Jun-2010 14:11:35] PHP Warning: mkdir() [<a href='function.mkdir'>function.mkdir</a>]: File exists in <windows>\moodle-cvs-20\lib\moodlelib.php on line 9147 ... [25-Jun-2010 14:19:15] PHP Catchable fatal error: Argument 2 passed to moodle_database::get_record() must be an array, string given, called in <windows>\moodle-cvs-20\mod\scorm\aicc.php on line 52 and defined in <windows>\moodle-cvs-20\lib\dml\moodle_database.php on line 1166 ...
        Hide
        Dan Marsden added a comment -

        Thanks Matteo - the db error looks like a get_record call that hasn't been updated correctly for 2.0 - I'll check this out later today when I'm front of my dev machine
        FYI old sytle get_record:
        get_record('table', 'field', 'value');
        new style get_record
        $DB->get_record('table', array('field'=>'value'));

        thanks!

        Show
        Dan Marsden added a comment - Thanks Matteo - the db error looks like a get_record call that hasn't been updated correctly for 2.0 - I'll check this out later today when I'm front of my dev machine FYI old sytle get_record: get_record('table', 'field', 'value'); new style get_record $DB->get_record('table', array('field'=>'value')); thanks!
        Hide
        Dan Marsden added a comment -

        fixed the get_record call issue - just looking at the check_dir_exists bug - it sounds like the function must be called with a file instead of a dir as the path

        Show
        Dan Marsden added a comment - fixed the get_record call issue - just looking at the check_dir_exists bug - it sounds like the function must be called with a file instead of a dir as the path
        Hide
        Dan Marsden added a comment -

        can't see the check_dir_exists one - lit doesn't appear to be coming from the scorm code - let me know if you track it down.

        thanks,

        Show
        Dan Marsden added a comment - can't see the check_dir_exists one - lit doesn't appear to be coming from the scorm code - let me know if you track it down. thanks,
        Hide
        Matteo Scaramuccia added a comment -

        Hi Dan,
        the calls are in {{

        {backup,restore}

        lib.php}} but I didn't ask for such actions: I will try to replicate it since I've also adjust the

        {full,short}

        site name - changing from "Dev 19" to "Dev HEAD" - before entering in the course and than in the activity.
        BTW it could be also related with the Windows environment: mkdir(""), mkdir(false), and mkdir(null) give a "file exists" error. this is also true of a directory name consisting of any string that only contains space characters. (this was on php 5.1.2 on Windows 2000).

        What about a patch like the one below?

        Index: moodlelib.php
        ===================================================================
        RCS file: /cvsroot/moodle/moodle/lib/moodlelib.php,v
        retrieving revision 1.1396
        diff -u -r1.1396 moodlelib.php
        --- moodlelib.php	25 Jun 2010 13:43:50 -0000	1.1396
        +++ moodlelib.php	26 Jun 2010 06:56:24 -0000
        @@ -9136,6 +9136,11 @@
                 return false;
             }
         
        +    if (is_file($dir)) {
        +        debugging('Warning. Wrong call to check_dir_exists(). $dir must be an absolute path under $CFG->dataroot ("' . $dir . '" is a file)', DEBUG_DEVELOPER);
        +        return false;
        +    }
        +
             if (is_dir($dir)) {
                 return true;
             }
        
        
        Show
        Matteo Scaramuccia added a comment - Hi Dan, the calls are in {{ {backup,restore} lib.php}} but I didn't ask for such actions: I will try to replicate it since I've also adjust the {full,short} site name - changing from "Dev 19" to "Dev HEAD" - before entering in the course and than in the activity. BTW it could be also related with the Windows environment: mkdir(""), mkdir(false), and mkdir(null) give a "file exists" error. this is also true of a directory name consisting of any string that only contains space characters. (this was on php 5.1.2 on Windows 2000) . What about a patch like the one below? Index: moodlelib.php =================================================================== RCS file: /cvsroot/moodle/moodle/lib/moodlelib.php,v retrieving revision 1.1396 diff -u -r1.1396 moodlelib.php --- moodlelib.php 25 Jun 2010 13:43:50 -0000 1.1396 +++ moodlelib.php 26 Jun 2010 06:56:24 -0000 @@ -9136,6 +9136,11 @@ return false ; } + if (is_file($dir)) { + debugging('Warning. Wrong call to check_dir_exists(). $dir must be an absolute path under $CFG->dataroot ( "' . $dir . '" is a file)', DEBUG_DEVELOPER); + return false ; + } + if (is_dir($dir)) { return true ; }
        Hide
        Dan Marsden added a comment -

        yeah - I saw the usage in backup/restore - the error you're getting has to be coming from somewhere else although I can't see where - unless it's the bug you're mentioning with mkdir('') - that could potentially be occurring in theme/image.php theme/javascript.php or theme/styles.php

        Show
        Dan Marsden added a comment - yeah - I saw the usage in backup/restore - the error you're getting has to be coming from somewhere else although I can't see where - unless it's the bug you're mentioning with mkdir('') - that could potentially be occurring in theme/image.php theme/javascript.php or theme/styles.php
        Hide
        Dan Marsden added a comment -

        my guess is theme/styles.php line 80-81:
        $css = $theme->editor_css_content();
        store_css($candidatesheet, $css);

        that doesn't look like the right way of using store_css to me - but I'm not all that familiar with the new output themes

        Show
        Dan Marsden added a comment - my guess is theme/styles.php line 80-81: $css = $theme->editor_css_content(); store_css($candidatesheet, $css); that doesn't look like the right way of using store_css to me - but I'm not all that familiar with the new output themes
        Hide
        Dan Marsden added a comment -
        Show
        Dan Marsden added a comment - looks like Sam's already fixed it! http://cvs.moodle.org/moodle/theme/styles.php?r1=1.12&r2=1.13
        Hide
        Matteo Scaramuccia added a comment -

        Hi Dan,
        it makes sense since "Sat Jun 26 08:48:35 2010 WST" (time in Perth?) is equal to "Sat Jun 26 02:48:35 2010 CEST", according with:

        • CEST, Central Europe Summer Time => UT+2:00
        • WST, Western Standard Time (Australia) => UT+8:00

        i.e. the fix came out after my CVS export .

        BTW, the next week I'll definitely try your good review (e.g. I've missed to catch the mkdir failure and being somewhat general) and try to add an AJAX AICC log viewer using something like AJAX Logfile Tailer & Viewer, without the need for *nix tail.

        Ciao,
        Matteo

        Show
        Matteo Scaramuccia added a comment - Hi Dan, it makes sense since "Sat Jun 26 08:48:35 2010 WST" (time in Perth?) is equal to "Sat Jun 26 02:48:35 2010 CEST", according with: CEST, Central Europe Summer Time => UT+2:00 WST, Western Standard Time (Australia) => UT+8:00 i.e. the fix came out after my CVS export . BTW, the next week I'll definitely try your good review (e.g. I've missed to catch the mkdir failure and being somewhat general) and try to add an AJAX AICC log viewer using something like AJAX Logfile Tailer & Viewer , without the need for *nix tail . Ciao, Matteo
        Hide
        Matteo Scaramuccia added a comment -

        Hi Dan,
        back again w/ a new patch (MDL-21354_scorm_aicc_debug_v02.patch) starting from your review: added a web view for the debug log (> mod/scorm/datamodels/aicc_debug.php).
        The new view works as per my needs and it should be nice that:

        • [High] it could be backported into 1.9 branch too;
        • [Low] it could be automatically opened launching an AICC HACP unit under DEVELOPER debug level.

        Feel free of reviewing anything of this patch!

        Ciao,
        Matteo

        Show
        Matteo Scaramuccia added a comment - Hi Dan, back again w/ a new patch ( MDL-21354 _scorm_aicc_debug_v02.patch ) starting from your review: added a web view for the debug log (> mod/scorm/datamodels/aicc_debug.php ). The new view works as per my needs and it should be nice that: [High] it could be backported into 1.9 branch too; [Low] it could be automatically opened launching an AICC HACP unit under DEVELOPER debug level. Feel free of reviewing anything of this patch! Ciao, Matteo
        Hide
        Dan Marsden added a comment -

        Hi Matteo - any chance you could review this patch again and format one to apply against master and I'll take another look?

        Show
        Dan Marsden added a comment - Hi Matteo - any chance you could review this patch again and format one to apply against master and I'll take another look?
        Hide
        Matteo Scaramuccia added a comment -

        Hi Dan: yes, but not in these days... no spare time. Is it possible to think at the end of December, first weeks of January for my delivery?

        Show
        Matteo Scaramuccia added a comment - Hi Dan: yes, but not in these days... no spare time. Is it possible to think at the end of December, first weeks of January for my delivery?
        Hide
        Dan Marsden added a comment -

        hehe - no pressure on my end! - it's just unlikely I'll look at this unless an up-to-date patch is provided - thanks!

        Show
        Dan Marsden added a comment - hehe - no pressure on my end! - it's just unlikely I'll look at this unless an up-to-date patch is provided - thanks!

          People

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

            Dates

            • Created:
              Updated: