Debugging is an integral part of any development process, and the time it requires tends to add up to a significant part of the total development time. Therefore, it is wise to consider various debugging tools and select the one that fits your working habits and conditions best to save time.
Among the aspects of debugging, logging debug messages is the one that I believe is most relevant in Drupal development. In this post, I am reviewing three different options to log events or messages in Drupal.
Printing Log Messages on the Web Page
Let me start with the simplest and most trivial one: using drupal_set_message() to print debugging data on the page. Normally used to show messages to the user, this function is perfectly suitable for debugging. By invoking this function with the log message as its first parameter, it will print the message in the Drupal message area when the page is reloaded.
For example, you can use this to check whether a certain part of the code gets executed. If you also need to check the content of a variable, you can use this function to print the variable. One thing to keep in mind is that the function takes a string as its parameter. If you need to print a more complex variable – an object or an array -- it needs to be converted to a human readable format using print_r(), as the following excerpt illustrates. The second parameter of print_r() tells it to return the output as opposed to printing it out directly.
drupal_set_message(print_r($my_var, TRUE));
Because this function takes part in Drupal’s page rendering process, there are certain pitfalls to using it for debugging. Here are some pitfalls I have experienced:
- It is not suitable to debug cached pages. Calling drupal_set_message() prevents the page from being served from cache or being saved to cache. This has rarely been a problem for me, but it is good to be aware of.
- It might be cumbersome to investigate large objects and arrays. If you try to print out something as huge as a view object, for example, the page will load slowly, and the printed variable will not be easily readable due to the limitations of the page width.
- It is too late to call drupal_set_message() in template files. If you do so, the message will only appear after one extra page reload.
- Messages are not persistent. If the output is data that you will need in the future, be sure to copy it somewhere else.
If you use this method, you can make good use of the Devel module as well, which defines a wrapper function around drupal_set_message(). With Devel module, you can just type dpm() instead, and this function can handle objects and arrays directly – in addition to being easier to type. Furthermore, it prints objects and arrays with the Krumo debugging tool, which prints complex variables in a collapsible structured way, making it easier to handle.
An alternative to drupal_set_message() would be to print the message directly using print or echo. This way, we would not be interfering with Drupal’s page rendering process. However, these messages could be sent to the browser right in the middle of the page rendering process, whereas Drupal normally renders everything first and sends the entire output to the browser at once. As a result, the printed message will appear at unpredictable locations on the page with an unpredictable formatting.
Saving to the Database
Drupal provides the watchdog() function to log debug messages to the database. Everything passed to it will be saved in the watchdog table, along with additional data regarding the page request, like the requesting user and url. Similarly to drupal_set_message(), watchdog() takes a string, so objects and arrays need to be sent through print_r().
This method does not interfere with the page rendering process, so it might be preferred in some cases. Messages can be viewed on Drupal’s admin interface at admin/reports/dblog. One downside is somewhat inconvenient to access the data. On the log page, you only see a list of entries, but not the actual message. To see the message, you need to click on the entry to load a new page with the message.
There is a module that makes this process one step easier. The Devel Debug Log module (which was authored by myself) provides a page that displays an auto-refreshing list of recent entries. It relies on Devel and uses its Krumo tool to print complex variables.
Of course, this method is not useful for troubleshooting database related bugs.
Saving to a File
I consider this the most versatile form of logging messages. It does its job independently of the Drupal ecosystem, and has no prerequisites, like saving to the database necessitates a working database connection. You only need to be certain that write permission is set on the output file.
To log messages to a file, create a simple function containing only the few lines shown in the snippet below. From then on, log_to_file($message) can be called to log a message. This, by the way, can be used on any PHP-based site, and not just Drupal.
function log_to_file($text) {
$f = fopen('my_log.txt', 'a');
fwrite($f, date('Ymd H:i:s - ') . $text . "\n");
fclose($f);
}
The example function also prepends the current time to the message so that it is easier to identify various entries.
The part I like most about this method is that one can open a console window and use the tail command to view the file’s contents such that new content is continuously being displayed as anything is written to the file. The actual command to do this is as follows:
tail –f my_log.txt
The excellent Devel module implements this method also. One can use its drupal_debug() function out of the box, without having to write any functions.
