Import Ruty
This commit is contained in:
@@ -0,0 +1,24 @@
|
||||
{
|
||||
"name": "roundcube/debug_logger",
|
||||
"type": "roundcube-plugin",
|
||||
"description": "Enhanced logging for debugging purposes. It is not recommended to be enabled on production systems without testing because of the somewhat increased memory, cpu and disk i/o overhead.",
|
||||
"license": "GPL-3.0-or-later",
|
||||
"version": "1.0",
|
||||
"authors": [
|
||||
{
|
||||
"name": "Ziba Scott",
|
||||
"email": "ziba@umich.edu",
|
||||
"role": "Lead"
|
||||
}
|
||||
],
|
||||
"repositories": [
|
||||
{
|
||||
"type": "composer",
|
||||
"url": "https://plugins.roundcube.net"
|
||||
}
|
||||
],
|
||||
"require": {
|
||||
"php": ">=7.3.0",
|
||||
"roundcube/plugin-installer": ">=0.1.3"
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,159 @@
|
||||
<?php
|
||||
|
||||
/**
|
||||
* Debug Logger
|
||||
*
|
||||
* Enhanced logging for debugging purposes. It is not recommended
|
||||
* to be enabled on production systems without testing because of
|
||||
* the somewhat increased memory, cpu and disk i/o overhead.
|
||||
*
|
||||
* Debug Logger listens for existing rcube::console() calls and
|
||||
* introduces start and end tags as well as free form tagging
|
||||
* which can redirect messages to files. The resulting log files
|
||||
* provide timing and tag quantity results.
|
||||
*
|
||||
* Enable the plugin in config.inc.php and add your desired
|
||||
* log types and files.
|
||||
*
|
||||
* @author Ziba Scott
|
||||
* @website http://roundcube.net
|
||||
*
|
||||
* Example:
|
||||
*
|
||||
* // $config['debug_logger'][type of logging] = name of file in log_dir
|
||||
* // The 'master' log includes timing information
|
||||
* $config['debug_logger']['master'] = 'master';
|
||||
* // If you want sql messages to also go into a separate file
|
||||
* $config['debug_logger']['sql'] = 'sql';
|
||||
*
|
||||
* index.php (just after $RCMAIL->plugins->init()):
|
||||
*
|
||||
* rcube::console("my test","start");
|
||||
* rcube::console("my message");
|
||||
* rcube::console("my sql calls","start");
|
||||
* rcube::console("cp -r * /dev/null","shell exec");
|
||||
* rcube::console("select * from example","sql");
|
||||
* rcube::console("select * from example","sql");
|
||||
* rcube::console("select * from example","sql");
|
||||
* rcube::console("end");
|
||||
* rcube::console("end");
|
||||
*
|
||||
* logs/master (after reloading the main page):
|
||||
*
|
||||
* [17-Feb-2009 16:51:37 -0500] start: Task: mail.
|
||||
* [17-Feb-2009 16:51:37 -0500] start: my test
|
||||
* [17-Feb-2009 16:51:37 -0500] my message
|
||||
* [17-Feb-2009 16:51:37 -0500] shell exec: cp -r * /dev/null
|
||||
* [17-Feb-2009 16:51:37 -0500] start: my sql calls
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
* [17-Feb-2009 16:51:37 -0500] end: my sql calls - 0.0018 seconds shell exec: 1, sql: 3,
|
||||
* [17-Feb-2009 16:51:37 -0500] end: my test - 0.0055 seconds shell exec: 1, sql: 3,
|
||||
* [17-Feb-2009 16:51:38 -0500] end: Task: mail. - 0.8854 seconds shell exec: 1, sql: 3,
|
||||
*
|
||||
* logs/sql (after reloading the main page):
|
||||
*
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
* [17-Feb-2009 16:51:37 -0500] sql: select * from example
|
||||
*/
|
||||
class debug_logger extends rcube_plugin
|
||||
{
|
||||
protected $runlog;
|
||||
|
||||
function init()
|
||||
{
|
||||
require_once(__DIR__ . '/runlog/runlog.php');
|
||||
|
||||
$this->runlog = new runlog();
|
||||
|
||||
if (!rcmail::get_instance()->config->get('log_dir')) {
|
||||
rcmail::get_instance()->config->set('log_dir', INSTALL_PATH . 'logs');
|
||||
}
|
||||
|
||||
$log_config = rcmail::get_instance()->config->get('debug_logger', []);
|
||||
$log_dir = rcmail::get_instance()->config->get('log_dir');
|
||||
|
||||
foreach ($log_config as $type => $file) {
|
||||
$this->runlog->set_file($log_dir . '/' . $file, $type);
|
||||
}
|
||||
|
||||
$start_string = '';
|
||||
$action = rcmail::get_instance()->action;
|
||||
$task = rcmail::get_instance()->task;
|
||||
|
||||
if ($action) {
|
||||
$start_string .= "Action: {$action}. ";
|
||||
}
|
||||
|
||||
if ($task) {
|
||||
$start_string .= "Task: {$task}. ";
|
||||
}
|
||||
|
||||
$this->runlog->start($start_string);
|
||||
|
||||
$this->add_hook('console', [$this, 'console']);
|
||||
$this->add_hook('authenticate', [$this, 'authenticate']);
|
||||
}
|
||||
|
||||
function authenticate($args)
|
||||
{
|
||||
$this->runlog->note('Authenticating '.$args['user'].'@'.$args['host']);
|
||||
return $args;
|
||||
}
|
||||
|
||||
function console($args)
|
||||
{
|
||||
$note = $args['args'][0];
|
||||
|
||||
if (!empty($args['args'][1])) {
|
||||
$type = $args['args'][1];
|
||||
}
|
||||
else {
|
||||
// This could be extended to detect types based on the
|
||||
// file which called console. For now only rcube_imap/rcube_storage is supported
|
||||
$bt = debug_backtrace();
|
||||
$file = count($bt) >= 2 ? $bt[2]['file'] : '';
|
||||
|
||||
switch (basename($file)) {
|
||||
case 'rcube_imap.php':
|
||||
$type = 'imap';
|
||||
break;
|
||||
case 'rcube_storage.php':
|
||||
$type = 'storage';
|
||||
break;
|
||||
default:
|
||||
$type = false;
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
switch ($note) {
|
||||
case 'end':
|
||||
$type = 'end';
|
||||
break;
|
||||
}
|
||||
|
||||
switch ($type) {
|
||||
case 'start':
|
||||
$this->runlog->start($note);
|
||||
break;
|
||||
case 'end':
|
||||
$this->runlog->end();
|
||||
break;
|
||||
default:
|
||||
$this->runlog->note($note, $type);
|
||||
break;
|
||||
}
|
||||
|
||||
return $args;
|
||||
}
|
||||
|
||||
function __destruct()
|
||||
{
|
||||
if ($this->runlog) {
|
||||
$this->runlog->end();
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,210 @@
|
||||
<?php
|
||||
|
||||
/**
|
||||
* runlog
|
||||
*
|
||||
* @author Ziba Scott <ziba@umich.edu>
|
||||
*/
|
||||
class runlog {
|
||||
|
||||
private $start_time = false;
|
||||
private $parent_stack = [];
|
||||
private $file_handles = [];
|
||||
private $debug_messages = [];
|
||||
private $indent = 0;
|
||||
private $run_log = [];
|
||||
|
||||
public $print_to_console = false;
|
||||
public $threshold = 0;
|
||||
public $tag_count = [];
|
||||
public $timestamp = "d-M-Y H:i:s O";
|
||||
public $max_line_size = 150;
|
||||
|
||||
function __construct()
|
||||
{
|
||||
$this->start_time = microtime(true);
|
||||
}
|
||||
|
||||
public function start($name, $tag = false)
|
||||
{
|
||||
$this->run_log[] = [
|
||||
'type' => 'start',
|
||||
'tag' => $tag,
|
||||
'index' => count($this->run_log),
|
||||
'value' => $name,
|
||||
'time' => microtime(true),
|
||||
'parents' => $this->parent_stack,
|
||||
'ended' => false,
|
||||
];
|
||||
|
||||
$this->parent_stack[] = $name;
|
||||
|
||||
$this->print_to_console("start: ".$name, $tag);
|
||||
$this->print_to_file("start: ".$name, $tag);
|
||||
$this->indent++;
|
||||
}
|
||||
|
||||
public function end()
|
||||
{
|
||||
$name = array_pop($this->parent_stack);
|
||||
$lastk = 0;
|
||||
|
||||
foreach ($this->run_log as $k => $entry) {
|
||||
if ($entry['value'] == $name && $entry['type'] == 'start' && !$entry['ended']) {
|
||||
$lastk = $k;
|
||||
}
|
||||
}
|
||||
|
||||
$start = $this->run_log[$lastk]['time'];
|
||||
$this->run_log[$lastk]['duration'] = microtime(true) - $start;
|
||||
$this->run_log[$lastk]['ended'] = true;
|
||||
$this->run_log[] = [
|
||||
'type' => 'end',
|
||||
'tag' => $this->run_log[$lastk]['tag'],
|
||||
'index' => $lastk,
|
||||
'value' => $name,
|
||||
'time' => microtime(true),
|
||||
'duration' => microtime(true) - $start,
|
||||
'parents' => $this->parent_stack,
|
||||
];
|
||||
|
||||
$this->indent--;
|
||||
if ($this->run_log[$lastk]['duration'] >= $this->threshold) {
|
||||
$tag_report = "";
|
||||
foreach ($this->tag_count as $tag => $count){
|
||||
$tag_report .= "$tag: $count, ";
|
||||
}
|
||||
$end_txt = sprintf("end: $name - %0.4f seconds $tag_report", $this->run_log[$lastk]['duration']);
|
||||
$this->print_to_console($end_txt, $this->run_log[$lastk]['tag']);
|
||||
$this->print_to_file($end_txt, $this->run_log[$lastk]['tag']);
|
||||
}
|
||||
}
|
||||
|
||||
public function increase_tag_count($tag)
|
||||
{
|
||||
if (!isset($this->tag_count[$tag])) {
|
||||
$this->tag_count[$tag] = 0;
|
||||
}
|
||||
|
||||
$this->tag_count[$tag]++;
|
||||
}
|
||||
|
||||
public function get_text()
|
||||
{
|
||||
$text = "";
|
||||
foreach ($this->run_log as $entry){
|
||||
$text .= str_repeat(" ", count($entry['parents']));
|
||||
if ($entry['tag'] != 'text') {
|
||||
$text .= $entry['tag'] . ': ';
|
||||
}
|
||||
$text .= $entry['value'];
|
||||
|
||||
if ($entry['tag'] == 'end') {
|
||||
$text .= sprintf(" - %0.4f seconds", $entry['duration']);
|
||||
}
|
||||
|
||||
$text .= "\n";
|
||||
}
|
||||
|
||||
return $text;
|
||||
}
|
||||
|
||||
public function set_file($filename, $tag = 'master')
|
||||
{
|
||||
if (!isset($this->file_handles[$tag])) {
|
||||
$this->file_handles[$tag] = fopen($filename, 'a');
|
||||
if (!$this->file_handles[$tag]) {
|
||||
trigger_error("Could not open file for writing: $filename");
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
public function note($msg, $tag = false)
|
||||
{
|
||||
if ($tag) {
|
||||
$this->increase_tag_count($tag);
|
||||
}
|
||||
if (is_array($msg)) {
|
||||
$msg = '<pre>' . print_r($msg, true) . '</pre>';
|
||||
}
|
||||
$this->debug_messages[] = $msg;
|
||||
$this->run_log[] = [
|
||||
'type' => 'note',
|
||||
'tag' => $tag ?: 'text',
|
||||
'value' => htmlentities($msg),
|
||||
'time' => microtime(true),
|
||||
'parents' => $this->parent_stack,
|
||||
];
|
||||
|
||||
$this->print_to_file($msg, $tag);
|
||||
$this->print_to_console($msg, $tag);
|
||||
}
|
||||
|
||||
public function print_to_file($msg, $tag = false)
|
||||
{
|
||||
$file_handle_tag = $tag ?: 'master';
|
||||
|
||||
if ($file_handle_tag != 'master' && isset($this->file_handles[$file_handle_tag])) {
|
||||
$buffer = $this->get_indent();
|
||||
$buffer .= "$msg\n";
|
||||
if (!empty($this->timestamp)) {
|
||||
$buffer = sprintf("[%s] %s", date($this->timestamp, time()), $buffer);
|
||||
}
|
||||
fwrite($this->file_handles[$file_handle_tag], wordwrap($buffer, $this->max_line_size, "\n "));
|
||||
}
|
||||
|
||||
if (isset($this->file_handles['master']) && $this->file_handles['master']) {
|
||||
$buffer = $this->get_indent();
|
||||
if ($tag) {
|
||||
$buffer .= "$tag: ";
|
||||
}
|
||||
$msg = str_replace("\n", "", $msg);
|
||||
$buffer .= "$msg";
|
||||
if (!empty($this->timestamp)) {
|
||||
$buffer = sprintf("[%s] %s", date($this->timestamp, time()), $buffer);
|
||||
}
|
||||
if(strlen($buffer) > $this->max_line_size){
|
||||
$buffer = substr($buffer,0,$this->max_line_size - 3) . "...";
|
||||
}
|
||||
fwrite($this->file_handles['master'], $buffer."\n");
|
||||
}
|
||||
}
|
||||
|
||||
public function print_to_console($msg, $tag = false)
|
||||
{
|
||||
if ($this->print_to_console) {
|
||||
if (is_array($this->print_to_console)) {
|
||||
if (in_array($tag, $this->print_to_console)) {
|
||||
echo $this->get_indent();
|
||||
if ($tag) {
|
||||
echo "$tag: ";
|
||||
}
|
||||
echo "$msg\n";
|
||||
}
|
||||
}
|
||||
else {
|
||||
echo $this->get_indent();
|
||||
if ($tag) {
|
||||
echo "$tag: ";
|
||||
}
|
||||
echo "$msg\n";
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
private function get_indent()
|
||||
{
|
||||
$buf = "";
|
||||
for ($i = 0; $i < $this->indent; $i++) {
|
||||
$buf .= " ";
|
||||
}
|
||||
return $buf;
|
||||
}
|
||||
|
||||
function __destruct()
|
||||
{
|
||||
foreach ($this->file_handles as $handle) {
|
||||
fclose($handle);
|
||||
}
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user