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.

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.

• 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. The privacy is controlled by event access control.
• Shouldn’t delete logs when course is deleted. There is no API to delete logs, each log storage controls the rotation or deleting of old data individually.

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 one standard moodle database table, which is not scalable;
  • it is not possible to configure level of logging at present; and
  • it is not possible to disable logging completely.

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. (This will not be addressed by new logging API.)
• There is no logging of error information to help debug Moodle issues. (This will not be addressed by new logging API.)

Logging

The Moodle Events API provides a notification 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.
• The original logging code and db tables are kept in place for full backwards compatibility. It will be posssible to completely disable the old logging.
• 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, 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 is currently stored in a single standard moodle database table, which is accessed directly. The new API will still encourage the log storage plugins to expose the data in the form of standardised database table, but it will be possible to use read only database views with arbitrary name.

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\log\manager) observes the event and determines if it is log-worthy depending on some admin settings.
4. The logmanager sends the event to all enabled log storage plugins implementing \core\log\writer.
5. The logstorage plugin(s) stores the event data optionally including extra information such as remote IP or type of access (preferably in DB or wherever else).

Reading from the log

1. A teacher opens activity report.
2. If there is more than one log storage reader (implementing \core\log\sql_reader) available they can select the source of data for the report.
3. A teacher requests report of student assignment submissions.
4. 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\log\manager below.
2. Storing the events data in the log storage (DB, filesystem, etc.). See interface \core\log\writer below.
3. Retrieving the data from log storage - each plugin implements some methods to query and extract logs back to Moodle. See interfaces \core\log\reader and \core\log\sql_reader below.
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

Public API

This section describes all interfaces that need to be implemented by log manager and each log storage class.

Management API

• function \get_log_manager() - returns the current log manager if configured or some dummy instance otherwise, it uses the signleton pattern.
• interface \core\log\manager - log manager interface, in standard distribution implemented by \tool_logmanager\log\manager and \core\log\dummy_manager
  • public function get_readers() returns the active storages implementing reader interface, returns array(classname => storage instance, ...)
• interface \core\log\storage - must be implemented by each log writer and reader
  • public function __construct() - no parameters, configuration is taken from admin settings
  • public function get_name() - returns name of the log storage, this will be used when selection data source in reports.
  • public function get_description() - some help for admins.

When searching for storage classes we look for class named storage in \log_pluginname\log\ namespace and then analyse if it implements the interface (one class can implement multiple interfaces).

Writing API

• interface \core\log\writer extends \core\log\storage - interface indicating the log storage may be used for writing.
  • public function store(core_event_base $event) - called from event observer defined in log manager.

The writing API is expected to be used by log managers only.

Each log storage plugin will be responsible for filtering of events, it may use standardised admin settings and filtering or decide to implement custom filtering.

Reading API

• interface \core\log\reader extends \core\log\storage - general log storage that supports sql selects (or emulates them)
  • public function get_events($selectwhere, array $params, $order, $limitfrom, $limitnum) - returns event object instances matching given parameters.
  • public function get_events_count($selectwhere, array $params) - returns number of events that would be returned from get_events() with the same parameters.
• interface \core\log\sql_reader extends \core\log\reader - log storage that can expose data as read-only database view or table.
  • public function get_log_table() - returns database table or view; structure is described in phpdocs, it will include all columns defined by log_sql
• interface \core\event\reportable (extended by \core\event\base) - TODO
• interface \core\event\legacy_log(ged)?_event implements \core\event\(reportable) - TODO

Reports are expected to use only the reading API. Please note that all non-sql readers need to somehow translate the $selectwhere SQL query syntax. 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.

Necessary decisions

1. We need to decide the event->level property.
2. How do we implement access control to log storages? New methods or fixed capability for reading? This would affect result of manager::get_readers().

Standard logging plugins

Standard Moodle distribution will include four plugins.

Logging management plugin (tool_logmanager)

Defines:

 class \tool_logmanager\log\manager implements \core\log\manager;

The log manager is responsible for step 1 from Figure 1 above. It allows admins to configure the kinds of events to store through each log storage plugin. The log storage plugins are implemented as new plugins plugin type with class "storage" in their namespace (\log_xxxx\log\storage).

The log manager can also return the list of available log readers, which are implemented as log plugins with class "storage" in their namespace (\core\log\reader or \core\log\writer).

Storage settings

In the default manager shipped with Moodle, an administrator can use a simple user interface to define what not to log in a specific \core\log\writer, as by default everything is logged.

• Include guests actions (default Yes).
• Only log level equal or higher than (default 0)
• Exclude by CRUD (default empty), accepts C, R, U, and D.
• Exclude by component (default empty)
• Exclude by event name (default empty)

This list of filters should not be too flexible or we could be affecting performances.

DB log storage plugin (log_db)

Defines:

 class \log_db\log\storage implements \core\log\sql_reader, \core\log\writer;

This log storage plugin is responsible for steps 2 and 3 from Figure 1 above. It is the primary replacement for the former {log} table. It is not likely to be more efficient than the former log table, but for smaller sites, this simple default will suffice.

Each plugin decides how much data is kept, when it is deleted, etc.

File system log storage plugin (log_file)

Defines:

 class \log_file\log\storage implements \core\log\writer;

This log storage plugin is responsible for step 2 only from Figure 1 above. There will be no interface to read from it provided with Moodle core. File writing in PHP is inefficient and does not scale well, so this plugin will not be suitable for large-scale production use. This plugin will serve as an example for simple log writer plugin implementations.

Legacy log table reader (log_legacy)

Defines:

 class \log_legacy\log\storage implements \core\log\reader;

This plugin will not conduct any log writing; it will translate existing {log} table data into the new event format and transforms new SQL selects to match the legacy table format. This serves as a simple emulation layer that allows new reports to access historical data stored in mdl_log table. users will have to select this datasource manually if they want to see historical data that is not present in new log tables.

Necessary decisions

1. How are we going to deal with database transactions? We can safely ignore them when storing data in Moodle database tables, all other storages including external databases must somehow buffer the data and get notifications from the DML layer.
2. Do we want to implement file logging? It would not be suitable for production, maybe we could implement support for some other write-only backend that will actually scale.

Mockups

Log storage Instance configuration page

Log storage instance configuration page

File log instance configuration page

File Log instance configuration page

Log management page

Log management page

Log management settings page

settings page for a database log setup

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, do not change existing implementation, allow admins to disable it
• provide hooks to expose logs everywhere. For example, each page should have a link that shows logs and stats for that page.

Tasks

1. Define all interfaces.
2. Define the expected log table structure with extra request information.
3. Add new log plugin type support in /lib/log/* directory.
4. Implement tool_logmanager.
5. Implement log_db.
6. Implement new log storage admin settings.
7. Implement new log storage filtering.
8. Optionally implement log_file or any other sample external storage.

Reports

Logging usage#Reports describes current reports.

Migration to new logging API

TODO

Tasks

1. Alter repors to accept new event object instances instead of array data.
2. Alter reports to understand new event properties.
3. Write tool_legacylog emulation reader - it needs to map new selects to old mdl_log table and it has to create new legacy event similar to standard logged events.
4. Rework statistics report to use new event data.

Related

Here are some ideas of how new even data and observers can be put to use:

• Please note that the log storage 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).

Logging of exceptions, errors and debugging:

• Logging of Errors and warnings is not part of this specification, it meeds to be handled via a completely separate mechanism.
  • People report errors that cannot be duplicated. Logging errors with a stack trace, session variables and other relevant data could be useful for debugging.
• Standard logs may theoretically produce errors and exceptions that need to be logged somewhere else.

Performance logging and profiling

We need to measure the performance of logging system and store the infomration somewhere.

Tasks:

• Explain what can and cannot be done with logging API.

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/