diff options
| -rw-r--r-- | config/dav.inc.php.sample | 4 | ||||
| -rw-r--r-- | lib/Kolab/Utils/DAVLogger.php | 175 | ||||
| -rw-r--r-- | lib/Kolab/Utils/HTTPResponse.php | 92 | ||||
| -rw-r--r-- | public_html/debug.php | 173 | ||||
| -rw-r--r-- | public_html/index.php | 28 |
5 files changed, 246 insertions, 226 deletions
diff --git a/config/dav.inc.php.sample b/config/dav.inc.php.sample index 623f7b4..0c22f32 100644 --- a/config/dav.inc.php.sample +++ b/config/dav.inc.php.sample @@ -46,3 +46,7 @@ $config['kolabdav_console'] = false; // enable per-user debugging if /var/log/iRony/<username>/ folder exists $config['kolabdav_user_debug'] = false; + +// enable logging of full HTTP payload +// (bitmask of these values: 2 = HTTP Requests, 4 = HTTP Responses) +$config['kolabdav_http_log'] = 0; diff --git a/lib/Kolab/Utils/DAVLogger.php b/lib/Kolab/Utils/DAVLogger.php index 982d87e..311fc8a 100644 --- a/lib/Kolab/Utils/DAVLogger.php +++ b/lib/Kolab/Utils/DAVLogger.php @@ -23,7 +23,9 @@ namespace Kolab\Utils; +use \rcube; use Sabre\DAV; +use Kolab\DAV\Auth\HTTPBasic; /** @@ -31,8 +33,24 @@ use Sabre\DAV; */ class DAVLogger extends DAV\ServerPlugin { + const CONSOLE = 1; + const HTTP_REQUEST = 2; + const HTTP_RESPONSE = 4; + + private $rcube; private $server; private $method; + private $loglevel; + + + /** + * Default constructor + */ + public function __construct($level = 1) + { + $this->rcube = rcube::get_instance(); + $this->loglevel = $level; + } /** * This initializes the plugin. @@ -40,47 +58,134 @@ class DAVLogger extends DAV\ServerPlugin * * @param Server $server */ - public function initialize(DAV\Server $server) - { - $this->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')); + $server->subscribeEvent('beforeMethod', array($this, '_beforeMethod'), 15); + $server->subscribeEvent('exception', array($this, '_exception')); + $server->subscribeEvent('exit', array($this, '_exit')); + + // replace $server->httpResponse with a derived class that can do logging + $server->httpResponse = new HTTPResponse(); } - /** - * Handler for 'beforeMethod' events - */ - public function _beforeMethod($method, $uri) - { - $this->method = $method; + /** + * Handler for 'beforeMethod' events + */ + public function _beforeMethod($method, $uri) + { + $this->method = $method; - // log to console - console($method . ' ' . $uri); - } + // turn on per-user http logging if the destination file exists + if ($this->loglevel < 2 && $this->rcube->config->get('kolabdav_user_debug', false) + && ($log_dir = $this->user_log_dir()) && file_exists($log_dir . '/httpraw')) { + $this->loglevel |= (self::HTTP_REQUEST | self::HTTP_RESPONSE); + } - /** - * Handler for 'exception' events - */ - public function _exception($e) - { - // log to console - console(get_class($e) . ' (EXCEPTION)', $e->getMessage() /*, $e->getTraceAsString()*/); - } + // log full HTTP request data + if ($this->loglevel & self::HTTP_REQUEST) { + $request = $this->server->httpRequest; + $content_type = $request->getHeader('CONTENT_TYPE'); + if (strpos($content_type, 'text/') === 0) { + $http_body = $request->getBody(true); - /** - * Handler for 'exit' events - */ - public function _exit() - { - $time = microtime(true) - KOLAB_DAV_START; + // Hack for reading php:://input because that stream can only be read once. + // This is why we re-populate the request body with the existing data. + $request->setBody($http_body); + } + else if (!empty($content_type)) { + $http_body = '[binary data]'; + } - 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'; + // catch all headers + $http_headers = array(); + foreach (apache_request_headers() as $hdr => $value) { + $http_headers[$hdr] = "$hdr: $value"; + } - console(sprintf("/%s: %0.4f sec; %s", $this->method, $time, $mem)); - } + $this->write_log('httpraw', $request->getMethod() . ' ' . $request->getUri() . ' ' . $_SERVER['SERVER_PROTOCOL'] . "\n" . + join("\n", $http_headers) . "\n\n" . $http_body); + } + + // log to console + if ($this->loglevel & self::CONSOLE) { + $this->write_log('console', $method . ' ' . $uri); + } + } + + /** + * Handler for 'exception' events + */ + public function _exception($e) + { + // log to console + $this->console(get_class($e) . ' (EXCEPTION)', $e->getMessage() /*, $e->getTraceAsString()*/); + } + + /** + * Handler for 'exit' events + */ + public function _exit() + { + if ($this->loglevel & self::CONSOLE) { + $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'; + + $this->write_log('console', sprintf("/%s: %0.4f sec; %s", $this->method, $time, $mem)); + } + + // log full HTTP reponse + if ($this->loglevel & self::HTTP_RESPONSE) { + $this->write_log('httpraw', "RESPONSE: " . $this->server->httpResponse->dump()); + } + } + + /** + * Wrapper for rcube::cosole() to write per-user logs + */ + public function console(/* ... */) + { + if ($this->loglevel & self::CONSOLE) { + $msg = array(); + foreach (func_get_args() as $arg) { + $msg[] = !is_string($arg) ? var_export($arg, true) : $arg; + } + + $this->write_log('console', join(";\n", $msg)); + } + } + + /** + * Wrapper for rcube::write_log() that can write per-user logs + */ + public function write_log($filename, $msg) + { + // dump data per user + if ($this->rcube->config->get('kolabdav_user_debug', false)) { + if ($this->user_log_dir()) { + $filename = HTTPBasic::$current_user . '/' . $filename; + } + else { + return; // don't log + } + } + + rcube::write_log($filename, $msg); + } + + /** + * Get the per-user log directory + */ + private function user_log_dir() + { + $log_dir = $this->rcube->config->get('log_dir', RCUBE_INSTALL_PATH . 'logs'); + $user_log_dir = $log_dir . '/' . HTTPBasic::$current_user; + + return HTTPBasic::$current_user && is_writable($user_log_dir) ? $user_log_dir : false; + } }
\ No newline at end of file diff --git a/lib/Kolab/Utils/HTTPResponse.php b/lib/Kolab/Utils/HTTPResponse.php new file mode 100644 index 0000000..4f4e72d --- /dev/null +++ b/lib/Kolab/Utils/HTTPResponse.php @@ -0,0 +1,92 @@ +<?php + +/** + * Utility class representing a HTTP response with logging capabilities + * + * @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; + +/** + * This class represents a HTTP response. + */ +class HTTPResponse extends \Sabre\HTTP\Response +{ + private $status; + private $body = ''; + private $headers = array(); + + /** + * Sends an HTTP status header to the client. + * + * @param int $code HTTP status code + * @return bool + */ + public function sendStatus($code) + { + $this->status = $this->getStatusMessage($code, $this->defaultHttpVersion); + return parent::sendStatus($code); + } + + /** + * Sets an HTTP header for the response + * + * @param string $name + * @param string $value + * @param bool $replace + * @return bool + */ + public function setHeader($name, $value, $replace = true) { + $this->headers[$name] = $value; + return parent::setHeader($name, $value, $replace); + } + + /** + * Sends the entire response body + * + * This method can accept either an open filestream, or a string. + * + * @param mixed $body + * @return void + */ + public function sendBody($body) + { + if (is_resource($body)) { + fpassthru($body); + $this->body = '[binary data]'; + } + else { + echo $body; + $this->body .= $body; + } + } + + /** + * Dump the response data for logging + */ + public function dump() + { + $result_headers = ''; + foreach ($this->headers as $hdr => $value) { + $result_headers .= "\n$hdr: " . $value; + } + + return $this->status . $result_headers . "\n\n" . $this->body; + } +}
\ No newline at end of file diff --git a/public_html/debug.php b/public_html/debug.php deleted file mode 100644 index 10fcea8..0000000 --- a/public_html/debug.php +++ /dev/null @@ -1,173 +0,0 @@ -<?php - -/** - * Kolab WebDAV/CalDAV/CardDAV Debug Pipe - * - * @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/>. - */ - -// define some environment variables used throughout the app and libraries -define('KOLAB_DAV_ROOT', realpath('../')); -define('KOLAB_DAV_START', microtime(true)); - -define('RCUBE_INSTALL_PATH', KOLAB_DAV_ROOT . '/'); -define('RCUBE_CONFIG_DIR', KOLAB_DAV_ROOT . '/config/'); - -ini_set('error_reporting', E_ALL &~ E_NOTICE &~ E_STRICT); - -require_once KOLAB_DAV_ROOT . '/vendor/autoload.php'; -require_once KOLAB_DAV_ROOT . '/lib/Roundcube/bootstrap.php'; - -// Roundcube framework initialization -$rcube = rcube::get_instance(); -$rcube->config->load_from_file(RCUBE_CONFIG_DIR . 'dav.inc.php'); - -$base_uri = $rcube->config->get('base_uri', slashify(substr(dirname($_SERVER['SCRIPT_FILENAME']), strlen($_SERVER['DOCUMENT_ROOT'])))); - -// quick & dirty request debugging -$http_headers = array(); -foreach (apache_request_headers() as $hdr => $value) { - if ($hdr == 'Destination') - $value = str_replace($base_uri, $base_uri . 'index.php/', $value); - $http_headers[$hdr] = "$hdr: $value"; -} -// read HTTP request body -$in = fopen('php://input', 'r'); -$http_body = stream_get_contents($in); -fclose($in); - -$rcube->write_log('davdebug', $_SERVER['REQUEST_METHOD'] . ' ' . $_SERVER['REQUEST_URI'] . ' ' . $_SERVER['SERVER_PROTOCOL'] . "\n" . - join("\n", $http_headers) . "\n\n" . $http_body); - -// fix URIs in request body -$http_body = preg_replace("!(<\w+:href[^>]*>$base_uri)!i", '\\1index.php/', $http_body); -$http_headers['Content-Length'] = "Content-Length: " . strlen($http_body); - -// forward the full request to index.php -$rel_url = substr($_SERVER['REQUEST_URI'], strlen($base_uri)); -$host = $_SERVER['HTTP_HOST']; -$port = 80; -$path = $base_uri . 'index.php/' . $rel_url; - -// remove Host: header -unset($http_headers['Host']); -$response_headers = array(); - -// re-send using curl -$ch = curl_init(); -curl_setopt($ch, CURLOPT_URL, "http://$host:$port$path"); -curl_setopt($ch, CURLOPT_RETURNTRANSFER, 1); -curl_setopt($ch, CURLOPT_CUSTOMREQUEST, $_SERVER['REQUEST_METHOD']); -curl_setopt($ch, CURLOPT_POSTFIELDS, $http_body); -curl_setopt($ch, CURLOPT_HTTPHEADER, array_values($http_headers)); -curl_setopt($ch, CURLOPT_HEADER, 0); -curl_setopt($ch, CURLOPT_HEADERFUNCTION, function($ch, $header) use (&$response_headers){ - list($key, $val) = explode(": ", rtrim($header), 2); - if (!empty($val)) $response_headers[$key] = $val; - return strlen($header); -}); - -$result = str_replace('index.php/', '', curl_exec($ch)); -$info = curl_getinfo($ch); - -// send recieved HTTP status code -$result_headers = $_SERVER['SERVER_PROTOCOL'] . " " . $info['http_code'] . " " . http_response_phrase($info['http_code']); -header($result_headers, true); - -// forward response headers -unset($response_headers['Transfer-Encoding']); -foreach ($response_headers as $hdr => $value) { - $value = str_replace('index.php/', '', $value); - $result_headers .= "\n$hdr: " . $value; - header("$hdr: " . $value, true); -} - -// log response -$rcube->write_log('davdebug', "RESPONSE:\n" . $result_headers . "\n\n" . (strpos($info['content_type'], 'image/') === false ? $result : '')); - -// send response body back to client -echo $result; - - -/** - * Derived from HTTP_Request2_Response::getDefaultReasonPhrase() - */ -function http_response_phrase($code) -{ - static $phrases = array( - - // 1xx: Informational - Request received, continuing process - 100 => 'Continue', - 101 => 'Switching Protocols', - - // 2xx: Success - The action was successfully received, understood and - // accepted - 200 => 'OK', - 201 => 'Created', - 202 => 'Accepted', - 203 => 'Non-Authoritative Information', - 204 => 'No Content', - 205 => 'Reset Content', - 206 => 'Partial Content', - 207 => 'Multi-Status', - - // 3xx: Redirection - Further action must be taken in order to complete - // the request - 300 => 'Multiple Choices', - 301 => 'Moved Permanently', - 302 => 'Found', // 1.1 - 303 => 'See Other', - 304 => 'Not Modified', - 305 => 'Use Proxy', - 307 => 'Temporary Redirect', - - // 4xx: Client Error - The request contains bad syntax or cannot be - // fulfilled - 400 => 'Bad Request', - 401 => 'Unauthorized', - 402 => 'Payment Required', - 403 => 'Forbidden', - 404 => 'Not Found', - 405 => 'Method Not Allowed', - 406 => 'Not Acceptable', - 407 => 'Proxy Authentication Required', - 408 => 'Request Timeout', - 409 => 'Conflict', - 410 => 'Gone', - 411 => 'Length Required', - 412 => 'Precondition Failed', - 413 => 'Request Entity Too Large', - 414 => 'Request-URI Too Long', - 415 => 'Unsupported Media Type', - 416 => 'Requested Range Not Satisfiable', - 417 => 'Expectation Failed', - - // 5xx: Server Error - The server failed to fulfill an apparently - // valid request - 500 => 'Internal Server Error', - 501 => 'Not Implemented', - 502 => 'Bad Gateway', - 503 => 'Service Unavailable', - 504 => 'Gateway Timeout', - 505 => 'HTTP Version Not Supported', - 509 => 'Bandwidth Limit Exceeded', - ); - - return $phrases[$code]; -} - diff --git a/public_html/index.php b/public_html/index.php index 64f02ea..0886ebb 100644 --- a/public_html/index.php +++ b/public_html/index.php @@ -66,30 +66,22 @@ $required = array('libkolab', 'libcalendaring'); $rcube->plugins->init($rcube); $rcube->plugins->load_plugins($plugins, $required); +// enable logger +if ($rcube->config->get('kolabdav_console') || $rcube->config->get('kolabdav_user_debug')) { + $logger = new \Kolab\Utils\DAVLogger((\Kolab\Utils\DAVLogger::CONSOLE | $rcube->config->get('kolabdav_http_log', 0))); +} // convenience function, you know it well :-) function console() { - global $rcube; + global $rcube, $logger; // 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)); - } + else if ($logger) { + call_user_func_array(array($logger, 'console'), func_get_args()); } } @@ -145,9 +137,9 @@ else if ($services['WEBDAV']) { $server = new \Sabre\DAV\Server($nodes); $server->setBaseUri($base_uri); -// enable logger -if ($rcube->config->get('kolabdav_console') || $rcube->config->get('kolabdav_user_debug')) { - $server->addPlugin(new \Kolab\Utils\DAVLogger()); +// connect logger +if (is_object($logger)) { + $server->addPlugin($logger); } // register some plugins |