Better logging facilities to enable per-user debug log (#2462)

4 files changed, 124 insertions, 9 deletions

diff --git a/config/dav.inc.php.sample b/config/dav.inc.php.sample
index d8dd7fe..623f7b4 100644
--- a/config/dav.inc.php.sample
+++ b/config/dav.inc.php.sample
@@ -22,24 +22,27 @@
  +-------------------------------------------------------------------------+
 */
 
-$rcmail_config = array();
+$config = array();
 
 // Log DAV requests to <log_dir>/davdebug
-$rcmail_config['base_uri'] = null;
+$config['base_uri'] = null;
 
 // User agent string written to kolab storage MIME messages
-$rcmail_config['useragent'] = 'Kolab DAV Server libkolab/' . RCUBE_VERSION;
+$config['useragent'] = 'Kolab DAV Server libkolab/' . RCUBE_VERSION;
 
 // Roundcube plugins. Not all are supported here.
-$rcmail_config['kolabdav_plugins'] = array('kolab_auth');
+$config['kolabdav_plugins'] = array('kolab_auth');
 
 // Type of Auth cache. Supported values: 'db', 'apc' and 'memcache'.
 // Note: This is only for username canonification map.
-$rcmail_config['kolabdav_auth_cache'] = 'apc';
+$config['kolabdav_auth_cache'] = 'apc';
 
 // lifetime of the Auth cache, possible units: s, m, h, d, w
-$rcmail_config['kolabdav_auth_cache_ttl'] = '1h';
+$config['kolabdav_auth_cache_ttl'] = '1h';
 
 // enable debug console showing the internal function calls triggered
 // by http requests. This will write log to /var/log/iRony/console
-$rcmail_config['kolab_dav_console'] = false;
+$config['kolabdav_console'] = false;
+
+// enable per-user debugging if /var/log/iRony/<username>/ folder exists
+$config['kolabdav_user_debug'] = false;
diff --git a/lib/Kolab/Utils/DAVBackend.php b/lib/Kolab/Utils/DAVBackend.php
index 0734be9..1111216 100644
--- a/lib/Kolab/Utils/DAVBackend.php
+++ b/lib/Kolab/Utils/DAVBackend.php
@@ -1,7 +1,7 @@
 <?php
 
 /**
- * Utility class prividing a simple API to PHP's APC cache
+ * Utility class providing a simple API to PHP's APC cache
  *
  * @author Thomas Bruederli <bruederli@kolabsys.com>
  *
diff --git a/lib/Kolab/Utils/DAVLogger.php b/lib/Kolab/Utils/DAVLogger.php
new file mode 100644
index 0000000..982d87e
--- /dev/null
+++ b/lib/Kolab/Utils/DAVLogger.php
@@ -0,0 +1,86 @@
+<?php
+
+/**
+ * Utility class logging DAV requests
+ *
+ * @author Thomas Bruederli <bruederli@kolabsys.com>
+ *
+ * Copyright (C) 2013, Kolab Systems AG <contact@kolabsys.com>
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as
+ * published by the Free Software Foundation, either version 3 of the
+ * License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU Affero General Public License for more details.
+ *
+ * You should have received a copy of the GNU Affero General Public License
+ * along with this program. If not, see <http://www.gnu.org/licenses/>.
+ */
+
+namespace Kolab\Utils;
+
+use Sabre\DAV;
+
+
+/**
+ * Utility class to log debug information about processed DAV requests
+ */
+class DAVLogger extends DAV\ServerPlugin
+{
+    private $server;
+    private $method;
+
+    /**
+     * This initializes the plugin.
+     * This method should set up the required event subscriptions.
+     *
+     * @param Server $server
+     */
+   public function initialize(DAV\Server $server)
+   {
+       $this->server = $server;
+
+       $server->subscribeEvent('beforeMethod', array($this, '_beforeMethod'));
+       $server->subscribeEvent('exception', array($this, '_exception'));
+       $server->subscribeEvent('exit', array($this, '_exit'));
+   }
+
+   /**
+    * Handler for 'beforeMethod' events
+    */
+   public function _beforeMethod($method, $uri)
+   {
+       $this->method = $method;
+
+       // log to console
+       console($method . ' ' . $uri);
+   }
+
+   /**
+    * Handler for 'exception' events
+    */
+   public function _exception($e)
+   {
+       // log to console
+       console(get_class($e) . ' (EXCEPTION)', $e->getMessage() /*, $e->getTraceAsString()*/);
+   }
+
+   /**
+    * Handler for 'exit' events
+    */
+   public function _exit()
+   {
+       $time = microtime(true) - KOLAB_DAV_START;
+
+       if (function_exists('memory_get_usage'))
+         $mem = round(memory_get_usage() / 1024) . 'K';
+       if (function_exists('memory_get_peak_usage'))
+         $mem .= '/' . round(memory_get_peak_usage() / 1024) . 'K';
+
+       console(sprintf("/%s: %0.4f sec; %s", $this->method, $time, $mem));
+   }
+} 
\ No newline at end of file
diff --git a/public_html/index.php b/public_html/index.php
index a702fef..5d12f14 100644
--- a/public_html/index.php
+++ b/public_html/index.php
@@ -66,12 +66,31 @@ $required = array('libkolab', 'libcalendaring');
 $rcube->plugins->init($rcube);
 $rcube->plugins->load_plugins($plugins, $required);
 
+
 // convenience function, you know it well :-)
 function console()
 {
     global $rcube;
-    if ($rcube->config->get('kolab_dav_console', false))
+
+    // write to global console log
+    if ($rcube->config->get('kolabdav_console', false)) {
         call_user_func_array(array('rcube', 'console'), func_get_args());
+    }
+
+    // dump console data per user
+    if ($rcube->config->get('kolabdav_user_debug', false)) {
+        $uname = \Kolab\DAV\Auth\HTTPBasic::$current_user;
+        $log_dir = $rcube->config->get('log_dir', RCUBE_INSTALL_PATH . 'logs');
+
+        if ($uname && $log_dir && is_writable($log_dir . '/' . $uname)) {
+            $msg = array();
+            foreach (func_get_args() as $arg) {
+                $msg[] = !is_string($arg) ? var_export($arg, true) : $arg;
+            }
+
+            rcube::write_log($uname . '/console', join(";\n", $msg));
+        }
+    }
 }
 
 
@@ -130,6 +149,11 @@ $server->setBaseUri($base_uri);
 $server->addPlugin(new \Sabre\DAV\Auth\Plugin($auth_backend, 'KolabDAV'));
 $server->addPlugin(new \Sabre\DAVACL\Plugin());
 
+// enable logger
+if ($rcube->config->get('kolabdav_console') || $rcube->config->get('kolabdav_user_debug')) {
+    $server->addPlugin(new \Kolab\Utils\DAVLogger());
+}
+
 if ($services['CALDAV']) {
     $caldav_plugin = new \Kolab\CalDAV\Plugin();
     $caldav_plugin->setIMipHandler(new \Kolab\CalDAV\IMip());
@@ -158,3 +182,5 @@ if (getenv('DAVBROWSER')) {
 // finally, process the request
 $server->exec();
 
+// trigger log
+$server->broadcastEvent('exit', array());