Skip to content

Commit

Permalink
adding single-file mode and log truncation
Browse files Browse the repository at this point in the history
  • Loading branch information
@123andy
123andy committed May 4, 2021
1 parent 5a72592 commit 0e66b24
Show file tree
Hide file tree
Showing 3 changed files with 104 additions and 30 deletions.
20 changes: 15 additions & 5 deletions README.md
View file
Original file line number Diff line number Diff line change
@@ -1,20 +1,31 @@
# emLogger Utility

This is a utility logging external module. It is intended to be enabled on your server and configured with a physical directory where the log files will be saved. We use this on many of our external modules so we can easily track logs without clogging the REDCap logs.
This is a utility logging external module. It is intended to be enabled on your server and configured with a physical
directory where the log files will be saved. We use this on many of our external modules so we can easily track logs
without clogging the REDCap logs.

A module that uses the emLogger should 'fail gracefully' - meaning that if you do not have this module enabled on your server, it should behave as it normally would but just not log.
A module that uses the emLogger should 'fail gracefully' - meaning that if you do not have this module enabled on your
server, it should behave as it normally would but just not log.

## Configuring

Upon enabling this external module you must configure it with:
* path where all logs will be stored (e.g. `/var/log/redcap/`)
* turn on/off TSV logging
* turn on/off json logging - we use splunk and the json-level logging can be easily indexed and searched
* turn on/off json logging

You must enable either TSV or JSON logging or else no logs will be created.

### Single File Mode
To support easy scraping of log files using fluentd with kubernetes, we added an option that aggregates all log entries
into a single file with a new prefix attribute. Optionally, if you use this mode, you can also enable a weekly cron
task that will erase your logs on a weekly basis.

## Usage

This module is actually used by other external modules. If the other module was already built to use this, there isn't much of anything you need to do. In the other module there may be options to control the logging levels.
This module is used by other external modules (typically written at Stanford). If the other module was already built
to use this, there isn't much of anything you need to do. In the other modules should support configuration at either
the system or project level to control the logging output.

If you are building a new module and want to add emLogger to it, follow these directions:

Expand Down Expand Up @@ -50,7 +61,6 @@ $q = REDCap::getData('array',..);
$this-emDebug("Loaded data", $q);`
```


emLog and emError are always written to log file. If you wish to enable 'debug' logging (which is normally turned off) - you can add these options to your EM's config.json file so end-users can turn this level of logging on or off. For example, add these two system and project-level settings:

```json
Expand Down
41 changes: 35 additions & 6 deletions config.json
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,19 @@

"namespace":"Stanford\\emLogger",

"description": "Logging utility used by other external modules",
"description": "An optional logging utility used by many other external modules built at Stanford. If configured, other modules will write out error, debugging and other log information to the file path specified in the config.",

"documentation": "README.md",

"versions": [
{ "0.1": "Initial" }
{
"0.1": "Initial",
"0.2": "5/4/2021 Added support for a single-file mode"
}
],

"framework-version": 5,

"authors": [
{
"name": "Andrew Martin",
Expand All @@ -25,6 +30,7 @@
],

"permissions": [
"redcap_module_save_configuration"
],

"links": {
Expand All @@ -37,18 +43,18 @@
"system-settings": [
{
"key": "instructions",
"name": "<div class='alert alert-warning'><b>You should leave the top two checkboxes (Enable module and Make Discoverable) UNCHECKED.<br>The logging features will still be available to other modules even if it is not enabled on a per-project basis</b><br/>You can leave both log options unchecked to deactivate any logging. If you are expecting logs and not seeing then, make sure the module that is logging has debug logs enabled in the external module configuration page for that module</div>",
"name": "<div class='alert alert-warning'><b>You should leave the top three checkboxes (Enable module and Make Discoverable and Allow users to enable) UNCHECKED.</b><br/>The logging features will still be available to other modules even if it is not enabled on a per-project basis<br/>You can leave both log options unchecked to deactivate any logging. If you are expecting logs and not seeing then, make sure the module that is logging has debug logs enabled in the external module configuration page for that module</div>",
"type": "descriptive"
},
{
"key": "base-server-path",
"name": "<b>Base path on server where logs are written</b><br>(e.g. /var/log/redcap/ - include ending slash)",
"name": "<b>Base path on server where logs are written</b><br>(<i>e.g.</i> <code>/var/log/redcap/</code> - <u>don't forget to include ending slash</u>)",
"required": true,
"type": "text"
},
{
"key": "log-json",
"name": "<b>Check to log in json format (includes backtrace info)</b>",
"name": "<b>Check to log in json format</b><br><i>(emError logs will include a backtrace)",
"required": false,
"type": "checkbox"
},
Expand All @@ -57,7 +63,30 @@
"name": "<b>Check to log in tab-separated-value (TSV) format</b>",
"required": false,
"type": "checkbox"
},
{
"key": "single-file",
"name": "<b>Single-File mode</b><br/>If checked, all logs will be output to a single with the module-name attribute included as a parameter. This was added to support easy logging to kubernetes and splunk where the output file is processed and can be sorted by module in logging software",
"required": false,
"type": "checkbox"
},
{
"key": "single-file-cleanup",
"name": "<b>Enable Weekly Log File Clearing</b><br/>If checked and using single-file mode, a cron job will clear the single log file every Sunday a midnight to prevent it from growing too large. This is designed for cases where you are shipping your logs off the server to another tool",
"required": false,
"type": "checkbox"
}
]

],

"crons": [
{
"cron_name": "truncate_logs_cron",
"cron_description": "A weekly cron to clear out the log file every Sunday at midnight",
"method": "truncateLogsCron",
"cron_hour": 0,
"cron_minute": 0,
"cron_weekday": 0
}
]
}
73 changes: 54 additions & 19 deletions emLogger.php
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,19 +6,35 @@ class emLogger extends \ExternalModules\AbstractExternalModule
{
private $log_json;
private $log_tsv;
private $single_file; // If set, all logs will output to a single file - emLogger.tsv or emLogger.json
private $base_server_path;
private $ts_start;

function __construct()
{
parent::__construct();
$this->log_json = $this->getSystemSetting('log-json');
$this->log_tsv = $this->getSystemSetting('log-tsv');

$settings = $this->getSystemSettings();
$this->ts_start = microtime(true);

$this->log_json = $this->getSystemSetting('log-json');
$this->log_tsv = $this->getSystemSetting('log-tsv');
$this->single_file = $this->getSystemSetting('single-file');
$this->base_server_path = $this->getSystemSetting('base-server-path');
$this->ts_start = microtime(true);
}


public function redcap_module_save_configuration($project_id = null) {
// Try saving
$this->emLog("emLogger", "Configuration Updated", "INFO", false);
}


/**
* Is the payload string a valid JSON object
* @param $string
* @return bool
*/
function isJson($string) {
json_decode($string);
return (json_last_error() == JSON_ERROR_NONE);
Expand All @@ -33,14 +49,19 @@ function isJson($string) {
* @param null $fix_backtrace (optional parameter to assist when nesting logging functions)
* @throws \Exception
*/
function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null) {
function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null, $flags = FILE_APPEND) {

// FILENAME
$filename = $this->base_server_path . $file_prefix;
if ($this->single_file) {
$filename = $this->base_server_path . "emLogger";
} else {
$filename = $this->base_server_path . $file_prefix;
}

// BACKTRACE (remove one from this logging class)
$bt = debug_backtrace();
$bt = debug_backtrace(2);

// FIX START OF BACKTRACE
/* In cases where you call this log function from a parent object's log function, you really are interested
in the backtrace from one level higher. To make the logic work, we strip off the last backtrace array
element. If, on the other hand, you simply instantiate this and call it from a script, you will not need
Expand All @@ -49,15 +70,16 @@ function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null) {
To summarize, if you wrap this in a parent object, call it with methods 'log,debug, or error' and everything
should work.
*/
// If you do not specify, we 'guess' if we should fix the backtrace by looking at the name of the function 1 level up
If you do not specify the 4th argument, we 'guess' if we should fix the backtrace by looking at the name
of the function 1 level up
*/
if (isset($bt[1]["function"])
&& in_array($bt[1]['function'], array("log","debug","error","emLog","emDebug","emError"))
&& is_null($fix_backtrace)) $fix_backtrace = true;

// PARSE BACKTRACE
if ($fix_backtrace) array_shift($bt);

// PARSE BACKTRACE
$function = isset($bt[1]['function']) ? $bt[1]['function'] : "";
$file = isset($bt[0]['file']) ? $bt[0]['file'] : "";
$line = isset($bt[0]['line']) ? $bt[0]['line'] : "";
Expand All @@ -75,16 +97,17 @@ function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null) {
$username = defined('USERID') ? USERID : "";
if (empty($username)) $username = "-";


// PARSE ARGUMENTS:
// Convert into an array in the event someone passes a string or other variable type
if (!is_array($args)) $args = array($args);

if ($this->log_json) {

// Add context to args
$args_detail = array();
$args_detail = [];
$i = 1;
foreach ($args as $arg) {
$detail = array();
$detail = [];

$arg_type = gettype($arg);
if ($arg_type == "string") {
Expand All @@ -111,22 +134,25 @@ function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null) {
"pid" => $pid,
"username" => $username,
"args" => $args_detail,
//"args1" => $args,
"file" => $file,
"line" => $line,
"function" => $function,
"runtime" => $runtime
);

if ($type == "DEBUG") $entry['backtrace'] = $bt;
// Add the prefix in single-file mode
if($this->single_file) $entry['prefix'] = $file_prefix;

$file_suffix = "_log.json";
if ($type == "ERROR") $entry['backtrace'] = $bt;

$file_suffix = ".json";
$log = json_encode($entry) . "\n";

// WRITE TO FILE
$this->write($filename . $file_suffix, $log, FILE_APPEND);
$this->write($filename . $file_suffix, $log, $flags);
} //json


if ($this->log_tsv) {
$entries = array();

Expand Down Expand Up @@ -167,14 +193,15 @@ function emLog($file_prefix, $args, $type = "INFO", $fix_backtrace = null) {
"obj" => $obj,
"msg" => $msg
);
$entries[] = implode("\t", $entry);

if ($this->single_file) $entry = array("prefix" => $file_prefix) + $entry;
$entries[] = implode("\t", $entry);
} // loop
$file_suffix = ".log";
$log = implode("\n", $entries) . "\n";

// WRITE TO FILE
$this->write($filename . $file_suffix, $log, FILE_APPEND);
$this->write($filename . $file_suffix, $log, $flags);
} // tsv

} // log
Expand All @@ -187,4 +214,12 @@ function write($filename, $data, $flags) {
}
}

public function truncateLogsCron($cron) {
if ($this->single_file) {
$this->emLog($this->PREFIX, "About to truncate log - to disable edit the emLogger configuration");
sleep(30); // Give the log parser a chance to detect this log entry...
$this->emLog($this->PREFIX, "Logs Truncated - to disable edit the emLogger configuration","INFO",false,0);
}
}

} // class

0 comments on commit 0e66b24

Please sign in to comment.