Improved logging in WooCommerce 2.7

One of the changes coming in 2.7 is an improved log system. We’ve made a significant effort to address the limitations of the logger with a focus on extensibility. In this post I’ll outline the changes that have been made and how you can start taking advantage of the new logger starting with the next 2.7 beta. Let’s have a look…

What’s changed

We’ve introduced the concept of log handlers. This change extracts how a log is handled from the logger itself. The core WC_Logger will continue to receive log messages, but it just passes logs to its registered handlers which must do something with that log. This makes it simpler to change the behavior of the logger without the need to replace it.

The function wc_get_logger has been introduced to return a shared logger instance. To get the instance of the site-wide logger, just call $logger = wc_get_logger(); and voilà, log away.

The core WC_Logger has been significantly rewritten to work with handlers. It also implements the methods described by the PSR-3 logger interface. PSR-3 is a standard specification of the logger interface, so implementing it will make it easier to find a replacement logger and it will be familiar if you have experience with other PSR-3 compatible loggers.

The new WC_Logger

The preferred way to interact with the logger is to retrieve the logger via wc_get_logger, then invoke one of the logging methods as follows:

$logger = wc_get_logger();

// $context may hold arbitrary data.
// If you provide a "source", it will be used to group your logs.
// More on this later.
$context = array( 'source' => 'my-extension-name' );

$logger->debug( 'Detailed debug information', $context );
$logger->info( 'Interesting events', $context );
$logger->notice( 'Normal but significant events', $context );
$logger->warning( 'Exceptional occurrences that are not errors', $context );
$logger->error( 'Runtime errors that do not require immediate', $context );
$logger->critical( 'Critical conditions', $context );
$logger->alert( 'Action must be taken immediately', $context );
$logger->emergency( 'System is unusable', $context );

// The `log` method accepts any valid level as its first argument.
$logger->log( 'debug', '<- Provide a level', $context );

Log levels

The methods debug, info, …, emergency are levels, and all log messages must now include a level. They express the severity of the log message from debug to emergency, lowest to highest. They are described in the IEFT RFC5424 spec:

Emergency: system is unusable
Alert: action must be taken immediately
Critical: critical conditions
Error: error conditions
Warning: warning conditions
Notice: normal but significant condition
Informational: informational messages
Debug: debug-level messages

Phew! That’s a lot of specs for one post! No more, I promise.

Logger methods

In addition to the 8 “level” methods, the log method accepts an arbitrary level as it’s first argument: $logger->log( 'info', 'An "info" level message.' );

All of the methods (except add) also accept a context array as the final argument. The context is an array of arbitrary information which may be used when handling the log. Include source in the context to have core handlers group log messages:

// The following messages will be grouped together
$logger->debug( 'debug message', array( 'source' => 'my-extension' ) );
$logger->info( 'another message', array( 'source' => 'my-extension' ) );

WC_Logger still exposes the add method, but only for backwards compatibility. add is not part of the PSR-3 specification and, although we’ve decided not to deprecate it in 2.7, it will most likely be deprecated and removed in the future. Here’s how you might update an add call to a PSR-3 compliant method:

// before
$logger->add( 'my-extension', 'The log message' );
// after (choose the most appropriate level)
$logger->info( 'The log message', array( 'source' => 'my-extension' ) );

Replacing the logger

If you want to replace the provided logger, you can do so via the woocommerce_logging_class filter. This filter affects the shared logger instance returned from wc_get_logger and should return a class name or instance implementing WC_Logger_Interface. The interface is new in 2.7 and helps to ensure that a replacement logger will be compatible for logging throughout the WooCommerce ecosystem.

function return_my_logger() { return 'My_Compatible_Logger_Class'; }
add_filter( 'woocommerce_logging_class', 'return_my_logger' );

// $logger will be an instance of My_Compatible_Logger_Class
$logger = wc_get_logger();

Keep in mind that wc_get_logger returns a shared instance, so your filter must be registered before the first invocation of wc_get_logger to have any effect.

The WC_Logger_Interface includes all the methods described by PSR-3 as well as the add method to maintain backwards compatibility. In order to implement WC_Logger_Interface, PSR-3 loggers must also implement the add method.

Log handlers

Log handlers are the solution in 2.7 to customize the core logger’s behavior. WC_Logger delegates all of its work to handlers by keeping an array of handlers and passing log message along to each of them. Core provides a few handlers to chose from.

File

WC_Log_Handler_File writes logs to a file which can be viewed on the WooCommerce admin status page or on the sever at wp-content/uploads/wc-logs/. File handling is essentially the same as previous logger behavior.

Database

WC_Log_Handler_DB writes logs to the database, which is pretty cool if you want to view, filter and sort logs right from the admin area. It comes with a shiny new interface on the WooCommerce admin status page. Check it out:

db-logs_720
Isn’t the DB log viewer pretty?

Configuration

WooCommerce will register a handler by default which can be configured by the constant WC_LOG_HANDLER, so you can add this to your wp-config.php to use the DB logger:

define( 'WC_LOG_HANDLER', 'WC_Log_Handler_DB' );

This constant should be the name of a log handler class. It determines the default handler as well as the viewer on the WooCommerce admin status page, so I recommend you use one of the core handlers.

If you want to register more handlers, you can use the filter woocommerce_register_log_handlers which should return an array of instantiated handlers, for example:

function add_my_handler( $handlers ) {
	array_push( $handlers, new My_Log_Handler() );
	return $handlers;
}
add_filter( 'woocommerce_register_log_handlers', 'add_my_handler' );

Implementing a handler

The only available handlers right now are those included with core, which makes log handlers a great opportunity for extensions. The only method a handler must implement is handle, and 2.7 includes the abstract WC_Log_Handler class which you can extend to implement your handler.

In addition to WC_Log_Handler_File and WC_Log_Handler_DB, core includes WC_Log_Handler_Email. The email handler is fully functional, but email is not a very good system for handling logs in general, so I don’t recommend you use it on an important production site. I do think it’s a great resource to look at for ideas about other handlers you might implement and how you might go about it.

A handler implementation will probably look something like this:

class My_New_Handler extends WC_Log_Handler {
	public function handle( $timestamp, $level, $message, $context ) {
		// Do something interesting with the message...
	}
}

Note: Handlers must implement WC_Log_Handler_Interface which includes the handle method. If you extend WC_Log_Handler, this is already taken care of. However, if you decide to implement your handler without extending, make sure it implements WC_Log_Handler_Interface.

Will the changes break my plugin/extension/site?

No! If you’re not interested in any of the new functionality, your code will continue to work as before with no changes. We’ve done our best to ensure that the logger remains backwards compatible. That said, $logger->add() is not part of the PSR-3 specification and, although it hasn’t been deprecated in 2.7, it may be deprecated or removed in the future. I encourage you to update your logging calls to use one of the new methods.

When can I start?

These changes are currently in master, so you could start bleeding-edge testing anytime. The new logger will be part of the next 2.7 beta.

Bonus

That’s right, there’s more! We’ve seen some extremely strict server environments which blacklist debugging functions such as print_r. That can make logging and debugging complicated, and may cause fatal errors if you try to call print_r! To help combat this problem, we’ve introduced wc_print_r as is part of core in 2.7. Think of it as a replacement for print_r:

wc_print_r( array( 1, 2, 3 ) );

will print

Array
(
    [0] => 1
    [1] => 2
    [2] => 3
)

If you want to return the string representation, provide true as the second argument just like print_r, for example:

$logger->alert( wc_print_r( $myvar, true ) );

Found a problem?

As always, just log an issue over at the WooCommerce issues page. Happy logging!


8 responses to “Improved logging in WooCommerce 2.7”

  1. That’s good news. The logger has always been a bit of a “weak spot” of WooCommerce. I replaced it with my own, PSR-3 compliant logger last year, which I use in my plugins, and that makes much easier to keep track of plugin’s activity.

    Most likely, I will keep using my own logger class, as it’s now tailored to my needs and won’t interfere with the one in WC 2.7, but I’m happy to see that we are on the same page. 🙂

    1. Jut tested: the interface of the new WC_Logger class matches the one I wrote, almost exactly. No notices, no “strict” messages. We are literally on the exact same page. +1 from me 🙂

  2. This is so much awesomeness!!!

  3. […] added new improved logging for […]

  4. […] logger  is PSR-3 compliant, powerful and flexible. We were pleased to hear that WooCommerce 2.7 will introduce a similar logger system, as it’s a proof that we have been, and we still are, on the right track. Our plugins will […]

  5. thanks, so much better

Leave a Reply

Your email address will not be published. Required fields are marked *