jsonlog.module in JSONlog 7

JSONlog module.

File

jsonlog.module

<?php

/**
 * @file
 * JSONlog module.
 */

/**
 * Default max. length of a log entry, in kilobytes.
 *
 * @type integer
 */
define('JSONLOG_TRUNCATE_DEFAULT', 4);

/**
 * Adds this module's setting fields to the system logging settings form.
 *
 * Implements hook_form_FORM_ID_alter().
 *
 * @param array &$form
 * @param array &$form_state
 */
function jsonlog_form_system_logging_settings_alter(&$form, &$form_state) {
  module_load_include('inc', 'jsonlog');
  $form['#attributes']['autocomplete'] = 'off';
  drupal_add_css(drupal_get_path('module', 'jsonlog') . '/jsonlog.admin.css', array(
    'type' => 'file',
    'group' => CSS_DEFAULT,
    'preprocess' => FALSE,
    'every_page' => FALSE,
  ));

  // Defaults.
  $siteid_default = jsonlog_default_site_id();
  if (!($file_default = jsonlog_default_file())) {
    drupal_set_message(t('Failed to establish the server\'s default logging directory.', array(), array(
      'context' => 'module:jsonlog',
    )), 'error');
  }

  // These translations are used a lot.
  $t_siteId = t('Site ID', array(), array(
    'context' => 'module:jsonlog',
  ));
  $t_overridden = t(' !sml¡overridden!!_sml', array(
    '!sml' => '<small>',
    '!_sml' => '</small>',
  ), array(
    'context' => 'module:jsonlog',
  ));

  // Using 'emergency' as threshold is simply not an option; because it's falsy (expensive type checks, FALSE), and wouldn't make sense anyway.
  $severity_levels = watchdog_severity_levels();
  unset($severity_levels[0]);
  $form['jsonlog'] = array(
    '#type' => 'fieldset',
    '#title' => 'JSON Log',
    '#description' => t('Any server variable \'drupal_[jsonlog_varable_name]\' will override \'[jsonlog_varable_name]\' conf. variable,!breakexcept for !emphtags!_emph (will be combined).', array(
      '!break' => '<br/>',
      '!emph' => '<em>',
      '!_emph' => '</em>',
    ), array(
      'context' => 'module:jsonlog',
    )) . '<br/>' . t('Tip: Server environment variables set in virtual host or .htaccess won\'t be visible by drush/CLI; /etc/environment might be your friend instead.', array(
      '!break' => '<br/>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#collapsible' => TRUE,
    '#collapsed' => FALSE,
  );

  // Severity threshold.
  if ($severity_threshold = getenv('drupal_jsonlog_severity_threshold')) {
    $overridden = TRUE;
  }
  else {
    $severity_threshold = variable_get('jsonlog_severity_threshold', WATCHDOG_WARNING);
    $overridden = FALSE;
  }
  $form['jsonlog']['jsonlog_severity_threshold'] = array(
    '#type' => 'select',
    '#title' => t('Don\'t log events that are less severe than !sml[jsonlog_severity_threshold]!_sml!overridden', array(
      '!overridden' => $overridden ? $t_overridden : '',
      '!sml' => '<small>',
      '!_sml' => '</small>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('Emergency is not an option.', array(), array(
      'context' => 'module:jsonlog',
    )),
    '#options' => $severity_levels,
    '#default_value' => $severity_threshold,
  );
  if ($overridden) {
    $form['jsonlog']['jsonlog_severity_threshold']['#attributes'] = array(
      'disabled' => 'disabled',
    );
  }

  // Truncation.
  if (($truncate = getenv('drupal_jsonlog_truncate')) !== FALSE) {
    $overridden = TRUE;
  }
  else {
    $truncate = variable_get('jsonlog_truncate', JSONLOG_TRUNCATE_DEFAULT);
    $overridden = FALSE;
  }
  $form['jsonlog']['jsonlog_truncate'] = array(
    '#type' => 'textfield',
    '#title' => t('Truncate events to !sml[jsonlog_truncate]!_sml!overridden', array(
      '!overridden' => $overridden ? $t_overridden : '',
      '!sml' => '<small>',
      '!_sml' => '</small>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('Zero means no truncation.!breakLog entries longer than the file system\'s block size may result in garbled logs, due to concurrent file writes.!breakThe default block size of ext3 (common *nix file system) is !default Kb.', array(
      '!default' => JSONLOG_TRUNCATE_DEFAULT,
      '!break' => '<br/>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#default_value' => $truncate,
    '#size' => 5,
    '#field_suffix' => t('Kb', array(), array(
      'context' => 'module:jsonlog',
    )),
  );
  if ($overridden) {
    $form['jsonlog']['jsonlog_truncate']['#attributes'] = array(
      'disabled' => 'disabled',
    );
  }

  // Site ID.
  if ($site_id = getenv('drupal_jsonlog_siteid')) {
    $overridden = TRUE;
  }
  else {
    if (!($site_id = variable_get('jsonlog_siteid'))) {
      $site_id = $siteid_default;
    }
    $overridden = FALSE;
  }
  $form['jsonlog']['jsonlog_siteid'] = array(
    '#type' => 'textfield',
    '#title' => t('Site ID !sml[jsonlog_siteid]!_sml!overridden', array(
      '!overridden' => $overridden ? $t_overridden : '',
      '!sml' => '<small>',
      '!_sml' => '</small>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('Spaces and quotes get replaced by hyphens.!breakDefaults to the server\'s hostname and the site\'s database name and prefix (if any):!break!default', array(
      '!default' => '&nbsp; ' . $siteid_default,
      '!break' => '<br/>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#required' => TRUE,
    '#default_value' => $site_id,
  );
  if ($overridden) {
    $form['jsonlog']['jsonlog_siteid']['#attributes'] = array(
      'disabled' => 'disabled',
    );
  }

  // File.
  if ($file = getenv('drupal_jsonlog_file')) {
    $overridden = TRUE;
  }
  else {
    if (!($file = variable_get('jsonlog_file'))) {
      $file = $file_default;
    }
    $overridden = FALSE;
  }
  $form['jsonlog']['jsonlog_file'] = array(
    '#type' => 'textfield',
    '#title' => t('Log file !sml[jsonlog_file]!_sml!overridden', array(
      '!overridden' => $overridden ? $t_overridden : '',
      '!sml' => '<small>',
      '!_sml' => '</small>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('Defaults to PHP ini \'error_log\' path + /drupal-jsonlog/ + !site_id:!break!default!breakNB: The web server user (www-data|apache) probably isn\'t allowed to write to a file in the \'error_log\' path!break- create a sub dir (like \'drupal-jsonlog\') as root user, and do a chown or chmod on that sub dir.', array(
      '!default' => '&nbsp; ' . $file_default,
      '!site_id' => $t_siteId,
      '!break' => '<br/>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#required' => TRUE,
    '#default_value' => $file,
    '#size' => 100,
  );
  if ($overridden) {
    $form['jsonlog']['jsonlog_file']['#attributes'] = array(
      'disabled' => 'disabled',
    );
  }

  // Test logging.
  $form['jsonlog']['jsonlog_test_filing'] = array(
    '#type' => 'checkbox',
    '#title' => t('Test filing a JSONlog entry', array(), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('You\'ll be warned and guided along if it doesn\'t work correctly.', array(), array(
      'context' => 'module:jsonlog',
    )),
    '#default_value' => 0,
    '#title_display' => 'before',
  );

  // Tags.
  $tags_server = ($tags = getenv('drupal_jsonlog_tags')) !== FALSE ? $tags : '';
  $form['jsonlog']['jsonlog_tags'] = array(
    '#type' => 'textfield',
    '#title' => t('Tags !sml[jsonlog_tags]!_sml', array(
      '!sml' => '<small>',
      '!_sml' => '</small>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#description' => t('Comma-separated list of tags.!breakTags set by server environment variable will be combined with tags set here.', array(
      '!break' => '<br/>',
    ), array(
      'context' => 'module:jsonlog',
    )),
    '#default_value' => $tags_site = variable_get('jsonlog_tags', ''),
    '#size' => 100,
    '#field_prefix' => $tags_server !== '' ? $tags_server . ', ' : '',
  );

  // Make table view of a log entry.
  // ISO 8601 timestamp.
  $millis = round(microtime(TRUE) * 1000);
  $seconds = (int) floor($millis / 1000);
  $millis -= $seconds * 1000;
  $millis = str_pad($millis, 3, '0', STR_PAD_LEFT);
  $timestamp = substr(gmdate('c', $seconds), 0, 19) . '.' . $millis . 'Z';
  if ($tags_server) {
    $tags = $tags_server;
    if ($tags_site) {
      $tags .= ',' . $tags_site;
    }
  }
  else {
    $tags = $tags_site;
  }
  if ($tags) {
    $tags = '[\'' . join('\',\'', explode(',', $tags)) . '\']';
  }
  else {
    $tags = 'null';
  }

  // JSON fields.
  $json_fields = array(
    'message' => array(
      'label' => t('Message', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => t('Some message', array(), array(
        'context' => 'module:jsonlog',
      )),
    ),
    'timestamp' => array(
      'label' => t('Timestamp', array(), array(
        'context' => 'module:jsonlog',
      )),
      'name' => '@timestamp',
      'value' => $timestamp,
    ),
    'version' => array(
      'custom' => TRUE,
      'name' => '@version',
      'label' => t('Version', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => 1,
    ),
    'message_id' => array(
      'custom' => TRUE,
      'name' => 'message_id',
      'label' => t('Message ID (!site_id + unique ID)', array(
        '!site_id' => $t_siteId,
      ), array(
        'context' => 'module:jsonlog',
      )),
      'value' => uniqid($site_id, TRUE),
    ),
    'site_id' => array(
      'custom' => TRUE,
      'name' => 'site_id',
      'label' => $t_siteId,
      'value' => $site_id,
    ),
    'tags' => array(
      'custom' => TRUE,
      'name' => 'tags',
      'label' => t('Tags (null or array of strings)', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $tags,
    ),
    'type' => array(
      'label' => t('Type', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => 'some_module_name',
    ),
    'severity' => array(
      'label' => t('Severity', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $severity_threshold,
    ),
    'method' => array(
      'custom' => TRUE,
      'name' => 'method',
      'label' => t('Request method (GET, POST, cli)', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $_SERVER['REQUEST_METHOD'],
    ),
    'request_uri' => array(
      'label' => t('Request URI', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $GLOBALS['base_root'] . request_uri(),
    ),
    'referer' => array(
      'label' => t('Referer', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => isset($_SERVER['HTTP_REFERER']) ? check_plain($_SERVER['HTTP_REFERER']) : '',
    ),
    'uid' => array(
      'label' => t('User ID', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $uid = $GLOBALS['user']->uid,
    ),
    'username' => array(
      'custom' => TRUE,
      'name' => 'username',
      'label' => t('Username (when not anonymous user)', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => $uid && !empty($GLOBALS['user']->name) ? $GLOBALS['user']->name : '',
    ),
    'ip' => array(
      'name' => 'client_ip',
      'label' => t('User\'s I.P. address', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => ip_address(),
    ),
    'link' => array(
      'label' => t('Link', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => '',
    ),
    'variables' => array(
      'label' => t('Variables (null or object hash map)', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => '',
    ),
    'truncation' => array(
      'custom' => TRUE,
      'name' => 'trunc',
      'label' => t('Truncation (null, or array [original message length, truncated message length])', array(), array(
        'context' => 'module:jsonlog',
      )),
      'value' => NULL,
    ),
  );
  $table_header = array(
    t('Property', array(), array(
      'context' => 'module:jsonlog',
    )),
    t('JSON field name', array(), array(
      'context' => 'module:jsonlog',
    )),
    t('Example', array(), array(
      'context' => 'module:jsonlog',
    )),
  );
  $table_rows = array();
  foreach ($json_fields as $name => $props) {
    $table_rows[] = array(
      'data' => array(
        $props['label'],
        !empty($props['name']) ? $props['name'] : $name,
        $props['value'],
      ),
    );
  }
  $form['jsonlog']['example'] = array(
    '#type' => 'markup',
    '#markup' => '<label>' . t('JSONlog entry example', array(), array(
      'context' => 'module:jsonlog',
    )) . '</label>' . theme_table(array(
      'header' => $table_header,
      'rows' => $table_rows,
      'attributes' => array(
        'class' => array(
          'jsonlog-entry-example',
        ),
      ),
      'caption' => '',
      'colgroups' => array(),
      'sticky' => TRUE,
      'empty' => '',
    )),
  );
  $form['#validate'][] = 'jsonlog_form_system_logging_settings_validate';

  // Prepend our submit handler; we need to get in first, otherwise our changes to form values amounts to nothing.
  array_unshift($form['#submit'], 'jsonlog_form_system_logging_settings_submit');
  return system_settings_form($form);
}

/**
 * @param array $form
 * @param array $form_state
 */
function jsonlog_form_system_logging_settings_validate($form, $form_state) {
  $values =& $form_state['values'];

  // Non-empty truncate must be non-negative integer.
  if ($values['jsonlog_truncate'] !== '' && ($value = trim($values['jsonlog_truncate'])) !== '') {
    if (!preg_match('/^\\d+$/', $value)) {
      form_set_error('jsonlog_truncate', t('\'@field\' is not a non-negative integer.', array(
        '@field' => t('Truncate events to'),
      )));
    }
  }
}

/**
 * Custom submit handler for the system logging settings form.
 *
 * @param array $form
 * @param array $form_state
 */
function jsonlog_form_system_logging_settings_submit($form, &$form_state) {
  $values =& $form_state['values'];
  $file = '';
  $fields = array(
    'jsonlog_severity_threshold',
    'jsonlog_truncate',
    'jsonlog_siteid',
    'jsonlog_file',
  );
  foreach ($fields as $name) {

    // Trim all values.
    $values[$name] = trim($values[$name]);
    switch ($name) {
      case 'jsonlog_truncate':
        if (!$values['jsonlog_truncate']) {
          $values['jsonlog_truncate'] = 0;
        }
        break;
      case 'jsonlog_file':
        if ($values['jsonlog_file']) {
          $file = $values['jsonlog_file'];
        }
        break;
    }
  }

  // Tags.
  if (($values['jsonlog_tags'] = $v = trim($values['jsonlog_tags'])) !== '') {
    $v = str_replace(array(
      "\r",
      "\n",
    ), '', $v);
    if ($v !== '') {
      if ($v[0] === ',') {
        $v = substr($v, 1);
      }
      if ($v !== '') {
        if ($v[strlen($v) - 1] === ',') {
          $v = substr($v, 0, strlen($v) - 1);
        }
      }
      if (strpos($v, ',')) {
        $v = preg_replace('/ *, */', ',', $v);
      }
    }
    $values['jsonlog_tags'] = trim($v);
  }

  // Test.
  if ($values['jsonlog_test_filing']) {
    module_load_include('inc', 'jsonlog');
    jsonlog_test_filing($file ? $file : jsonlog_default_file());
  }

  // Don't ever save that field.
  unset($form_state['input']['jsonlog_test_filing'], $values['jsonlog_test_filing']);
}

/**
 * Logs any watchdog call - at or above a certain severity threshold - as JSON to a custom log file.
 *
 * Default severity threshold: warning.
 *
 * Prefers server environment variables for Drupal conf variables.
 * Any jsonlog conf variable may be overridden by a 'drupal_[jsonlog variable]' server environment var.
 *
 *  JSON fields (watchdog standard fields are not explained here):
 *  - \@timestamp: ISO-8601 milliseconds timestamp instead of watchdog's native seconds timestamp
 *  - \@version: (always) 1
 *  - message_id: jsonlog site ID + unique padding
 *  - site_id: (default) server's hostname + database name + database prefix (if any)
 *  - tags: comma-separated list; becomes array
 *  - type
 *  - severity
 *  - method: HTTP request method, or 'cli' (if drush)
 *  - request_uri
 *  - referer
 *  - uid
 *  - username: name of current user, or empty
 *  - client_ip: equivalent to watchdog standard 'ip' field
 *  - link
 *  - variables: watchdog standard, except null if empty
 *  - trunc: null if the log entry as a whole doesn't exceed the json_truncate setting; otherwise array of original length, truncated length
 *
 * Implements hook_watchdog().
 *
 * @param array $log_entry
 */
function jsonlog_watchdog(array $log_entry) {
  static $_threshold, $_site_id, $_file, $_truncate, $_severity, $_tags;

  // Don't load more settings than threshold, in case current entry isn't sufficiently severe.
  if (!$_threshold) {

    // A threshold of zero (emergency) wouldnt make sense in the real world, so no reason to check by type (boolean).
    if (!($_threshold = getenv('drupal_jsonlog_severity_threshold'))) {
      $_threshold = variable_get('jsonlog_severity_threshold', WATCHDOG_WARNING);
    }
  }

  // Severity is upside down; less is more.
  if ($log_entry['severity'] > $_threshold) {
    return;
  }

  // Load the rest of the settings.
  if (!$_site_id) {

    // Site ID: Try server environment var before Drupal conf. var.
    if (!($_site_id = getenv('drupal_jsonlog_siteid'))) {
      if (!($_site_id = variable_get('jsonlog_siteid'))) {
        module_load_include('inc', 'jsonlog');
        variable_set('jsonlog_siteid', $_site_id = jsonlog_default_site_id());
      }
    }

    // File: Try server environment var before Drupal conf. var.
    if (!($_file = getenv('drupal_jsonlog_file'))) {
      if (!($_file = variable_get('jsonlog_file'))) {
        module_load_include('inc', 'jsonlog');
        if ($_file = jsonlog_default_file()) {
          variable_set('jsonlog_file', $_file);
        }
        else {
          error_log('Drupal jsonlog, site ID[' . $_site_id . '], failed to establish server\'s default log dir.');
        }
      }
    }

    // Truncation: Try server environment var before Drupal conf. var.
    if (($_truncate = getenv('drupal_jsonlog_truncate')) === FALSE) {
      $_truncate = variable_get('jsonlog_truncate', JSONLOG_TRUNCATE_DEFAULT);
    }
    if ($_truncate) {

      // Kb to bytes.
      $_truncate *= 1024;

      // Substract estimated max length of everything but message content.
      $_truncate -= 768;

      // Message will get longer when JSON encoded, because of hex encoding of <>&" chars.
      $_truncate *= 7 / 8;
    }
    $_severity = array(
      'emergency',
      'alert',
      'critical',
      'error',
      'warning',
      'notice',
      'info',
      'debug',
    );

    // Tags: append Drupal conf. var to server env. var.
    $tags_server = ($tags = getenv('drupal_jsonlog_tags')) !== FALSE ? $tags : '';
    $tags_site = variable_get('jsonlog_tags', '');
    if ($tags_server) {
      $tags = $tags_server;
      if ($tags_site) {
        $tags .= ',' . $tags_site;
      }
    }
    else {
      $tags = $tags_site;
    }
    if ($tags) {
      $_tags = explode(',', $tags);
    }
  }

  // Create the entry.
  $entry = new stdClass();

  // Strip tags if message starts with < (Inspect logs in tag).
  if (($message = $log_entry['message']) && $message[0] === '<') {
    $message = strip_tags($message);
  }

  // Escape newline, (drupal_)json_encode() doesn't escape control characters (Inspect uses newline).
  // Escape null control char.
  $message = str_replace(array(
    "\n",
    "\0",
  ), array(
    '\\n',
    '_NUL_',
  ), $message);

  // If truncation required, start by skipping variables.
  $variables = $log_entry['variables'];

  // Truncate message.
  if ($_truncate && ($le = strlen($message)) > $_truncate) {

    // Deliberately not drupal_strlen(); need 'physical' length, not (possibly shorter) multibyte length.
    // Flag variables truncated by setting it to false.
    if ($variables) {
      $variables = FALSE;
    }

    // Truncate multibyte safe until ASCII length is equal to/less than max. byte length.
    $truncation = array(
      $le,
      strlen($message = drupal_truncate_bytes($message, (int) $_truncate)),
    );
  }
  else {
    $truncation = NULL;
  }
  $entry->message = $message;
  unset($message);

  // Use a milliseconds timestamp instead of watchdog()'s seconds timestamp.
  $millis = round(microtime(TRUE) * 1000);
  $seconds = (int) floor($millis / 1000);
  $millis -= $seconds * 1000;
  $millis = str_pad($millis, 3, '0', STR_PAD_LEFT);
  $entry->{'@timestamp'} = substr(gmdate('c', $seconds), 0, 19) . '.' . $millis . 'Z';
  $entry->{'@version'} = 1;
  $entry->message_id = uniqid($_site_id, TRUE);
  $entry->site_id = $_site_id;
  $entry->tags = $_tags;
  $entry->type = $log_entry['type'];
  $entry->severity = $_severity[$log_entry['severity']];
  $entry->method = !empty($_SERVER['REQUEST_METHOD']) ? $_SERVER['REQUEST_METHOD'] : 'cli';
  $entry->request_uri = $log_entry['request_uri'];
  $entry->referer = $log_entry['referer'];
  $entry->uid = $uid = $log_entry['uid'];
  $entry->username = $uid && !empty($GLOBALS['user']->name) ? $GLOBALS['user']->name : '';
  $entry->client_ip = $log_entry['ip'];
  $entry->link = !$log_entry['link'] ? NULL : strip_tags($log_entry['link']);
  $entry->variables = $variables ? $variables : NULL;
  $entry->trunc = $truncation;

  // File append, using lock (write, doesn't prevent reading).
  // If failure: log filing error to web server's default log.
  if (!file_put_contents($_file, "\n" . drupal_json_encode($entry), FILE_APPEND | LOCK_EX)) {
    error_log('Drupal jsonlog, site ID[' . $_site_id . '], failed to write to file[' . $_file . '].');
  }
}

Functions

Name	Description
jsonlog_form_system_logging_settings_alter	Adds this module's setting fields to the system logging settings form.
jsonlog_form_system_logging_settings_submit	Custom submit handler for the system logging settings form.
jsonlog_form_system_logging_settings_validate	_state
jsonlog_watchdog	Logs any watchdog call - at or above a certain severity threshold - as JSON to a custom log file.

Constants

Name	Description
JSONLOG_TRUNCATE_DEFAULT	Default max. length of a log entry, in kilobytes.