From e855756795da07e79807b8cf1a31cfea8d253d61 Mon Sep 17 00:00:00 2001 From: =?utf8?q?Sven=20Sch=C3=B6ling?= Date: Wed, 15 May 2013 14:32:29 +0200 Subject: [PATCH] Neuer Debugparameter: Request Loggt sinnvolle Informationen zum Request. --- SL/Dispatcher.pm | 1 + SL/LXDebug.pm | 57 +++++++++++++++++++++++++++++++---- SL/Request.pm | 19 +++++++----- config/kivitendo.conf.default | 2 ++ 4 files changed, 66 insertions(+), 13 deletions(-) diff --git a/SL/Dispatcher.pm b/SL/Dispatcher.pm index 828dc1f1a..93d3a18e6 100644 --- a/SL/Dispatcher.pm +++ b/SL/Dispatcher.pm @@ -209,6 +209,7 @@ sub handle_request { my %routing; eval { %routing = _route_request($ENV{SCRIPT_NAME}); 1; } or return; ($routing_type, $script_name, $action) = @routing{qw(type controller action)}; + $::lxdebug->log_request($routing_type, $script_name, $action); $::request->type(lc($routing{request_type} || 'html')); diff --git a/SL/LXDebug.pm b/SL/LXDebug.pm index 13f86a71a..d98d36a1a 100644 --- a/SL/LXDebug.pm +++ b/SL/LXDebug.pm @@ -8,9 +8,10 @@ use constant QUERY => 1 << 3; use constant TRACE => 1 << 4; use constant BACKTRACE_ON_ERROR => 1 << 5; use constant REQUEST_TIMER => 1 << 6; -use constant WARN => 1 << 7; -use constant TRACE2 => 1 << 8; -use constant ALL => (1 << 9) - 1; +use constant REQUEST => 1 << 7; +use constant WARN => 1 << 8; +use constant TRACE2 => 1 << 9; +use constant ALL => (1 << 10) - 1; use constant DEVEL => INFO | DEBUG1 | QUERY | TRACE | BACKTRACE_ON_ERROR | REQUEST_TIMER; use constant FILE_TARGET => 0; @@ -20,6 +21,7 @@ use Data::Dumper; use POSIX qw(strftime getppid); use Time::HiRes qw(gettimeofday tv_interval); use YAML; +use SL::Request (); use strict; @@ -251,14 +253,19 @@ sub _write { local *FILE; chomp($message); + $self->_write_raw("${date}${message}\n"); +} +sub _write_raw { + my ($self, $message) = @_; + local *FILE; if ((FILE_TARGET == $self->{"target"}) && open(FILE, ">>", $self->{"file"})) { - print(FILE "${date}${message}\n"); - close(FILE); + print FILE $message; + close FILE; } elsif (STDERR_TARGET == $self->{"target"}) { - print(STDERR "${date}${message}\n"); + print STDERR $message; } } @@ -322,6 +329,44 @@ sub level_by_name { return $global_level & $self->_by_name($level); } +sub is_request_logging_enabled { + my ($self) = @_; + return $global_level & REQUEST; +} + +sub add_request_params { + my ($self, $key, $value) = @_; + return unless $self->is_request_logging_enabled; + return if $key =~ /password/; + + push @{ $::request->{debug}{PARAMS} ||= [] }, [ $key => $value ]; +} + +sub log_request { + my ($self, $type, $controller, $action) = @_; + return unless $self->is_request_logging_enabled; + + my $session_id = $::auth->create_or_refresh_session; + + my $template = <_write('Request', $template); + + my $params = join "\n ", map { + "$_->[0] = $_->[1]" + } @{ $::request->{debug}{PARAMS} || [] }; + + $self->_write_raw(<enter_sub(2); - my ($target, $input) = @_; + my ($target, $input, $log) = @_; my @pairs = split(/&/, $input); foreach (@pairs) { my ($key, $value) = split(/=/, $_, 2); - _store_value($target, uri_decode($key), uri_decode($value)) if ($key); + next unless $key; + _store_value($target, uri_decode($key), uri_decode($value)); + + # for debugging + $::lxdebug->add_request_params(uri_decode($key) => uri_decode($value)) if $log; } $::lxdebug->leave_sub(2); } sub _parse_multipart_formdata { - my ($target, $temp_target, $input) = @_; + my ($target, $temp_target, $input, $log) = @_; my ($name, $filename, $headers_done, $content_type, $boundary_found, $need_cr, $previous, $p_attachment, $encoding, $transfer_encoding); my $data_start = 0; @@ -113,6 +117,7 @@ sub _parse_multipart_formdata { } else { ${ $previous } = $data; } + $::lxdebug->add_request_params($name, $$previous) if $log; undef $previous; undef $filename; @@ -263,8 +268,8 @@ sub read_cgi_input { # since both of these can potentially bring their encoding in INPUT_ENCODING # they get dumped into temp_target - _input_to_hash($temp_target, $ENV{QUERY_STRING}) if $ENV{QUERY_STRING}; - _input_to_hash($temp_target, $ARGV[0]) if @ARGV && $ARGV[0]; + _input_to_hash($temp_target, $ENV{QUERY_STRING}, 1) if $ENV{QUERY_STRING}; + _input_to_hash($temp_target, $ARGV[0], 1) if @ARGV && $ARGV[0]; if ($ENV{CONTENT_LENGTH}) { my $content; @@ -272,10 +277,10 @@ sub read_cgi_input { if ($ENV{'CONTENT_TYPE'} && $ENV{'CONTENT_TYPE'} =~ /multipart\/form-data/) { # multipart formdata can bring it's own encoding, so give it both # and let ti decide on it's own - _parse_multipart_formdata($target, $temp_target, $content); + _parse_multipart_formdata($target, $temp_target, $content, 1); } else { # normal encoding must be recoded - _input_to_hash($temp_target, $content); + _input_to_hash($temp_target, $content, 1); } } diff --git a/config/kivitendo.conf.default b/config/kivitendo.conf.default index 9debb7bb0..4e4919d50 100644 --- a/config/kivitendo.conf.default +++ b/config/kivitendo.conf.default @@ -260,6 +260,8 @@ dbix_log4perl_config = log4perl.logger = FATAL, LOGFILE # TRACE - Track function calls and returns # BACKTRACE_ON_ERROR - Print a function call backtrace when $form->error() is called # REQUEST_TIMER - Log timing of HTTP requests +# REQUEST - Log each request. Careful! Passwords get filtered, but +# there may be confidential information being logged here # WARN - warnings # ALL - all possible debug messages # -- 2.20.1