Logging 2

Note: This page is a work-in-progress. Feedback and suggested improvements are welcome. Please join the discussion on moodle.org or use the page comments.

Logging stage 2
Project state	In very early specification
Tracker issue	MDL-37658
Discussion
Assignee	moodle.com DEV team

Mandate

To rewrite the logging API in Moodle to:

• allow capturing of richer information from plugins/core about actions;
• provide control over how much information is logged;
• separate log writing and reading so logging can be scaled;
• control how much logging history is kept; and
• support research, reporting and analytics.

Why is Logging an important topic?

Logging is fundamental to research, reporting and analytics.

Not much of new Moodle development is based on measured data. We need to be able to:

• prove there is a problem and
• prove that a given change is an improvement.

Logging data can be used by different Moodle users.

• Better data would allow researchers to study what happens in online teaching.
• Better data would give admins more feedback on how to run their site (both technically and process).
• Better data would give teachers better feedback to improve their teaching process.
• Better data would give students better feedback to improve their learning.

We can't predict all forms of analysis that might happen in future.

• The logging system needs to be flexible in order to accommodate applications by these different users.
• The logging API needs to be constructed in a way that is possible to change in future.

Use cases that would data from new events

Here are some ideas of how new even data and observers can be put to use, please note that the log strorage API is not optimised for these tasks.

• Timely notifications of critical events (defined by users), for example more than five people posted in the same forum within an hour.
• "Red circle" notification badge counter icons everywhere in Moodle highlighting things that a user needs to pay attention attention to, such as ???.
• Colour heatmaps overlaid on course pages showing recent usage patterns of the course.
• Visualisation of live activity across a whole site (for admins) (is that logging or event handling?)
• Live engagement analytics reporting ??? that take specific actions into account, such as ???.
• Identification of students at risk based on their involvement in the course (or lack of it).

Places where we need more logs

The principle work of this project is to replace the existing logging API. Once the new system is in place, the coverage of logging around Moodle can be improved.

Suggestions for places in Moodle where logging is needed should be reported as Tracker issues and linked to the Epic MDL-28443 "Action logging improvements". Feel free to echo significant areas here.

• Errors and warnings
  • People report errors that cannot be duplicated. Logging errors with a stack trace, session variables and other relevant data could be useful for debugging.
• Activities on site, course and activity administration pages.
• Micro activities in a page (more than one per load), such as ???.
• AJAX calls (eg on course page), such as ???.
• Logging of long events (such as an LDAP synchronisation) should have:
  • one unique identifier per event (like for example postfix mail server) to help admin monitor the cron processes and
  • at least 2 log entries (begining and end) for each event, possibly more.
• Should be careful about logging confidential information (e.g. do not log any POST data) (Why? These are logs, not reports.)
• Shouldn’t delete logs when course is deleted.

Existing Problems

This project will help to resolve a number of problems.

• Logging is added ad-hoc by developers and has spotty coverage.
• Some logged actions do not contain important information needed later.
• There are performance and scalability problems, such as:
  • log tables are joined in many popular queries and are slow;
  • all logs go to database, which is not scalable;
  • it is not possible to configure level of logging at present; and
  • a large number of database writes occur when carrying out 'read-only' requests.

Feel free to add more areas that should be worked on in future.

• There is no mechanism for archiving, so old logs are deleted and lost.
• Log deletion is indiscriminate, with no control of what log information is deleted or retained.
• There is no synchronization with server logs to help debugging performance issues.
• There is no logging of error information to help debug Moodle issues.

Logging API

The Moodle Events API provides a communication mechanism and single collection point for actions within Moodle. The Events system also defines information about events that can be extended with additional information and functionality by core code and plugins, as needed.

In order capture events a logging API will be specified, consisting of a number of plugin types. Simple examples will be provided that exemplify the new plugin types.

To transition from the old logging system to the new, work is required in a number of areas.

• In places where we previously added information to 'the' log table, we must instead generate a new event.
• The standard Moodle distribution will include simple DB logging storage plugin that will store events in new format.
• There will also be a legacy logging plugin that will be able to store data in the old format in the old {log} table. This plugin may be disabled if access to legacy logs is no longer needed.
• All standard reports will be upgraded to use the new logging system that will use a logging retrieval plugin to access log information.
• Custom report plugins (add-ons) will be able to query the {log} table while the legacy logging plugin writes to it, but should ideally shift to the new logging system over time, so that sites are not forced to continue double logging.

Existing log usage analysis

Log data us currently stored in a single database table, which is accessed directly. The new API will encourage log data to be accessed through appropriate plugins.

See this analysis to see log usage in Moodle 2.5 core code.

Example scenario

Writing to the log

1. A student submits an assignment.
2. An event is triggered by the Assignment module.
3. The logmanager plugin (implementing \core\logger\manager) observes the event and determines if it is log-worthy (how???).
4. The logmanager decides which writable log storage plugin(s) (implementing \core\logger\writer) will store the log (how???).
5. The logstorage plugin(s) stores the information about the submission (on disc, in DB or wherever).

Reading from the log

1. An admin sets up a report to use a particular logreader plugin (implementing \core\logger\legacy_reader or \core\logger\sql_reader) based on a list of available readers returned by the logmanager (are there defaults???).
2. A teacher requests report of student assignment submissions.
3. The report requests data from the logreader and displays it.

From event to report

There are four steps of how event is captured, logged and potentially presented in a report. These steps are summarised in Figure 1 below and can be described as follows.

1. Handling of events and filtering what needs to be logged. See interface \core\logger\manager (where??? link???)
2. Storing the events data in the log storage (DB, filesystem, etc.). See interface \core\logger\writer (where??? link???)
3. Retrieving the data from log storage - each plugin implements some methods to query and extract logs back to Moodle. See interfaces \core\logger\reader and \core\logger\sql_reader (where??? link???)
4. Displaying the data in the report.

One plugin may cover multiple steps. For example we expect that most of log writer plugins will also implement log reader. It is also possible to create a report that has built-in event handling, log writing and reading and report presentation (all four steps). Also external logging systems may not wish to allow log data they capture to be reported within Moodle, handling it through an external system, so they may not implement steps 3 and 4 at all.

The Moodle standard distribution will provide a suggestion for a logging-report chain that may be followed by add-on plugins, but the API will be flexible enough to allow alternatives.

Figure 1. Logging plugins relationship diagram

As shown in Figure 2 below ...description description description description description description description description description description description description description description description description description description description description description description description.

Figure 2. Logging plugins sequence diagram

Moodle core

• interface \core\logger\manager - log manager (listing of log storage plugins)
  • function get_readers() returns the active storages implementing reader interface, returns array(classname => storage instance, ...)
• interface \core\logger\storage -
  • function __construct() - No logic in here
  • function get_name()
  • function get_description()
• interface \core\logger\writer extends \core\logger\storage - log storage (adding to storage)
  • function store(core_event_base $event)
  • 2.7? hook: starting_transaction()
  • 2.7? hook: commiting_transaction()
  • 2.7? hook: rollbacking_transaction()
  • 2.7? hook: starting_page_output() - it would flush event buffer
• interface \core\logger\reader extends \core\logger\storage - Nothing here, just an interface to define what supports reading, in case we create other reading interfaces later on.
• interface \core\logger\sql_reader extends \core\logger\reader - log storage (reading from storage, sql)
  • function get_log_table() - also describes in phpdocs which fields are expected in the table
  • function get_events($selectwhere, array $params, $order, $limitfrom, $limitnum)
  • function get_events_count($selectwhere, array $params)
• function \get_log_manager() - returns the current log manager if configured or some dummy class otherwise
• class \core\logger\dummy_logger - dummy class implementing log manager interface
• interface \core\event\reportable (extended by \core\event\base)
• interface \core\event\legacy_log(ged)?_event implements \core\event\(reportable)
• interface \core\logger\logacy_reader extends \core\logger\reader - for reading from mdl_log table or log storage plugin that pretends to be old-format table
  • ???
• class \core\logger\legacy_reader implements \core\logger\legacy_reader - for reading from mdl_log table. There is no writer plugin, it is implemented by default when event with legacy log info is triggered.
  • ???

When searching for classes implementing interface we look for class in plugin’s namespace named logger and then analyse if it implements the interface (one class can implement multiple interfaces)

If there are multiple storages returned by the log manager, then the report is responsible for letting the user choose which storage to create the report on.

Standard logging plugins

Standard Moodle 2.6 distribution will include 3 plugins:

Logging management plugin (tool_logmanager)

Defines:

 class \tool\logmanager\logger implements \core\logger\manager;

Responsible for step 1 from above. Allows admin to configure what kind of events to store for each log storage. Available log storages are "admin tool" plugins with class log (in their namespace) implementing \core\log\storage. Also can return the list of available log readers - "admin tool" plugins with class log (in their namespace) implementing \core\log\reader

DB log storage plugin (tool_logdb)

Defines:

 class \tool\logdb\logger implements \core\logger\sql_reader, \core\logger\writer;

Responsible for steps 2 and 3 from above

File system log storage plugin (tool_logfile)

Defines:

 class \tool\logfile\logger implements \core\logger\writer;

Responsible for step 2 from above only. No interface to read from it.

Mockups

Log storage settings page

Log storage settings page

Log storage Instance configuration page

Log storage instance configuration page

File log instance configuration page

File Log instance configuration page

Event observer initial configuration page

Event observer initial configuration page

Event observer individual logging device event management page

Event observer individual logging device event management page

Summary

We can't actually predict all the use cases so we must think generically and plan for worst cases.

• Things that don't need to use logs should not use logs. (Recent activity, etc)
• Make logging calls as cheap as possible
• Use Events API for the originating calls to create lots of hooks for other things
• Use MUC-like plug-ins to determine where to put logs permanently (NoSQL, SAS, file...). Default will be to the current log table.
• Log everything we possibly can think of.
• Define log level settings (on each logging call) so different sites can choose what they want logged and so control size, speed etc
• add_to_log retained for backward compatibility, make it a wrapper for new logger function.
• provide hooks to expose logs everywhere. For example, each page should have a link that shows logs and stats for that page.

See also

• Event 2

Example logging systems:

• http://logstash.net/
• http://fluentd.org/
• http://logging.apache.org/log4php/

Examples of data-based learning technology development:

• http://onlinelibrary.wiley.com/doi/10.1111/j.1467-8535.2008.00928.x/abstract
• http://www.sciencedirect.com/science/article/pii/S0360131510000461 -> qtype_pmatch
• http://www.tandfonline.com/doi/abs/10.1080/02680513.2011.567754
• http://oro.open.ac.uk/24619/