Fix pgbouncer parsing and request throughput reports. Thanks to Levente Birta for...

diff --git a/pgbadger b/pgbadger
index ddb56322e15ff5a2edd332d6a89076ddccfbe1ca..f58b89ba73db4bb1d668e40996b341ae7dc9d7cd 100755 (executable)
--- a/pgbadger
+++ b/pgbadger
@@ -1988,34 +1988,30 @@ sub set_parser_regex
        @prefix_q_params = ();
 
        if ($fmt eq 'pgbouncer') {
-
                $pgbouncer_log_format = qr/^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\+\-\d]{3,6})? (\d+) ([^\s]+) (.\-0x[0-9a-f\.]*): ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)(?:\(\d+\))??[:\d]* (.*)/;
                @pgb_prefix_params = ('t_timestamp', 't_pid', 't_loglevel', 't_session_id', 't_dbname', 't_dbuser', 't_client', 't_query');
-
-               $pgbouncer_log_parse1 = qr/^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\+\-\d]{3,6})? (\d+) ([^\s]+) (.*)/;
-               @pgb_prefix_parse1 = ('t_timestamp', 't_pid', 't_loglevel', 't_query');
+               $pgbouncer_log_parse1 = qr/^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\+\-\d]{3,6})? (\d+) ([^\s]+) (.\-0x[0-9a-f\.]+|Stats): (.*)/;
+               @pgb_prefix_parse1 = ('t_timestamp', 't_pid', 't_loglevel', 't_session_id', 't_query');
                $pgbouncer_log_parse2 = qr/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d+(?: [A-Z\+\-\d]{3,6})? \d+ [^\s]+ .\-0x[0-9a-f\.]*: ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)?(?:\(\d+\))?(?:\(\d+\))?[:\d]* (.*)/;
                @pgb_prefix_parse2 = ('t_dbname', 't_dbuser', 't_client', 't_query');
 
        } elsif ($fmt eq 'pgbouncer1') {
 
-               $fmt = 'pgbouncer';
                $pgbouncer_log_format = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]*): ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)?(?:\(\d+\))?[:\d]* (.*)/;
                @pgb_prefix_params = ('t_year', 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_id', 't_dbname', 't_dbuser', 't_client', 't_query');
 
-               $pgbouncer_log_parse1 = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]*): (.*)/;
-               @pgb_prefix_parse1 = ('t_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_query');
+               $pgbouncer_log_parse1 = qr/^(...)\s+(\d+)\s(\d+):(\d+):(\d+)(?:\s[^\s]+)?\s([^\s]+)\s([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]+|Stats): (.*)/;
+               @pgb_prefix_parse1 = ('t_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_id', 't_query');
                $pgbouncer_log_parse2 = qr/^...\s+\d+\s\d+:\d+:\d+(?:\s[^\s]+)?\s[^\s]+\s[^\s\[]+\[\d+\]: .\-0x[0-9a-f\.]*: ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)?(?:\(\d+\))?[:\d]* (.*)/;
                @pgb_prefix_parse2 = ('t_dbname', 't_dbuser', 't_client', 't_query');
 
        } elsif ($fmt eq 'pgbouncer2') {
 
-               $fmt = 'pgbouncer';
                $pgbouncer_log_format = qr/^(\d{4})-(\d{2})-(\d{2})T(\d{2}):(\d{2}):(\d{2})(?:.[^\s]+)?\s([^\s]+)\s(?:[^\s]+\s)?(?:[^\s]+\s)?([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]*): ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)?(?:\(\d+\))?[:\d]* (.*)/;
                @pgb_prefix_params = ('t_year', 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_id', 't_dbname', 't_dbuser', 't_client', 't_query');
 
-               $pgbouncer_log_parse1 = qr/^(\d{4})-(\d{2})-(\d{2})T(\d{2}):(\d{2}):(\d{2})(?:.[^\s]+)?\s([^\s]+)\s(?:[^\s]+\s)?(?:[^\s]+\s)?([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]*): (.*)/;
-               @pgb_prefix_parse1 = ('t_year', 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_query');
+               $pgbouncer_log_parse1 = qr/^(\d{4})-(\d{2})-(\d{2})T(\d{2}):(\d{2}):(\d{2})(?:.[^\s]+)?\s([^\s]+)\s(?:[^\s]+\s)?(?:[^\s]+\s)?([^\s\[]+)\[(\d+)\]: (.\-0x[0-9a-f\.]+|Stats): (.*)/;
+               @pgb_prefix_parse1 = ('t_year', 't_month', 't_day', 't_hour', 't_min', 't_sec', 't_host', 't_ident', 't_pid', 't_session_id', 't_query');
                $pgbouncer_log_parse2 = qr/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:.[^\s]+)?\s[^\s]+\s(?:[^\s]+\s)?(?:[^\s]+\s)?[^\s\[]+\[\d+\]: .\-0x[0-9a-f\.]*: ([0-9a-zA-Z\_\[\]\-\.]*)\/([0-9a-zA-Z\_\[\]\-\.]*)\@([a-zA-Z0-9\-\.]+|\[local\]|\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}|[0-9a-fA-F:]+)?(?:\(\d+\))?[:\d]* (.*)/;
                @pgb_prefix_parse2 = ('t_dbname', 't_dbuser', 't_client', 't_query');
 
@@ -2553,7 +2549,7 @@ sub process_file
        # Check if the first date in the log are after the last date saved
        if (($logfile ne '-') && ($fmt ne 'binary') && ($fmt ne 'csv') && !$http_download) {
                if ($start_offset && !$chunk_pos) {
-                       my ($retcode, $msg) = check_file_changed($logfile, $file_size{$logfile}, $fmt, ($fmt eq 'pgbouncer') ? $pgb_saved_last_line{datetime} : $saved_last_line{datetime}, $start_offset, 1);
+                       my ($retcode, $msg) = check_file_changed($logfile, $file_size{$logfile}, $fmt, ($fmt =~ /pgbouncer/) ? $pgb_saved_last_line{datetime} : $saved_last_line{datetime}, $start_offset, 1);
                        if ($retcode) {
                                &logmsg('DEBUG', "This file should be parsed from the beginning: $logfile, $msg");
                                &logmsg('DEBUG', "Reverting start offset $start_offset to 0 for file $logfile, stoppping offset is " . ($stop_offset || $totalsize));
@@ -2587,7 +2583,7 @@ sub process_file
        }
 
        # Parse pgbouncer logfile
-       if ($fmt eq 'pgbouncer') {
+       if ($fmt =~ /pgbouncer/) {
 
                my $time_pattern = qr/(\d{4})-(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})/;
                my $cur_pid = '';
@@ -2654,6 +2650,11 @@ sub process_file
 "$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_loglevel'} = 'LOG';
+                               if ($prefix_vars{'t_session_id'} eq 'Stats') {
+                                       $prefix_vars{'t_loglevel'} = 'STATS';
+                                       $prefix_vars{'t_session_id'} = '';
+                                       $prefix_vars{'t_query'} = 'Stats: ' . $prefix_vars{'t_query'};
+                               }
 
                                # Skip unwanted lines
                                my $res = &skip_unwanted_line();
@@ -3207,8 +3208,8 @@ sub process_file
 
        %cur_info = ();
        # In incremental mode data are saved to disk per day
-       if ($incremental && ($last_line{datetime} || (($fmt eq 'pgbouncer') && $pgb_last_line{datetime}))) {
-               $incr_date = ($fmt eq 'pgbouncer') ? $pgb_last_line{datetime} : $last_line{datetime};
+       if ($incremental && ($last_line{datetime} || (($fmt =~ /pgbouncer/) && $pgb_last_line{datetime}))) {
+               $incr_date = ($fmt =~ /pgbouncer/) ? $pgb_last_line{datetime} : $last_line{datetime};
                $incr_date =~ s/\s.*$//;
                # set path and create subdirectories
                if ($incr_date =~ /^(\d+)-(\d+)-(\d+)/) {
@@ -3252,7 +3253,7 @@ sub process_file
        if ($last_parsed && (scalar keys %last_line || scalar keys %pgb_last_line)) {
                if (open(my $out, '>>', "$tmp_last_parsed")) {
                        flock($out, 2) || return $getout;
-                       if ($fmt eq 'pgbouncer') {
+                       if ($fmt =~ /pgbouncer/) {
                                $pgb_last_line{current_pos} ||= 0;
                                &logmsg('DEBUG', "Saving pgbouncer last parsed line into $tmp_last_parsed ($pgb_last_line{datetime}\t$pgb_last_line{current_pos})");
                                print $out "pgbouncer\t$pgb_last_line{datetime}\t$pgb_last_line{current_pos}\t$pgb_last_line{orig}\n";
@@ -3531,7 +3532,7 @@ sub check_file_changed
                                }
                        }
 
-               } elsif ($fmt eq 'pgbouncer') {
+               } elsif ($fmt =~ /pgbouncer/) {
 
                        my @matches = ($line =~ $pgbouncer_log_parse1);
                        if ($#matches >= 0) {
@@ -3572,7 +3573,7 @@ sub check_incremental_position
 {
        my ($fmt, $cur_date, $line) = @_;
 
-       if ($last_parsed && ($fmt ne 'pgbouncer')) {
+       if ($last_parsed && ($fmt !~ /pgbouncer/)) {
                if ($saved_last_line{datetime}) {
                        if ($cur_date lt $saved_last_line{datetime}) {
                                return 0;
@@ -13411,7 +13412,7 @@ sub parse_pgbouncer
        my $fmt = shift;
 
        my $t_pid = $prefix_vars{'t_pid'};
-       my $t_session_id = $prefix_vars{'t_session_id'} || $prefix_vars{'t_pid'};
+       my $t_session_id = $prefix_vars{'t_session_id'};
 
        my $date_part = "$prefix_vars{'t_year'}$prefix_vars{'t_month'}$prefix_vars{'t_day'}";
        my $cur_last_log_timestamp = "$prefix_vars{'t_year'}-$prefix_vars{'t_month'}-$prefix_vars{'t_day'} " .
@@ -13525,7 +13526,7 @@ sub parse_pgbouncer
                }
 
                # set current session workload
-               if ( !$disable_session ) {
+               if ( !$disable_session && $t_session_id) {
                        $pgb_current_sessions{$t_session_id} = $prefix_vars{'t_timestamp'};
                        my $sess_count = scalar keys %pgb_current_sessions;
                        $pgb_overall_stat{'peak'}{$cur_last_log_timestamp}{session} = $sess_count;
@@ -14260,7 +14261,7 @@ sub autodetect_format
        }
 
        # When --pgbouncer-only is used force the format
-       if (!$format && $pgbouncer_only) {
+       if (!$format && !$fmt && $pgbouncer_only) {
                $pgbouncer_only = 1;
                $fmt = 'pgbouncer';
        } elsif (!$format) {
@@ -14287,7 +14288,7 @@ sub search_log_format
 
        # Are pgbouncer syslog lines ?
        if ($line =~
-/^[A-Z][a-z]{2}\s+\d+ \d+:\d+:\d+(?:\s[^\s]+)?\s[^\s]+\s([^\s\[]+)\[\d+\]: (.\-0x[0-9a-f\.]*|Stats):/
+/^[A-Z][a-z]{2}\s+\d+ \d+:\d+:\d+(?: [^\s]+)? [^\s]+ [^\s\[]+\[\d+\]: (.\-0x[0-9a-f\.]+|Stats):/
           )
        {
                $fmt = 'pgbouncer1';
@@ -14343,7 +14344,7 @@ sub search_log_format
                $fmt = 'default';
 
        # Are pgbouncer lines ?
-       } elsif ($line =~ /^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\+\-\d]{3,6})? (\d+) (LOG|ERROR) (.\-0x[0-9a-f\.]*|Stats):/) {
+       } elsif ($line =~ /^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+(?: [A-Z\+\-\d]{3,6})? (\d+) (LOG|ERROR) (.\-0x[0-9a-f\.]+|Stats):/) {
                $fmt = 'pgbouncer';
                # If we just have one single pgbouncer file, force pgbouncer_only to 1
                $pgbouncer_only = 1 if ($#log_files == 0);