Copy plugins into 0.4.1 release branch

2 files changed, 373 insertions, 0 deletions

diff --git a/plugins/debug_logger/debug_logger.php b/plugins/debug_logger/debug_logger.php
new file mode 100644
index 000000000..f04ba6a61
--- /dev/null
+++ b/plugins/debug_logger/debug_logger.php
@@ -0,0 +1,146 @@
+<?php
+
+/**
+ * Debug Logger
+ *
+ * Enhanced logging for debugging purposes.  It is not recommened
+ * 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 console("message") 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/main.inc.php and add your desired
+ * log types and files.
+ *
+ * @version 1.0
+ * @author Ziba Scott
+ * @website http://roundcube.net
+ * 
+ * Example:
+ *
+ * config/main.inc.php:
+ *
+ *   // $rcmail_config['debug_logger'][type of logging] = name of file in log_dir
+ *   // The 'master' log includes timing information
+ *   $rcmail_config['debug_logger']['master'] = 'master';
+ *   // If you want sql messages to also go into a separate file 
+ *   $rcmail_config['debug_logger']['sql'] = 'sql';
+ *
+ * index.php (just after $RCMAIL->plugins->init()):
+ *
+ *   console("my test","start");
+ *   console("my message");
+ *   console("my sql calls","start");
+ *   console("cp -r * /dev/null","shell exec");
+ *   console("select * from example","sql");
+ *   console("select * from example","sql");
+ *   console("select * from example","sql");
+ *   console("end");
+ *   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
+{
+    function init()
+    {
+        require_once(dirname(__FILE__).'/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',array());
+
+        foreach($log_config as $type=>$file){
+            $this->runlog->set_file(rcmail::get_instance()->config->get('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', array($this, 'console'));
+        $this->add_hook('authenticate', array($this, 'authenticate'));
+    }
+
+    function authenticate($args){
+        $this->runlog->note('Authenticating '.$args['user'].'@'.$args['host']);
+        return $args;
+    }
+
+    function console($args){
+        $note = $args[0];
+        $type = $args[1];
+
+
+        if(!isset($args[1])){
+            // This could be extended to detect types based on the 
+            // file which called console.  For now only rcube_imap.inc is supported
+            $bt = debug_backtrace();
+            $file  = $bt[3]['file'];
+            switch(basename($file)){
+                case 'rcube_imap.php':
+                    $type = 'imap';
+                    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(){
+                $this->runlog->end();
+    }
+}
+?>
diff --git a/plugins/debug_logger/runlog/runlog.php b/plugins/debug_logger/runlog/runlog.php
new file mode 100644
index 000000000..c9f672615
--- /dev/null
+++ b/plugins/debug_logger/runlog/runlog.php
@@ -0,0 +1,227 @@
+<?php
+
+/**
+ * runlog 
+ * 
+ * @author Ziba Scott <ziba@umich.edu> 
+ */
+class runlog {
+
+    private $start_time = FALSE;
+
+    private $parent_stack = array();
+
+    public $print_to_console = FALSE;
+
+    private $file_handles = array();
+
+    private $indent = 0;
+
+    public $threshold = 0;
+
+    public $tag_count = array();
+
+    public $timestamp = "d-M-Y H:i:s O";
+
+    public $max_line_size = 150;
+
+    private $run_log = array();
+
+    function runlog()
+    {
+        $this->start_time = microtime( TRUE );
+    }
+
+    public function start( $name, $tag = FALSE  )
+    {
+        $this->run_log[] = array( '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, 'start');
+        $this->print_to_file("start: ".$name, $tag, 'start');
+        $this->indent++;
+    }
+
+    public function end()
+    {
+        $name = array_pop( $this->parent_stack );
+        foreach ( $this->run_log as $k => $entry ) {
+            if ( $entry['value'] == $name && $entry['type'] == 'start'  && $entry['ended'] == false) {
+                $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[] = array( '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, ";
+            }
+            if(!empty($tag_report)){
+//                $tag_report = "\n$tag_report\n";
+            }
+            $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'] , 'end');
+            $this->print_to_file($end_txt,  $this->run_log[$lastk]['tag'], 'end');
+        }
+    }
+
+    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_handle[$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[] = array( 'type' => 'note',
+                                  'tag' => $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, $type = FALSE){
+       if(!$tag){
+        $file_handle_tag = 'master';
+       }
+       else{
+            $file_handle_tag = $tag;
+       }
+       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, mktime()), $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, mktime()), $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";
+            }
+        }
+    }
+
+    public function print_totals(){
+        $totals = array();
+        foreach ( $this->run_log as $k => $entry ) {
+            if ( $entry['type'] == 'start'  && $entry['ended'] == true) {
+                $totals[$entry['value']]['duration'] += $entry['duration'];
+                $totals[$entry['value']]['count'] += 1;
+            }
+        }
+       if($this->file_handle){
+           foreach($totals as $name=>$details){
+            fwrite($this->file_handle,$name.": ".number_format($details['duration'],4)."sec,  ".$details['count']." calls \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);
+        }
+    }
+
+}
+
+?>