From: Darold Gilles Date: Tue, 13 Nov 2012 20:16:16 +0000 (+0100) Subject: Add two more Pg keywords and run perltidy. X-Git-Tag: v3.2~101 X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=b67c247ab00c7dcd08fdf3b2fd0d60973e45b3ac;p=pgbadger Add two more Pg keywords and run perltidy. --- diff --git a/pgbadger b/pgbadger index 7dcf579..1cf5a1e 100755 --- a/pgbadger +++ b/pgbadger @@ -34,7 +34,7 @@ use File::Basename; use Time::Local 'timegm_nocheck'; use POSIX qw(locale_h); setlocale(LC_NUMERIC, ''); -setlocale(LC_ALL, 'C'); +setlocale(LC_ALL, 'C'); $VERSION = '2.1'; @@ -44,64 +44,64 @@ $| = 1; my $JQGRAPH = 1; # Command line options -my $zcat = 'zcat'; -my $bzcat = 'bunzip2 -c'; -my $ucat = 'unzip -p'; -my $uncompress_size = "gunzip -l %f | grep -E '^\\s*[0-9]+' | awk '{print \$2}'"; -my $format = ''; -my $outfile = ''; -my $outdir = ''; -my $help = ''; -my $ver = ''; -my @dbname = (); -my @dbuser = (); -my @dbclient = (); -my @dbappname = (); -my @exclude_user = (); -my $ident = ''; -my $top = 0; -my $sample = 0; -my $extension = ''; -my $maxlength = 0; -my $graph = 1; -my $nograph = 0; -my $debug = 0; -my $nohighlight = 0; -my $noprettify = 0; -my $from = ''; -my $to = ''; -my $quiet = 0; -my $progress = 1; -my $error_only = 0; -my @exclude_query = (); -my $exclude_file = ''; -my @include_query = (); -my $include_file = ''; -my $disable_error = 0; -my $disable_hourly = 0; -my $disable_type = 0; -my $disable_query = 0; -my $disable_session = 0; -my $disable_connection = 0; -my $disable_lock = 0; -my $disable_temporary = 0; -my $disable_checkpoint = 0; -my $avg_minutes = 5; -my $last_parsed = ''; -my $report_title = 'PgBadger: PostgreSQL log analyzer'; -my $log_line_prefix = ''; -my $compiled_prefix = ''; -my $project_url = 'http://dalibo.github.com/pgbadger/'; -my $t_min = 0; -my $t_max = 0; -my $t_min_hour = 0; -my $t_max_hour = 0; -my $log_duration = 0; -my $enable_log_duration = 0; -my $remove_comment = 0; -my $select_only = 0; +my $zcat = 'zcat'; +my $bzcat = 'bunzip2 -c'; +my $ucat = 'unzip -p'; +my $uncompress_size = "gunzip -l %f | grep -E '^\\s*[0-9]+' | awk '{print \$2}'"; +my $format = ''; +my $outfile = ''; +my $outdir = ''; +my $help = ''; +my $ver = ''; +my @dbname = (); +my @dbuser = (); +my @dbclient = (); +my @dbappname = (); +my @exclude_user = (); +my $ident = ''; +my $top = 0; +my $sample = 0; +my $extension = ''; +my $maxlength = 0; +my $graph = 1; +my $nograph = 0; +my $debug = 0; +my $nohighlight = 0; +my $noprettify = 0; +my $from = ''; +my $to = ''; +my $quiet = 0; +my $progress = 1; +my $error_only = 0; +my @exclude_query = (); +my $exclude_file = ''; +my @include_query = (); +my $include_file = ''; +my $disable_error = 0; +my $disable_hourly = 0; +my $disable_type = 0; +my $disable_query = 0; +my $disable_session = 0; +my $disable_connection = 0; +my $disable_lock = 0; +my $disable_temporary = 0; +my $disable_checkpoint = 0; +my $avg_minutes = 5; +my $last_parsed = ''; +my $report_title = 'PgBadger: PostgreSQL log analyzer'; +my $log_line_prefix = ''; +my $compiled_prefix = ''; +my $project_url = 'http://dalibo.github.com/pgbadger/'; +my $t_min = 0; +my $t_max = 0; +my $t_min_hour = 0; +my $t_max_hour = 0; +my $log_duration = 0; +my $enable_log_duration = 0; +my $remove_comment = 0; +my $select_only = 0; my $enable_log_min_duration = 0; -my $tsung_queries = 0; +my $tsung_queries = 0; my $NUMPROGRESS = 10000; my @DIMENSIONS = (800, 300); @@ -121,51 +121,51 @@ $num_sep = ' ' if ($n =~ /,/); # get the command line parameters my $result = GetOptions( - "a|average=i" => \$avg_minutes, - "b|begin=s" => \$from, - "c|client=s" => \@dbclient, - "C|nocomment!" => \$remove_comment, - "d|dbname=s" => \@dbname, - "e|end=s" => \$to, - "f|format=s" => \$format, - "G|nograph!" => \$nograph, - "h|help!" => \$help, - "i|ident=s" => \$ident, - "l|last-parsed=s" => \$last_parsed, - "m|maxlength=i" => \$maxlength, - "N|appname=s" => \@dbappname, - "n|nohighlight!" => \$nohighlight, - "o|outfile=s" => \$outfile, - "p|prefix=s" => \$log_line_prefix, - "P|no-prettify!" => \$noprettify, - "q|quiet!" => \$quiet, - "s|sample=i" => \$sample, - "S|select-only!" => \$select_only, - "t|top=i" => \$top, - "T|title=s" => \$report_title, - "u|dbuser=s" => \@dbuser, - "U|exclude-user=s" => \@exclude_user, - "v|verbose!" => \$debug, - "V|version!" => \$ver, - "w|watch-mode!" => \$error_only, - "x|extension=s" => \$extension, - "z|zcat=s" => \$zcat, - "pie-limit=i" => \$pie_percentage_limit, - "image-format=s" => \$img_format, - "exclude-query=s" => \@exclude_query, - "exclude-file=s" => \$exclude_file, - "include-query=s" => \@include_query, - "include-file=s" => \$include_file, - "disable-error!" => \$disable_error, - "disable-hourly!" => \$disable_hourly, - "disable-type!" => \$disable_type, - "disable-query!" => \$disable_query, - "disable-session!" => \$disable_session, - "disable-connection!" => \$disable_connection, - "disable-lock!" => \$disable_lock, - "disable-temporary!" => \$disable_temporary, - "disable-checkpoint!" => \$disable_checkpoint, - "enable-log_duration!" => \$enable_log_duration, + "a|average=i" => \$avg_minutes, + "b|begin=s" => \$from, + "c|client=s" => \@dbclient, + "C|nocomment!" => \$remove_comment, + "d|dbname=s" => \@dbname, + "e|end=s" => \$to, + "f|format=s" => \$format, + "G|nograph!" => \$nograph, + "h|help!" => \$help, + "i|ident=s" => \$ident, + "l|last-parsed=s" => \$last_parsed, + "m|maxlength=i" => \$maxlength, + "N|appname=s" => \@dbappname, + "n|nohighlight!" => \$nohighlight, + "o|outfile=s" => \$outfile, + "p|prefix=s" => \$log_line_prefix, + "P|no-prettify!" => \$noprettify, + "q|quiet!" => \$quiet, + "s|sample=i" => \$sample, + "S|select-only!" => \$select_only, + "t|top=i" => \$top, + "T|title=s" => \$report_title, + "u|dbuser=s" => \@dbuser, + "U|exclude-user=s" => \@exclude_user, + "v|verbose!" => \$debug, + "V|version!" => \$ver, + "w|watch-mode!" => \$error_only, + "x|extension=s" => \$extension, + "z|zcat=s" => \$zcat, + "pie-limit=i" => \$pie_percentage_limit, + "image-format=s" => \$img_format, + "exclude-query=s" => \@exclude_query, + "exclude-file=s" => \$exclude_file, + "include-query=s" => \@include_query, + "include-file=s" => \$include_file, + "disable-error!" => \$disable_error, + "disable-hourly!" => \$disable_hourly, + "disable-type!" => \$disable_type, + "disable-query!" => \$disable_query, + "disable-session!" => \$disable_session, + "disable-connection!" => \$disable_connection, + "disable-lock!" => \$disable_lock, + "disable-temporary!" => \$disable_temporary, + "disable-checkpoint!" => \$disable_checkpoint, + "enable-log_duration!" => \$enable_log_duration, "enable-log_min_duration!" => \$enable_log_min_duration, ); @@ -206,7 +206,6 @@ $avg_minutes ||= 5; $avg_minutes = 60 if ($avg_minutes > 60); $avg_minutes = 1 if ($avg_minutes < 1); - # Set default format $format ||= &autodetect_format($log_files[0]); @@ -267,6 +266,7 @@ $graph = 0 if ($nograph); my $end_top = $top - 1; if ($extension eq 'tsung') { + # Open filehandle my $fh = new IO::File ">$outfile"; if (not defined $fh) { @@ -275,6 +275,7 @@ if ($extension eq 'tsung') { print $fh "\n"; $fh->close(); } else { + # Test file creation before going to parse log my $tmpfh = new IO::File ">$outfile"; if (not defined $tmpfh) { @@ -333,7 +334,8 @@ if ($#include_query >= 0) { } } -my $other_syslog_line = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*(.*)/; +my $other_syslog_line = + qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*(.*)/; my $orphan_syslog_line = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:/; my $orphan_stderr_line = qr/[^']*\d+-\d+-\d+\s\d+:\d+:\d+[\.\d]*\s[^\s]+[^']*/; @@ -343,7 +345,10 @@ if ($log_line_prefix) { @prefix_params = &build_log_line_prefix_regex(); &check_regex($log_line_prefix, '--prefix'); if ($format eq 'syslog') { - $log_line_prefix = '^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*' . $log_line_prefix . '\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)'; + $log_line_prefix = + '^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*' + . $log_line_prefix + . '\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)'; $compiled_prefix = qr/$log_line_prefix/; unshift(@prefix_params, 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_line'); push(@prefix_params, 't_loglevel', 't_query'); @@ -353,10 +358,13 @@ if ($log_line_prefix) { push(@prefix_params, 't_loglevel', 't_query'); } } elsif ($format eq 'syslog') { - $compiled_prefix = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*(.*?)\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)/; - push(@prefix_params, 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_line', 't_logprefix', 't_loglevel', 't_query'); + $compiled_prefix = +qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]:(?:\s\[[^\]]+\])?\s\[(\d+)\-\d+\]\s*(.*?)\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)/; + push(@prefix_params, 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_line', + 't_logprefix', 't_loglevel', 't_query'); } elsif ($format eq 'stderr') { - $compiled_prefix = qr/^(\d+-\d+-\d+\s\d+:\d+:\d+)[\.\d]*(?: [A-Z\d]{3,6})?\s\[(\d+)\]:\s\[(\d+)\-\d+\]\s*(.*?)\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)/; + $compiled_prefix = +qr/^(\d+-\d+-\d+\s\d+:\d+:\d+)[\.\d]*(?: [A-Z\d]{3,6})?\s\[(\d+)\]:\s\[(\d+)\-\d+\]\s*(.*?)\s*(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+(.*)/; push(@prefix_params, 't_timestamp', 't_pid', 't_session_line', 't_logprefix', 't_loglevel', 't_query'); } @@ -411,7 +419,7 @@ my %abbr_month = ( my @KEYWORDS1 = ( 'ALL', 'ASC', 'AS', 'ALTER', 'AND', 'ADD', 'AUTO_INCREMENT', 'ANY', 'ANALYZE', 'BETWEEN', 'BINARY', 'BOTH', 'BY', 'BOOLEAN', 'BEGIN', - 'CHANGE', 'CHECK', 'COLUMNS', 'COLUMN', 'CROSS', 'CREATE', 'CASE', 'COMMIT', 'COALESCE', 'CLUSTER', 'COPY', + 'CHANGE', 'CHECK', 'COLLATION', 'COLUMNS', 'COLUMN', 'CONCURRENTLY', 'CROSS', 'CREATE', 'CASE', 'COMMIT', 'COALESCE', 'CLUSTER', 'COPY', 'DATABASES', 'DATABASE', 'DATA', 'DELAYED', 'DESCRIBE', 'DESC', 'DISTINCT', 'DELETE', 'DROP', 'DEFAULT', 'ENCLOSED', 'ESCAPED', 'EXISTS', 'EXPLAIN', 'ELSE', 'END', 'EXCEPT', 'FIELDS', 'FIELD', 'FLUSH', 'FOR', 'FOREIGN', 'FUNCTION', 'FROM', 'FULL', @@ -463,30 +471,30 @@ my @BRACKETS = ('(', ')'); map {$_ = quotemeta($_)} @BRACKETS; # Where statistic are stored -my %STATS = (); -my $first_log_timestamp = ''; -my $last_log_timestamp = ''; -my $first_log_date = ''; -my $last_log_date = ''; -my %overall_stat = (); -my @top_slowest = (); -my %normalyzed_info = (); -my %error_info = (); -my %logs_type = (); -my %per_hour_info = (); -my %per_minute_info = (); -my %lock_info = (); -my %tempfile_info = (); -my %connection_info = (); -my %session_info = (); -my %conn_received = (); -my %checkpoint_info = (); -my @graph_values = (); -my %cur_info = (); -my $nlines = 0; -my %last_line = (); -my %saved_last_line = (); -my %tsung_session = (); +my %STATS = (); +my $first_log_timestamp = ''; +my $last_log_timestamp = ''; +my $first_log_date = ''; +my $last_log_date = ''; +my %overall_stat = (); +my @top_slowest = (); +my %normalyzed_info = (); +my %error_info = (); +my %logs_type = (); +my %per_hour_info = (); +my %per_minute_info = (); +my %lock_info = (); +my %tempfile_info = (); +my %connection_info = (); +my %session_info = (); +my %conn_received = (); +my %checkpoint_info = (); +my @graph_values = (); +my %cur_info = (); +my $nlines = 0; +my %last_line = (); +my %saved_last_line = (); +my %tsung_session = (); my $t0 = Benchmark->new; @@ -529,9 +537,10 @@ foreach my $logfile (@log_files) { $uncompress = $bzcat; } elsif (($logfile =~ /\.zip/i) && ($zcat =~ /^zcat$/)) { $uncompress = $ucat; - } - &logmsg('DEBUG', "Compressed file found, will used command: $uncompress $logfile"); + } + &logmsg('DEBUG', "Compressed file found, will used command: $uncompress $logfile"); open($io, "$uncompress $logfile |") or die "FATAL: cannot open pipe to $uncompress $logfile. $!\n"; + # Real size of the file is unknow, try to find it my $cmd_file_size = $uncompress_size; $cmd_file_size =~ s/\%f/$logfile/g; @@ -554,14 +563,25 @@ foreach my $logfile (@log_files) { print "."; } } + # Process only relevant lines next if ($row->[11] !~ /^(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT)$/); + # Extract the date $row->[0] =~ m/^(\d+)-(\d+)-(\d+)\s+(\d+):(\d+):(\d+)\.(\d+)/; my $milli = $7 || 0; - ($prefix_vars{'t_year'}, $prefix_vars{'t_month'}, $prefix_vars{'t_day'}, $prefix_vars{'t_hour'}, $prefix_vars{'t_min'}, $prefix_vars{'t_sec'}) = ($1, $2, $3, $4, $5, $6); - $prefix_vars{'t_date'} = $prefix_vars{'t_year'} . $prefix_vars{'t_month'} . $prefix_vars{'t_day'} . $prefix_vars{'t_hour'} . $prefix_vars{'t_min'} . $prefix_vars{'t_sec'}; - $prefix_vars{'t_timestamp'} = "$prefix_vars{'t_year'}-$prefix_vars{'t_month'}-$prefix_vars{'t_day'} $prefix_vars{'t_hour'}:$prefix_vars{'t_min'}:$prefix_vars{'t_sec'}"; + ($prefix_vars{'t_year'}, $prefix_vars{'t_month'}, $prefix_vars{'t_day'}, $prefix_vars{'t_hour'}, $prefix_vars{'t_min'}, + $prefix_vars{'t_sec'}) = ($1, $2, $3, $4, $5, $6); + $prefix_vars{'t_date'} = + $prefix_vars{'t_year'} + . $prefix_vars{'t_month'} + . $prefix_vars{'t_day'} + . $prefix_vars{'t_hour'} + . $prefix_vars{'t_min'} + . $prefix_vars{'t_sec'}; + $prefix_vars{'t_timestamp'} = +"$prefix_vars{'t_year'}-$prefix_vars{'t_month'}-$prefix_vars{'t_day'} $prefix_vars{'t_hour'}:$prefix_vars{'t_min'}:$prefix_vars{'t_sec'}"; + # Skip unwanted lines next if ($from && ($from > $prefix_vars{'t_date'})); $getout = 1, last if ($to && ($to < $prefix_vars{'t_date'})); @@ -570,40 +590,41 @@ foreach my $logfile (@log_files) { next if (!&check_incremental_position($prefix_vars{'t_date'}, join(',', @$row))); # Set query parameters as global variables - $prefix_vars{'t_dbuser'} = $row->[1] || ''; - $prefix_vars{'t_dbname'} = $row->[2] || ''; + $prefix_vars{'t_dbuser'} = $row->[1] || ''; + $prefix_vars{'t_dbname'} = $row->[2] || ''; $prefix_vars{'t_appname'} = $row->[2] || ''; - $prefix_vars{'t_client'} = $row->[2] || ''; - $prefix_vars{'t_host'} = 'csv'; - $prefix_vars{'t_pid'} = $row->[3]; + $prefix_vars{'t_client'} = $row->[2] || ''; + $prefix_vars{'t_host'} = 'csv'; + $prefix_vars{'t_pid'} = $row->[3]; $prefix_vars{'t_session_line'} = $row->[5]; $prefix_vars{'t_session_line'} =~ s/\..*//; $prefix_vars{'t_loglevel'} = $row->[11]; - $prefix_vars{'t_query'} = $row->[13]; + $prefix_vars{'t_query'} = $row->[13]; # Store the current timestamp of the log line - if ( !$first_log_date || ($first_log_date > $prefix_vars{'t_date'}) ) { + if (!$first_log_date || ($first_log_date > $prefix_vars{'t_date'})) { $first_log_timestamp = $prefix_vars{'t_timestamp'}; - $first_log_date = $prefix_vars{'t_date'}; + $first_log_date = $prefix_vars{'t_date'}; } - if ( !$last_log_date || ($last_log_date < $prefix_vars{'t_date'}) ) { + if (!$last_log_date || ($last_log_date < $prefix_vars{'t_date'})) { $last_log_timestamp = $prefix_vars{'t_timestamp'}; - $last_log_date = $prefix_vars{'t_date'}; + $last_log_date = $prefix_vars{'t_date'}; } + # Parse the query now &parse_query(); if ($row->[14]) { if ($row->[11] eq 'LOG') { if ($row->[13] =~ /^(duration: \d+\.\d+ ms)/) { $row->[14] = "$1 $row->[14]"; - } + } } $prefix_vars{'t_loglevel'} = 'DETAIL'; - $prefix_vars{'t_query'} = $row->[14]; + $prefix_vars{'t_query'} = $row->[14]; &parse_query(); } if ($row->[15]) { - $prefix_vars{'t_query'} = $row->[15]; + $prefix_vars{'t_query'} = $row->[15]; $prefix_vars{'t_loglevel'} = 'HINT'; &parse_query(); } @@ -627,7 +648,7 @@ foreach my $logfile (@log_files) { } elsif (($logfile =~ /\.zip/i) && ($zcat =~ /^zcat$/)) { $uncompress = $ucat; } - &logmsg('DEBUG', "Compressed log file, will used command: $uncompress $logfile"); + &logmsg('DEBUG', "Compressed log file, will used command: $uncompress $logfile"); # Open a pipe to zcat program for compressed log $lfile->open("$uncompress $logfile |") || die "FATAL: cannot read from pipe to $uncompress $logfile. $!\n"; @@ -666,22 +687,30 @@ foreach my $logfile (@log_files) { if ($#matches >= 0) { - for (my $i = 0; $i <= $#prefix_params; $i++) { + for (my $i = 0 ; $i <= $#prefix_params ; $i++) { $prefix_vars{$prefix_params[$i]} = $matches[$i]; } + # skip non postgresql lines next if ($prefix_vars{'t_ident'} ne $ident); # Syslog do not have year information, so take care of year overlapping - $prefix_vars{'t_year'} = $gyear; - $prefix_vars{'t_day'} = sprintf("%02d", $prefix_vars{'t_day'}); + $prefix_vars{'t_year'} = $gyear; + $prefix_vars{'t_day'} = sprintf("%02d", $prefix_vars{'t_day'}); $prefix_vars{'t_month'} = $month_abbr{$prefix_vars{'t_month'}}; if ("$prefix_vars{'t_year'}$prefix_vars{'t_month'}$prefix_vars{'t_day'}" > $CURRENT_DATE) { $prefix_vars{'t_year'} = substr($CURRENT_DATE, 1, 4) - 1; } - $prefix_vars{'t_date'} = $prefix_vars{'t_year'} . $prefix_vars{'t_month'} . $prefix_vars{'t_day'} . $prefix_vars{'t_hour'} . $prefix_vars{'t_min'} . $prefix_vars{'t_sec'}; - $prefix_vars{'t_timestamp'} = "$prefix_vars{'t_year'}-$prefix_vars{'t_month'}-$prefix_vars{'t_day'} $prefix_vars{'t_hour'}:$prefix_vars{'t_min'}:$prefix_vars{'t_sec'}"; + $prefix_vars{'t_date'} = + $prefix_vars{'t_year'} + . $prefix_vars{'t_month'} + . $prefix_vars{'t_day'} + . $prefix_vars{'t_hour'} + . $prefix_vars{'t_min'} + . $prefix_vars{'t_sec'}; + $prefix_vars{'t_timestamp'} = +"$prefix_vars{'t_year'}-$prefix_vars{'t_month'}-$prefix_vars{'t_day'} $prefix_vars{'t_hour'}:$prefix_vars{'t_min'}:$prefix_vars{'t_sec'}"; # Skip unwanted lines next if ($from && ($from > $prefix_vars{'t_date'})); @@ -692,21 +721,23 @@ foreach my $logfile (@log_files) { $cur_pid = $prefix_vars{'t_pid'}; # Store the current timestamp of the log line - if ( !$first_log_date || ($first_log_date > $prefix_vars{'t_date'}) ) { + if (!$first_log_date || ($first_log_date > $prefix_vars{'t_date'})) { $first_log_timestamp = $prefix_vars{'t_timestamp'}; - $first_log_date = $prefix_vars{'t_date'}; + $first_log_date = $prefix_vars{'t_date'}; } - if ( !$last_log_date || ($last_log_date < $prefix_vars{'t_date'}) ) { + if (!$last_log_date || ($last_log_date < $prefix_vars{'t_date'})) { $last_log_timestamp = $prefix_vars{'t_timestamp'}; - $last_log_date = $prefix_vars{'t_date'}; + $last_log_date = $prefix_vars{'t_date'}; } # Extract information from log line prefix if (!$log_line_prefix) { &parse_log_prefix($prefix_vars{'t_logprefix'}); } + # Check if the log line shoud be exclude from the report if (&validate_log_line($prefix_vars{'t_pid'})) { + # Process the log line &parse_query(); } @@ -715,7 +746,7 @@ foreach my $logfile (@log_files) { $cur_pid = $8; my $t_query = $10; - $t_query = $11 if ($format eq 'syslog-ng');; + $t_query = $11 if ($format eq 'syslog-ng'); $t_query =~ s/#011/\t/g; next if ($t_query eq "\t"); if ($cur_info{$cur_pid}{statement}) { @@ -750,7 +781,7 @@ foreach my $logfile (@log_files) { %prefix_vars = (); my @matches = ($line =~ $compiled_prefix); if ($#matches >= 0) { - for (my $i = 0; $i <= $#prefix_params; $i++) { + for (my $i = 0 ; $i <= $#prefix_params ; $i++) { $prefix_vars{$prefix_params[$i]} = $matches[$i]; } if (!$prefix_vars{'t_timestamp'} && $prefix_vars{'t_mtimestamp'}) { @@ -758,8 +789,15 @@ foreach my $logfile (@log_files) { } elsif (!$prefix_vars{'t_timestamp'} && $prefix_vars{'t_session_timestamp'}) { $prefix_vars{'t_timestamp'} = $prefix_vars{'t_session_timestamp'}; } - ($prefix_vars{'t_year'}, $prefix_vars{'t_month'}, $prefix_vars{'t_day'}, $prefix_vars{'t_hour'}, $prefix_vars{'t_min'}, $prefix_vars{'t_sec'}) = ($prefix_vars{'t_timestamp'} =~ $time_pattern); - $prefix_vars{'t_date'} = $prefix_vars{'t_year'} . $prefix_vars{'t_month'} . $prefix_vars{'t_day'} . $prefix_vars{'t_hour'} . $prefix_vars{'t_min'} . $prefix_vars{'t_sec'}; + ($prefix_vars{'t_year'}, $prefix_vars{'t_month'}, $prefix_vars{'t_day'}, $prefix_vars{'t_hour'}, + $prefix_vars{'t_min'}, $prefix_vars{'t_sec'}) = ($prefix_vars{'t_timestamp'} =~ $time_pattern); + $prefix_vars{'t_date'} = + $prefix_vars{'t_year'} + . $prefix_vars{'t_month'} + . $prefix_vars{'t_day'} + . $prefix_vars{'t_hour'} + . $prefix_vars{'t_min'} + . $prefix_vars{'t_sec'}; # Skip unwanted lines next if ($from && ($from > $prefix_vars{'t_date'})); @@ -770,13 +808,13 @@ foreach my $logfile (@log_files) { $cur_pid = $prefix_vars{'t_pid'}; # Store the current timestamp of the log line - if ( !$first_log_date || ($first_log_date > $prefix_vars{'t_date'}) ) { + if (!$first_log_date || ($first_log_date > $prefix_vars{'t_date'})) { $first_log_timestamp = $prefix_vars{'t_timestamp'}; - $first_log_date = $prefix_vars{'t_date'}; + $first_log_date = $prefix_vars{'t_date'}; } - if ( !$last_log_date || ($last_log_date < $prefix_vars{'t_date'}) ) { + if (!$last_log_date || ($last_log_date < $prefix_vars{'t_date'})) { $last_log_timestamp = $prefix_vars{'t_timestamp'}; - $last_log_date = $prefix_vars{'t_date'}; + $last_log_date = $prefix_vars{'t_date'}; } # Extract information from log line prefix @@ -787,11 +825,12 @@ foreach my $logfile (@log_files) { # Check if the log line shoud be exclude from the report if (&validate_log_line($prefix_vars{'t_pid'})) { $prefix_vars{'t_host'} = 'stderr'; + # Process the log line &parse_query(); } - - # Collect orphans lines of multiline queries + + # Collect orphans lines of multiline queries } elsif ($line !~ $orphan_stderr_line) { if ($cur_info{$cur_pid}{statement}) { @@ -822,7 +861,7 @@ foreach my $logfile (@log_files) { &store_queries($pid); } if ($extension eq 'tsung') { - foreach my $pid (sort { $a <=> $b } keys %tsung_session) { + foreach my $pid (sort {$a <=> $b} keys %tsung_session) { &store_tsung_session($pid); } } @@ -875,6 +914,7 @@ if ($extension ne 'tsung') { } $fh->close; } else { + # Open filehandle $fh = new IO::File ">>$outfile"; if (not defined $fh) { @@ -1188,12 +1228,12 @@ Log start from $first_log_timestamp to $last_log_timestamp }; # Overall statistics - my $fmt_unique = &comma_numbers(scalar keys %normalyzed_info) || 0; - my $fmt_queries = &comma_numbers($overall_stat{'queries_number'}) || 0; + my $fmt_unique = &comma_numbers(scalar keys %normalyzed_info) || 0; + my $fmt_queries = &comma_numbers($overall_stat{'queries_number'}) || 0; if ((scalar keys %normalyzed_info == 1) && ($overall_stat{'queries_number'} > 1)) { - $fmt_unique = 'none'; + $fmt_unique = 'none'; $overall_stat{'first_query_ts'} = $first_log_timestamp; - $overall_stat{'last_query_ts'} = $last_log_timestamp; + $overall_stat{'last_query_ts'} = $last_log_timestamp; } my $fmt_duration = &convert_time($overall_stat{'queries_duration'}) || 0; print $fh qq{ @@ -1251,7 +1291,7 @@ Report not supported by text format # INSERT/DELETE/UPDATE/SELECT repartition my $totala = $overall_stat{'SELECT'} + $overall_stat{'INSERT'} + $overall_stat{'UPDATE'} + $overall_stat{'DELETE'}; - my $total = $overall_stat{'queries_number'} || 1; + my $total = $overall_stat{'queries_number'} || 1; print $fh "\n- Queries by type ------------------------------------------------------\n\n"; print $fh "Type Count Percentage\n"; print $fh "SELECT: ", &comma_numbers($overall_stat{'SELECT'}) || 0, " ", @@ -1498,8 +1538,9 @@ sub show_error_as_text print $fh "--\n"; my $j = 1; for (my $i = 0 ; $i <= $#{$error_info{$k}{date}} ; $i++) { - if ( ($error_info{$k}{error}[$i] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) || - ($error_info{$k}{error}[$i] =~ s/HINT: (database system was shut down)/LOG: $1/) ) { + if ( ($error_info{$k}{error}[$i] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) + || ($error_info{$k}{error}[$i] =~ s/HINT: (database system was shut down)/LOG: $1/)) + { $logs_type{HINT}--; $logs_type{LOG}++; } @@ -1511,8 +1552,9 @@ sub show_error_as_text $j++; } } else { - if ( ($error_info{$k}{error}[0] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) || - ($error_info{$k}{error}[0] =~ s/HINT: (database system was shut down)/LOG: $1/) ) { + if ( ($error_info{$k}{error}[0] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) + || ($error_info{$k}{error}[0] =~ s/HINT: (database system was shut down)/LOG: $1/)) + { $logs_type{HINT}--; $logs_type{LOG}++; } @@ -1924,12 +1966,12 @@ sub dump_as_html }; # Overall statistics - my $fmt_unique = &comma_numbers(scalar keys %normalyzed_info) || 0; - my $fmt_queries = &comma_numbers($overall_stat{'queries_number'}) || 0; + my $fmt_unique = &comma_numbers(scalar keys %normalyzed_info) || 0; + my $fmt_queries = &comma_numbers($overall_stat{'queries_number'}) || 0; if ((scalar keys %normalyzed_info == 1) && ($overall_stat{'queries_number'} > 1)) { - $fmt_unique = 'none'; + $fmt_unique = 'none'; $overall_stat{'first_query_ts'} = $first_log_timestamp; - $overall_stat{'last_query_ts'} = $last_log_timestamp; + $overall_stat{'last_query_ts'} = $last_log_timestamp; } my $fmt_duration = &convert_time($overall_stat{'queries_duration'}) || 0; print $fh qq{ @@ -2082,13 +2124,13 @@ sub dump_as_html if ($graph) { $first_log_timestamp =~ /(\d+)-(\d+)-(\d+) (\d+):(\d+):(\d+)/; - $t_min = timegm_nocheck(0, $5, $4, $3, $2-1, $1) * 1000; - $t_min -= ($avg_minutes*60000); - $t_min_hour = timegm_nocheck(0, 0, $4, $3, $2-1, $1) * 1000; + $t_min = timegm_nocheck(0, $5, $4, $3, $2 - 1, $1) * 1000; + $t_min -= ($avg_minutes * 60000); + $t_min_hour = timegm_nocheck(0, 0, $4, $3, $2 - 1, $1) * 1000; $last_log_timestamp =~ /(\d+)-(\d+)-(\d+) (\d+):(\d+):(\d+)/; - $t_max = timegm_nocheck(59, $5, $4, $3, $2-1, $1) * 1000; - $t_max += ($avg_minutes*60000); - $t_max_hour = timegm_nocheck(0, 0, $4, $3, $2-1, $1) * 1000; + $t_max = timegm_nocheck(59, $5, $4, $3, $2 - 1, $1) * 1000; + $t_max += ($avg_minutes * 60000); + $t_max_hour = timegm_nocheck(0, 0, $4, $3, $2 - 1, $1) * 1000; my @labels = (); my @data1 = (); my @data2 = (); @@ -2097,6 +2139,7 @@ sub dump_as_html my $d2 = ''; my $d3 = ''; my @avgs = (); + for (my $i = 0 ; $i < 59 ; $i += $avg_minutes) { push(@avgs, sprintf("%02d", $i)); } @@ -2130,6 +2173,7 @@ sub dump_as_html next if ($t < $t_min); last if ($t > $t_max); + # Average per minutes $d2 .= "[$t, " . int(($dataavg{average}{"$rd"} || 0) / (60 * $avg_minutes)) . "],"; @@ -2183,6 +2227,7 @@ sub dump_as_html next if ($t < $t_min); last if ($t > $t_max); + # Average per minutes $d2 .= "[$t, " . int(($dataavg{average}{"$rd"} || 0) / (60 * $avg_minutes)) . "],"; @@ -2233,6 +2278,7 @@ sub dump_as_html $d2 = ''; if (!$disable_query && (!$log_duration || $enable_log_min_duration)) { + # Select queries foreach my $tm (sort {$a <=> $b} keys %per_hour_info) { $tm =~ /(\d{4})(\d{2})(\d{2})/; @@ -2247,7 +2293,8 @@ sub dump_as_html $d2 .= "[$t, " . sprintf( "%.2f", - (($per_hour_info{$tm}{$h}{'SELECT'}{duration} || 0) / ($per_hour_info{$tm}{$h}{'SELECT'}{count} || 1)) / 1000 + (($per_hour_info{$tm}{$h}{'SELECT'}{duration} || 0) / ($per_hour_info{$tm}{$h}{'SELECT'}{count} || 1)) / + 1000 ) . "],"; } } @@ -3157,8 +3204,9 @@ sub show_error_as_html print $fh "
"; for (my $i = 0 ; $i <= $#{$error_info{$k}{date}} ; $i++) { - if ( ($error_info{$k}{error}[$i] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) || - ($error_info{$k}{error}[$i] =~ s/HINT: (database system was shut down)/LOG: $1/) ) { + if ( ($error_info{$k}{error}[$i] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) + || ($error_info{$k}{error}[$i] =~ s/HINT: (database system was shut down)/LOG: $1/)) + { $logs_type{HINT}--; $logs_type{LOG}++; } @@ -3174,8 +3222,9 @@ sub show_error_as_html } print $fh "
"; } else { - if ( ($error_info{$k}{error}[0] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) || - ($error_info{$k}{error}[0] =~ s/HINT: (database system was shut down)/LOG: $1/) ) { + if ( ($error_info{$k}{error}[0] =~ s/HINT: (parameter "[^"]+" changed to)/LOG: $1/) + || ($error_info{$k}{error}[0] =~ s/HINT: (database system was shut down)/LOG: $1/)) + { $logs_type{HINT}--; $logs_type{LOG}++; } @@ -3335,7 +3384,6 @@ sub compute_arg_list push(@dbappname, @tmp); } - sub validate_log_line { my ($t_pid) = @_; @@ -3385,13 +3433,13 @@ sub validate_log_line return 1; } - sub parse_log_prefix { my ($t_logprefix) = @_; # Extract user and database information from the logprefix part if ($t_logprefix) { + # Search for database user if ($t_logprefix =~ $regex_prefix_dbuser) { $prefix_vars{'t_dbuser'} = $1; @@ -3446,7 +3494,8 @@ sub parse_query my $date_part = "$prefix_vars{'t_year'}$prefix_vars{'t_month'}$prefix_vars{'t_day'}"; # Stores lock activity - if (($prefix_vars{'t_loglevel'} eq 'LOG') && ($prefix_vars{'t_query'} =~ /acquired ([^\s]+) on ([^\s]+) .* after ([0-9\.]+) ms/)) { + if (($prefix_vars{'t_loglevel'} eq 'LOG') && ($prefix_vars{'t_query'} =~ /acquired ([^\s]+) on ([^\s]+) .* after ([0-9\.]+) ms/)) + { return if ($disable_lock); $lock_info{$1}{count}++; $lock_info{$1}{duration} += $3; @@ -3476,14 +3525,16 @@ sub parse_query } # Stores connection activity - if (($prefix_vars{'t_loglevel'} eq 'LOG') && ($prefix_vars{'t_query'} =~ /connection authorized: user=([^\s]+) database=([^\s]+)/)) { + if ( ($prefix_vars{'t_loglevel'} eq 'LOG') + && ($prefix_vars{'t_query'} =~ /connection authorized: user=([^\s]+) database=([^\s]+)/)) + { return if ($disable_connection); my $usr = $1; my $db = $2; if ($extension eq 'tsung') { $tsung_session{$prefix_vars{'t_pid'}}{connection}{database} = $db; - $tsung_session{$prefix_vars{'t_pid'}}{connection}{user} = $usr; - $tsung_session{$prefix_vars{'t_pid'}}{connection}{date} = $prefix_vars{'t_date'}; + $tsung_session{$prefix_vars{'t_pid'}}{connection}{user} = $usr; + $tsung_session{$prefix_vars{'t_pid'}}{connection}{date} = $prefix_vars{'t_date'}; return; } @@ -3498,7 +3549,8 @@ sub parse_query if ($graph) { $per_minute_info{connection}{$date_part}{$prefix_vars{'t_hour'}}{"$prefix_vars{'t_min'}"}{count}++; - $per_minute_info{connection}{$date_part}{$prefix_vars{'t_hour'}}{"$prefix_vars{'t_min'}"}{second}{$prefix_vars{'t_sec'}}++; + $per_minute_info{connection}{$date_part}{$prefix_vars{'t_hour'}}{"$prefix_vars{'t_min'}"}{second} + {$prefix_vars{'t_sec'}}++; } if (exists $conn_received{$t_pid}) { $connection_info{host}{$conn_received{$t_pid}}++; @@ -3509,8 +3561,9 @@ sub parse_query } # Stores session duration - if ( ($prefix_vars{'t_loglevel'} eq 'LOG') - && ($prefix_vars{'t_query'} =~ /disconnection: session time: ([^\s]+) user=([^\s]+) database=([^\s]+) host=([^\s]+) port=(\d+)/)) + if (($prefix_vars{'t_loglevel'} eq 'LOG') + && ($prefix_vars{'t_query'} =~ + /disconnection: session time: ([^\s]+) user=([^\s]+) database=([^\s]+) host=([^\s]+) port=(\d+)/)) { return if ($disable_session); if ($extension eq 'tsung') { @@ -3572,7 +3625,9 @@ sub parse_query $checkpoint_info{chronos}{$date_part}{$prefix_vars{'t_hour'}}{total} += $8; return; } - if (($prefix_vars{'t_loglevel'} eq 'LOG') && ($prefix_vars{'t_query'} =~ /checkpoints are occurring too frequently \((\d+) seconds apart\)/)) { + if ( ($prefix_vars{'t_loglevel'} eq 'LOG') + && ($prefix_vars{'t_query'} =~ /checkpoints are occurring too frequently \((\d+) seconds apart\)/)) + { return if ($disable_checkpoint); $checkpoint_info{warning}++; $checkpoint_info{warning_seconds} += $1; @@ -3591,6 +3646,7 @@ sub parse_query # Process current query following context if ($cur_info{$t_pid}{query}) { + # Remove obsolete connexion storage delete $conn_received{$cur_info{$t_pid}{pid}}; @@ -3628,8 +3684,8 @@ sub parse_query my $t_duration = ''; if ($log_duration) { if ($prefix_vars{'t_query'} =~ s/duration: ([0-9\.]+) ms$//s) { - $t_duration = $1; - $t_action = 'statement'; + $t_duration = $1; + $t_action = 'statement'; $prefix_vars{'t_query'} = 'No log_min_duration'; } elsif (!$enable_log_min_duration) { if (exists $cur_info{$t_pid} && ($prefix_vars{'t_session_line'} != $cur_info{$t_pid}{session})) { @@ -3642,27 +3698,30 @@ sub parse_query if (!$log_duration || $enable_log_min_duration) { if (($extension eq 'tsung') && !exists $tsung_session{$prefix_vars{'t_pid'}}{connection} && $prefix_vars{'t_dbname'}) { $tsung_session{$prefix_vars{'t_pid'}}{connection}{database} = $prefix_vars{'t_dbname'}; - $tsung_session{$prefix_vars{'t_pid'}}{connection}{user} = $prefix_vars{'t_dbuser'}; - $tsung_session{$prefix_vars{'t_pid'}}{connection}{date} = $prefix_vars{'t_date'}; + $tsung_session{$prefix_vars{'t_pid'}}{connection}{user} = $prefix_vars{'t_dbuser'}; + $tsung_session{$prefix_vars{'t_pid'}}{connection}{date} = $prefix_vars{'t_date'}; } if ($prefix_vars{'t_query'} =~ s/duration: ([0-9\.]+) ms (query|statement): //is) { $t_duration = $1; $t_action = $2; - } elsif ($prefix_vars{'t_query'} =~ s/duration: ([0-9\.]+) ms (prepare|parse|bind|execute|execute from fetch)\s+[^:]+:\s//is) { + } elsif ($prefix_vars{'t_query'} =~ s/duration: ([0-9\.]+) ms (prepare|parse|bind|execute|execute from fetch)\s+[^:]+:\s//is) + { $t_duration = $1; $t_action = $2; + # Skiping parse and bind logs return if ($t_action !~ /query|statement|execute|bind/); } elsif (!$duration_required && ($prefix_vars{'t_query'} =~ s/(query|statement): //is)) { $t_action = $1; - } elsif (!$duration_required && ($prefix_vars{'t_query'} =~ s/(prepare|parse|bind|execute|execute from fetch)\s+[^:]+:\s//is)) { + } elsif (!$duration_required && ($prefix_vars{'t_query'} =~ s/(prepare|parse|bind|execute|execute from fetch)\s+[^:]+:\s//is)) + { $t_action = $1; # Skiping parse and bind logs return if ($t_action !~ /query|statement|execute|bind/); } elsif ($prefix_vars{'t_loglevel'} eq 'LOG') { if ($prefix_vars{'t_query'} !~ - /incomplete startup packet|connection|receive|unexpected EOF|still waiting for [^\s]+Lock|checkpoint starting:|could not send data to client|parameter .*configuration file|autovacuum launcher|automatic (analyze|vacuum)|detected deadlock while waiting for|database system was shut down/ +/incomplete startup packet|connection|receive|unexpected EOF|still waiting for [^\s]+Lock|checkpoint starting:|could not send data to client|parameter .*configuration file|autovacuum launcher|automatic (analyze|vacuum)|detected deadlock while waiting for|database system was shut down/ ) { &logmsg('DEBUG', "Unrecognized line: $prefix_vars{'t_loglevel'}: $prefix_vars{'t_query'} at line $nlines"); @@ -3674,24 +3733,24 @@ sub parse_query return; } } - $cur_info{$t_pid}{year} = $prefix_vars{'t_year'}; - $cur_info{$t_pid}{month} = $prefix_vars{'t_month'}; - $cur_info{$t_pid}{day} = $prefix_vars{'t_day'}; - $cur_info{$t_pid}{hour} = $prefix_vars{'t_hour'}; - $cur_info{$t_pid}{min} = $prefix_vars{'t_min'}; - $cur_info{$t_pid}{sec} = $prefix_vars{'t_sec'}; - $cur_info{$t_pid}{date} = $prefix_vars{'t_date'}; - $cur_info{$t_pid}{ident} = $prefix_vars{'t_ident'}; - $cur_info{$t_pid}{query} = $prefix_vars{'t_query'}; - $cur_info{$t_pid}{duration} = $t_duration; - $cur_info{$t_pid}{pid} = $prefix_vars{'t_pid'}; - $cur_info{$t_pid}{session} = $prefix_vars{'t_session_line'}; - $cur_info{$t_pid}{loglevel} = $prefix_vars{'t_loglevel'}; - $cur_info{$t_pid}{dbname} = $prefix_vars{'t_dbname'}; - $cur_info{$t_pid}{dbuser} = $prefix_vars{'t_dbuser'}; - $cur_info{$t_pid}{dbclient} = $prefix_vars{'t_client'}; - $cur_info{$t_pid}{dbappname}= $prefix_vars{'t_appname'}; - $cur_info{$t_pid}{action} = $t_action; + $cur_info{$t_pid}{year} = $prefix_vars{'t_year'}; + $cur_info{$t_pid}{month} = $prefix_vars{'t_month'}; + $cur_info{$t_pid}{day} = $prefix_vars{'t_day'}; + $cur_info{$t_pid}{hour} = $prefix_vars{'t_hour'}; + $cur_info{$t_pid}{min} = $prefix_vars{'t_min'}; + $cur_info{$t_pid}{sec} = $prefix_vars{'t_sec'}; + $cur_info{$t_pid}{date} = $prefix_vars{'t_date'}; + $cur_info{$t_pid}{ident} = $prefix_vars{'t_ident'}; + $cur_info{$t_pid}{query} = $prefix_vars{'t_query'}; + $cur_info{$t_pid}{duration} = $t_duration; + $cur_info{$t_pid}{pid} = $prefix_vars{'t_pid'}; + $cur_info{$t_pid}{session} = $prefix_vars{'t_session_line'}; + $cur_info{$t_pid}{loglevel} = $prefix_vars{'t_loglevel'}; + $cur_info{$t_pid}{dbname} = $prefix_vars{'t_dbname'}; + $cur_info{$t_pid}{dbuser} = $prefix_vars{'t_dbuser'}; + $cur_info{$t_pid}{dbclient} = $prefix_vars{'t_client'}; + $cur_info{$t_pid}{dbappname} = $prefix_vars{'t_appname'}; + $cur_info{$t_pid}{action} = $t_action; return 1; } @@ -3723,7 +3782,7 @@ sub store_tsung_session } print $fh " \n" if ($sec > 0); print $fh " \n"; - for (my $i = 0; $i <= $#{$tsung_session{$pid}{queries}}; $i++) { + for (my $i = 0 ; $i <= $#{$tsung_session{$pid}{queries}} ; $i++) { $tsung_queries++; $sec = 0; if ($i > 0) { @@ -3751,7 +3810,6 @@ sub store_queries { my $t_pid = shift; - # Remove comments if required if ($remove_comment) { $cur_info{$t_pid}{query} =~ s/\/\*(.*?)\*\///gs; @@ -3763,7 +3821,7 @@ sub store_queries # Should we just want select queries if ($select_only) { - return if ( ($cur_info{$t_pid}{query} !~ /^SELECT/is) || ($cur_info{$t_pid}{query} =~ /FOR UPDATE/is) ); + return if (($cur_info{$t_pid}{query} !~ /^SELECT/is) || ($cur_info{$t_pid}{query} =~ /FOR UPDATE/is)); } # Should we have to exclude some queries @@ -3794,11 +3852,11 @@ sub store_queries if ($extension eq 'tsung') { if ($cur_info{$t_pid}{loglevel} eq 'LOG') { push(@{$tsung_session{$t_pid}{queries}}, $cur_info{$t_pid}{query}); - push(@{$tsung_session{$t_pid}{dates}}, $cur_info{$t_pid}{date}); + push(@{$tsung_session{$t_pid}{dates}}, $cur_info{$t_pid}{date}); if (!exists $tsung_session{$t_pid}{connection} && $cur_info{$t_pid}{t_dbname}) { $tsung_session{$t_pid}{connection}{database} = $cur_info{$t_pid}{t_dbname}; - $tsung_session{$t_pid}{connection}{user} = $cur_info{$t_pid}{t_dbuser}; - $tsung_session{$t_pid}{connection}{date} = $cur_info{$t_pid}{date}; + $tsung_session{$t_pid}{connection}{user} = $cur_info{$t_pid}{t_dbuser}; + $tsung_session{$t_pid}{connection}{date} = $cur_info{$t_pid}{date}; } } return; @@ -3824,7 +3882,7 @@ sub store_queries my $cur_last_log_timestamp = "$cur_info{$t_pid}{year}-$cur_info{$t_pid}{month}-$cur_info{$t_pid}{day} $cur_info{$t_pid}{hour}:$cur_info{$t_pid}{min}:$cur_info{$t_pid}{sec}"; &set_top_error_sample( - $normalized_error, $cur_last_log_timestamp, $cur_info{$t_pid}{query}, $cur_info{$t_pid}{detail}, + $normalized_error, $cur_last_log_timestamp, $cur_info{$t_pid}{query}, $cur_info{$t_pid}{detail}, $cur_info{$t_pid}{context}, $cur_info{$t_pid}{statement}, $cur_info{$t_pid}{hint} ); @@ -3843,11 +3901,11 @@ sub store_queries "$cur_info{$t_pid}{year}$cur_info{$t_pid}{month}$cur_info{$t_pid}{day}$cur_info{$t_pid}{hour}$cur_info{$t_pid}{min}$cur_info{$t_pid}{sec}"; $overall_stat{'queries_number'}++; $overall_stat{'queries_duration'} += $cur_info{$t_pid}{duration}; - if ( !$overall_stat{'first_query_date'} || ($overall_stat{'first_query_date'} > $cur_last_log_date) ) { - $overall_stat{'first_query_ts'} = $cur_last_log_timestamp; + if (!$overall_stat{'first_query_date'} || ($overall_stat{'first_query_date'} > $cur_last_log_date)) { + $overall_stat{'first_query_ts'} = $cur_last_log_timestamp; $overall_stat{'first_query_date'} = $cur_last_log_date; } - if ( !$overall_stat{'last_query_date'} || ($overall_stat{'last_query_date'} < $cur_last_log_date) ) { + if (!$overall_stat{'last_query_date'} || ($overall_stat{'last_query_date'} < $cur_last_log_date)) { $overall_stat{'last_query_ts'} = $cur_last_log_timestamp; } $overall_stat{'query_peak'}{$cur_last_log_timestamp}++; @@ -3998,6 +4056,7 @@ sub autodetect_format } &logmsg('DEBUG', "Detect compressed file, will used command: $uncompress $file"); + # Open a pipe to zcat program for compressed log $tfile->open("$uncompress $file |") || die "FATAL: cannot read from pipe to $uncompress $file. $!\n"; } @@ -4013,16 +4072,29 @@ sub autodetect_format $nline++; # Is syslog lines ? - if ($line =~ /^[A-Z][a-z]{2}\s+\d+\s\d+:\d+:\d+(?:\s[^\s]+)?\s[^\s]+\s([^\s\[]+)\[\d+\]:(?:\s\[[^\]]+\])?\s\[\d+\-\d+\].*?(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+$duration/) { + if ($line =~ +/^[A-Z][a-z]{2}\s+\d+\s\d+:\d+:\d+(?:\s[^\s]+)?\s[^\s]+\s([^\s\[]+)\[\d+\]:(?:\s\[[^\]]+\])?\s\[\d+\-\d+\].*?(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+$duration/ + ) + { $fmt = 'syslog'; $nfound++; $ident_name{$1}++; # Is stderr lines - } elsif ( ($line =~ /^\d+-\d+-\d+ \d+:\d+:\d+\.\d+(?: [A-Z\d]{3,6})?,.*,(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT),/) && ($line =~ tr/,/,/ >= 12) ) { + } elsif ( + ( + $line =~ + /^\d+-\d+-\d+ \d+:\d+:\d+\.\d+(?: [A-Z\d]{3,6})?,.*,(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT),/ + ) + && ($line =~ tr/,/,/ >= 12) + ) + { $fmt = 'csv'; $nfound++; - } elsif ($line =~ /\d+-\d+-\d+ \d+:\d+:\d+[\.0-9]*(?: [A-Z\d]{3,6})?(.*?)(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+$duration/) { + } elsif ($line =~ +/\d+-\d+-\d+ \d+:\d+:\d+[\.0-9]*(?: [A-Z\d]{3,6})?(.*?)(LOG|WARNING|ERROR|FATAL|PANIC|DETAIL|STATEMENT|HINT|CONTEXT):\s+$duration/ + ) + { $fmt = 'stderr'; $nfound++; } @@ -4061,6 +4133,7 @@ sub autodetect_duration } &logmsg('DEBUG', "Found compressed file, will used command: $uncompress $file"); + # Open a pipe to zcat program for compressed log $tfile->open("$uncompress $file |") || die "FATAL: cannot read from pipe to $uncompress $file. $!\n"; } @@ -4070,7 +4143,9 @@ sub autodetect_duration $line =~ s/ //; next if (!$line); $nline++; - if (($line =~ /\s+duration: \d+\.\d+ ms\s+(query|statement|prepare|parse|bind|execute)/) || ($line =~ /,"duration: \d+\.\d+ ms\s+(query|statement|prepare|parse|bind|execute)[^"]+"/)) { + if ( ($line =~ /\s+duration: \d+\.\d+ ms\s+(query|statement|prepare|parse|bind|execute)/) + || ($line =~ /,"duration: \d+\.\d+ ms\s+(query|statement|prepare|parse|bind|execute)[^"]+"/)) + { $nfound++; } last if (($nfound > 10) || ($nline > 25000)); @@ -4087,7 +4162,6 @@ sub autodetect_duration return 1; } - sub progress_bar { my ($got, $total, $width, $char) = @_; @@ -4324,24 +4398,24 @@ EOF sub build_log_line_prefix_regex { my %regex_map = ( - '%a' => [ ('t_appname', '([0-9a-zA-Z\.\-\_\/\[\]]*)') ], # application name - '%u' => [ ('t_dbuser', '([0-9a-zA-Z\_\[\]]*)') ], # user name - '%d' => [ ('t_dbname', '([0-9a-zA-Z\_\[\]]*)') ], # database name - '%r' => [ ('t_hostport', '(\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})?[\(\d\)]*') ], # remote host and port - '%h' => [ ('t_client', '(\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})?') ], # remote host - '%p' => [ ('t_pid', '(\d+)') ], # process ID - '%t' => [ ('t_timestamp', '(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})(?: [A-Z\d]{3,6})?') ], # timestamp without milliseconds - '%m' => [ ('t_mtimestamp', '(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\d]{3,6})?') ], # timestamp with milliseconds - '%l' => [ ('t_session_line', '(\d+)') ], # session line number - '%s' => [ ('t_session_timestamp', '(\d{4}-\d{2}-\d{2} \d{2}):\d{2}:\d{2})(?: [A-Z\d]{3,6})?') ], # session start timestamp - '%c' => [ ('t_session_id', '([0-9a-f\.]*)') ], # session ID - '%v' => [ ('t_virtual_xid', '([0-9a-f\.\/]*)') ], # virtual transaction ID - '%x' => [ ('t_xid', '([0-9a-f\.\/]*)') ], # transaction ID - '%i' => [ ('t_command', '([0-9a-zA-Z\.\-\_]*)') ], # command tag - '%e' => [ ('t_sqlstate', '([0-9a-zA-Z]+)') ], # SQL state + '%a' => [('t_appname', '([0-9a-zA-Z\.\-\_\/\[\]]*)')], # application name + '%u' => [('t_dbuser', '([0-9a-zA-Z\_\[\]]*)')], # user name + '%d' => [('t_dbname', '([0-9a-zA-Z\_\[\]]*)')], # database name + '%r' => [('t_hostport', '(\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})?[\(\d\)]*')], # remote host and port + '%h' => [('t_client', '(\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})?')], # remote host + '%p' => [('t_pid', '(\d+)')], # process ID + '%t' => [('t_timestamp', '(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})(?: [A-Z\d]{3,6})?')], # timestamp without milliseconds + '%m' => [('t_mtimestamp', '(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\d]{3,6})?')], # timestamp with milliseconds + '%l' => [('t_session_line', '(\d+)')], # session line number + '%s' => [('t_session_timestamp', '(\d{4}-\d{2}-\d{2} \d{2}):\d{2}:\d{2})(?: [A-Z\d]{3,6})?')], # session start timestamp + '%c' => [('t_session_id', '([0-9a-f\.]*)')], # session ID + '%v' => [('t_virtual_xid', '([0-9a-f\.\/]*)')], # virtual transaction ID + '%x' => [('t_xid', '([0-9a-f\.\/]*)')], # transaction ID + '%i' => [('t_command', '([0-9a-zA-Z\.\-\_]*)')], # command tag + '%e' => [('t_sqlstate', '([0-9a-zA-Z]+)')], # SQL state ); my @param_list = (); - $log_line_prefix =~ s/([\[\]\|\(\)\{\}])/\\$1/g; + $log_line_prefix =~ s/([\[\]\|\(\)\{\}])/\\$1/g; $log_line_prefix =~ s/\%l([^\d])\d+/\%l$1\\d\+/; while ($log_line_prefix =~ s/(\%[audrhptmlscvxie])/$regex_map{"$1"}->[1]/) { push(@param_list, $regex_map{"$1"}->[0]);