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

Capture output during cron and task runs

    XMLWordPrintable

    Details

    • Testing Instructions:
      Hide

      Logging is disabled

      Setup

      1. Navigate to Site administration -> Server -> Task log configuration
      2. Change the log mode to "Do not log anything" and save changes

      Test normal

      1. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      2. Create a new export request for a user and Approve it
      3. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did not see any failures
      4. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list is empty

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did not see any failures
      5. Refresh the list of task logs
        1. Confirm that the list is empty
      6. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      7. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did not see any failures
      8. Refresh the list of task logs
        1. Confirm that the list is empty

      Test failing tasks

      1. Open the following files in your text editor:
        1. lib/classes/task/calendar_cron_task.php
        2. admin/tool/dataprivacy/classes/task/process_data_request_task.php
      2. Find the execute function and add the following at the start of the function:

        throw new \coding_exception('Oops');
        

      3. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      4. Create a new export request for a user and Approve it
      5. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did see a failure
      6. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list is empty

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did see a failure
      7. Refresh the list of task logs
        1. Confirm that the list is empty
      8. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      9. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did see a failure
      10. Refresh the list of task logs
        1. Confirm that the list is empty

      Cleanup

      1. Undo your changes:

        git checkout .
        

      Logging is set to failures only

      Setup

      1. Navigate to Site administration -> Server -> Task log configuration
      2. Change the log mode to "Only store logs for jobs which fail" and save changes

      Test normal

      1. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      2. Create a new export request for a user and Approve it
      3. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did not see any failures
      4. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list is empty

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did not see any failures
      5. Refresh the list of task logs
        1. Confirm that the list is empty
      6. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      7. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did not see any failures
      8. Refresh the list of task logs
        1. Confirm that the list is empty

      Test failing tasks

      1. Open the following files in your text editor:
        1. lib/classes/task/calendar_cron_task.php
        2. admin/tool/dataprivacy/classes/task/process_data_request_task.php
      2. Find the execute function and add the following at the start of the function:

        throw new \coding_exception('Oops');
        

      3. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      4. Create a new export request for a user and Approve it
      5. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did see a failure
      6. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list contains just the two jobs which failed

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did see a failure
      7. Refresh the list of task logs
        1. Confirm that the list now contains three jobs
      8. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      9. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did see a failure
      10. Refresh the list of task logs
        1. Confirm that the list now contains four jobs

      Test Dieing tasks

      1. Open the following files in your text editor:
        1. lib/classes/task/calendar_cron_task.php
        2. admin/tool/dataprivacy/classes/task/process_data_request_task.php
      2. Find the execute function and add the following at the start of the function instead of the exception (or before it):

        die;
        

      3. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      4. Create a new export request for a user and Approve it
      5. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did see a failure
      6. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list contains two new entries for those jobs you deliberately broke

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did see a failure
      7. Refresh the list of task logs
        1. Confirm that the list now contains another failed task
      8. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      9. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did see a failure
      10. Refresh the list of task logs
        1. Confirm that the list now contains another failed task

      Cleanup

      1. Undo your changes:

        git checkout .
        

      Logging is set to all tasks

      Setup

      1. Navigate to Site administration -> Server -> Task log configuration
      2. Change the log mode to "Store the log output of all jobs" and save changes

      Test normal

      1. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      2. Create a new export request for a user and Approve it
      3. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did not see any failures
      4. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list now contains loads of tasks

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did not see any failures
      5. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the scheduled task you just ran
      6. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      7. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did not see any failures
      8. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the adhoc task you just ran

      Test failing tasks

      1. Open the following files in your text editor:
        1. lib/classes/task/calendar_cron_task.php
        2. admin/tool/dataprivacy/classes/task/process_data_request_task.php
      2. Find the execute function and add the following at the start of the function:

        throw new \coding_exception('Oops');
        

      3. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      4. Create a new export request for a user and Approve it
      5. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did see a failure
      6. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list contains a load more tasks, including the two failed tasks you just ran

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did see a failure
      7. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the scheduled task you just ran
      8. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      9. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did see a failure
      10. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the adhoc task you just ran

      Test Dieing tasks

      1. Open the following files in your text editor:
        1. lib/classes/task/calendar_cron_task.php
        2. admin/tool/dataprivacy/classes/task/process_data_request_task.php
      2. Find the execute function and add the following at the start of the function instead of the exception (or before it):

        die;
        

      3. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      4. Create a new export request for a user and Approve it
      5. Run cron:

        php admin/cli/cron.php
        

        1. Confirm that you saw a lot of output from cron
        2. Confirm that you did see a failure
      6. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the list contains a load more tasks, including the two broken tasks

          php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task"
          

        2. Confirm that you saw relevant output
        3. Confirm that you did see a failure
      7. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the scheduled task you just ran
      8. Navigate to Site administration -> Users -> Privacy & Policies -> Data requests
      9. Create a new export request for a user and Approve it

        php admin/tool/task/cli/adhoc_task.php --execute
        

        1. Confirm that you saw relevant output
        2. Confirm that you did see a failure
      10. Refresh the list of task logs
        1. Confirm that the list now contains an additional task for the adhoc task you just ran

      UI Check

      1. Navigate to Site administration -> Server -> Task logs
      2. Confirm that the following features work as you would expect:
        1. Navigation between pages
        2. Sort
        3. Filter by status
        4. Filter by string (this only searches the class name)
        5. Previewing a log entry (via the magnify icon and should open in a popup)
          1. Confirm that the output matches the output you see on cron
        6. Downloading a log entry
          1. Confirm that the output matches the output you see on cron
      3. Navigate to Site adminnistration -> Server -> Scheduled tasks
      4. Find the 'calendar_cron_task' in the list
      5. Press the "Log" link
        1. Confirm that it takes you straight to those logs

      Cleanup task

      1. Navigate to Site administration -> Server -> Task logs
      2. Take note of the number of pages and some of the items in the list
      3. Run the cleanup task twice

        php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task"
        php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task"
        

      4. Navigate to Site administration -> Server -> Task logs
        1. Confirm that the number of pages did not change and that only two new item was added to the list
        2. Confirm that you see the task_log_cleanup_task listed twice
      5. Navigate to Site administration -> Server -> Task log configuration
      6. Change the "Retain runcount" setting to 1
      7. Run the cleanup task twice

        php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task"
        php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task"
        

      8. Navigate to Site administration -> Server -> Task logs
        1. Confirm that you only see two entries for the cleanup task (one from the time the cleanup was run, and the other is the cleanup which did the cleaning up)
      9. Navigate to Site administration -> Server -> Task log configuration
      10. Change the "Retention period" setting to 60 seconds
      11. Run the cleanup task:

        php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task"
        

      12. Navigate to Site administration -> Server -> Task logs
        1. Confirm that you only see entries for the past 1 minute
      Show
      Logging is disabled Setup Navigate to Site administration -> Server -> Task log configuration Change the log mode to "Do not log anything" and save changes Test normal Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did not see any failures Navigate to Site administration -> Server -> Task logs Confirm that the list is empty php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list is empty Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list is empty Test failing tasks Open the following files in your text editor: lib/classes/task/calendar_cron_task.php admin/tool/dataprivacy/classes/task/process_data_request_task.php Find the execute function and add the following at the start of the function: throw new \coding_exception('Oops'); Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did see a failure Navigate to Site administration -> Server -> Task logs Confirm that the list is empty php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list is empty Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list is empty Cleanup Undo your changes: git checkout . Logging is set to failures only Setup Navigate to Site administration -> Server -> Task log configuration Change the log mode to "Only store logs for jobs which fail" and save changes Test normal Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did not see any failures Navigate to Site administration -> Server -> Task logs Confirm that the list is empty php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list is empty Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list is empty Test failing tasks Open the following files in your text editor: lib/classes/task/calendar_cron_task.php admin/tool/dataprivacy/classes/task/process_data_request_task.php Find the execute function and add the following at the start of the function: throw new \coding_exception('Oops'); Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did see a failure Navigate to Site administration -> Server -> Task logs Confirm that the list contains just the two jobs which failed php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains three jobs Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains four jobs Test Dieing tasks Open the following files in your text editor: lib/classes/task/calendar_cron_task.php admin/tool/dataprivacy/classes/task/process_data_request_task.php Find the execute function and add the following at the start of the function instead of the exception (or before it): die; Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did see a failure Navigate to Site administration -> Server -> Task logs Confirm that the list contains two new entries for those jobs you deliberately broke php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains another failed task Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains another failed task Cleanup Undo your changes: git checkout . Logging is set to all tasks Setup Navigate to Site administration -> Server -> Task log configuration Change the log mode to "Store the log output of all jobs" and save changes Test normal Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did not see any failures Navigate to Site administration -> Server -> Task logs Confirm that the list now contains loads of tasks php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list now contains an additional task for the scheduled task you just ran Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did not see any failures Refresh the list of task logs Confirm that the list now contains an additional task for the adhoc task you just ran Test failing tasks Open the following files in your text editor: lib/classes/task/calendar_cron_task.php admin/tool/dataprivacy/classes/task/process_data_request_task.php Find the execute function and add the following at the start of the function: throw new \coding_exception('Oops'); Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did see a failure Navigate to Site administration -> Server -> Task logs Confirm that the list contains a load more tasks, including the two failed tasks you just ran php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains an additional task for the scheduled task you just ran Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains an additional task for the adhoc task you just ran Test Dieing tasks Open the following files in your text editor: lib/classes/task/calendar_cron_task.php admin/tool/dataprivacy/classes/task/process_data_request_task.php Find the execute function and add the following at the start of the function instead of the exception (or before it): die; Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it Run cron: php admin/cli/cron.php Confirm that you saw a lot of output from cron Confirm that you did see a failure Navigate to Site administration -> Server -> Task logs Confirm that the list contains a load more tasks, including the two broken tasks php admin/tool/task/cli/schedule_task.php --execute="\core\task\calendar_cron_task" Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains an additional task for the scheduled task you just ran Navigate to Site administration -> Users -> Privacy & Policies -> Data requests Create a new export request for a user and Approve it php admin/tool/task/cli/adhoc_task.php --execute Confirm that you saw relevant output Confirm that you did see a failure Refresh the list of task logs Confirm that the list now contains an additional task for the adhoc task you just ran UI Check Navigate to Site administration -> Server -> Task logs Confirm that the following features work as you would expect: Navigation between pages Sort Filter by status Filter by string (this only searches the class name) Previewing a log entry (via the magnify icon and should open in a popup) Confirm that the output matches the output you see on cron Downloading a log entry Confirm that the output matches the output you see on cron Navigate to Site adminnistration -> Server -> Scheduled tasks Find the ' calendar_cron_task ' in the list Press the "Log" link Confirm that it takes you straight to those logs Cleanup task Navigate to Site administration -> Server -> Task logs Take note of the number of pages and some of the items in the list Run the cleanup task twice php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task" php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task" Navigate to Site administration -> Server -> Task logs Confirm that the number of pages did not change and that only two new item was added to the list Confirm that you see the task_log_cleanup_task listed twice Navigate to Site administration -> Server -> Task log configuration Change the "Retain runcount" setting to 1 Run the cleanup task twice php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task" php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task" Navigate to Site administration -> Server -> Task logs Confirm that you only see two entries for the cleanup task (one from the time the cleanup was run, and the other is the cleanup which did the cleaning up) Navigate to Site administration -> Server -> Task log configuration Change the "Retention period" setting to 60 seconds Run the cleanup task: php admin/tool/task/cli/schedule_task.php --execute="\core\task\task_log_cleanup_task" Navigate to Site administration -> Server -> Task logs Confirm that you only see entries for the past 1 minute
    • Affected Branches:
      MOODLE_29_STABLE, MOODLE_37_STABLE
    • Fixed Branches:
      MOODLE_37_STABLE
    • Pull Master Branch:
      MDL-49399-master

      Description

      The intent of this set of changes is to help with tracking down issues with the site and is a oft-requested feature.
      Currently our recommendation is to write cron output to a log file and read it. This isn't really very administrator-friendly and means that failing jobs can go unnoticed for a considerable period.

      This set of changes introduces a new task logging system which adds a new output buffer to:

      1. cron runs (web + CLI)
      2. scheduled task runs
      3. adhoc task runs

      The output buffer uses a new function which both returns the same buffer (so that it is displayed to the user still), and writes to a filehandle.
      This method allows capture of all content displayed via:

      1. mtrace
      2. echo
      3. var_dump
      4. print_r
      5. print_object
        It does not capture output displayed via fwrite(STDOUT, 'Hidden from logs but displayed in CLI');
        If the job itself runs an ob_start then the output of that nested capture is not considered. It does not interfere with any logic within a task.

      When the task finishes, the task is sent to a log storage class to store as appropriate.
      Filters can be applied at this stage to store all, or only failed jobs.
      The functionality can be disabled entirely too.
      If the task fails then the state is noted too.
      if the task calls die or causes the thread to finish prematurely then this also counts as a fail and is logged. (segfaults are excluded from this).

      The change allows for the storage class to be overridden such that a custom storage class can be used. This may be useful for those shipping to somewhere such as fluentd, graylog, etc.

      The default implementation stores a range of metadata in the database (start and end time, number of DB queries, result, user that the task ran as for adhoc tasks, etc.). The output is stored in the file storage API.

      A cleanup task is also present and used in the default implementation to keep the number of logs to a minimum.

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                8 Vote for this issue
                Watchers:
                24 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Fix Release Date:
                  20/May/19

                  Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 day, 30 minutes
                  1d 30m