From: Gilles Darold Date: Thu, 18 Aug 2016 14:18:36 +0000 (+0200) Subject: Fix histogram over multiples days to be cumulative per hour, not an average of the... X-Git-Tag: v8.3~3 X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=7edeaf2821815011a5c2446aa17fa41d4697c3d2;p=pgbadger Fix histogram over multiples days to be cumulative per hour, not an average of the number of event per day. --- diff --git a/pgbadger b/pgbadger index b7a2733..20f4bf7 100755 --- a/pgbadger +++ b/pgbadger @@ -4435,6 +4435,38 @@ Log start from $overall_stat{'first_log_ts'} to $overall_stat{'last_log_ts'} } +# We change temporary log level from LOG to ERROR +# to store these messages into the error report +sub change_log_level +{ + my $msg = shift; + + return 1 if ($msg =~ /parameter "[^"]+" changed to "[^"]+"/); + return 1 if ($msg =~ /database system was/); + return 1 if ($msg =~ /recovery has paused/); + return 1 if ($msg =~ /ending cancel to blocking autovacuum/); + return 1 if ($msg =~ /skipping analyze of/); + return 1 if ($msg =~ /using stale statistics/); + return 1 if ($msg =~ /replication command:/); + + return 0; +} + +sub revert_log_level +{ + my $msg = shift; + + return ($msg, 1) if ($msg =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (database system was)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (recovery has paused)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (skipping analyze of)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (using stale statistics)/LOG: $1/); + return ($msg, 1) if ($msg =~ s/ERROR: (received replication command:)/LOG: $1/); + + return ($msg, 0); +} + sub show_error_as_text { return if (scalar keys %error_info == 0); @@ -4446,13 +4478,7 @@ sub show_error_as_text last if ($idx > $top); last if (!$error_info{$k}{count}); - my $msg = $k; - $msg =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/; - $msg =~ s/ERROR: (database system was)/LOG: $1/; - $msg =~ s/ERROR: (recovery has paused)/LOG: $1/; - $msg =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/; - $msg =~ s/ERROR: (skipping analyze of)/LOG: $1/; - $msg =~ s/ERROR: (using stale statistics)/LOG: $1/; + my ($msg, $ret) = &revert_log_level($k); if ($error_info{$k}{count} > 1) { print $fh "$idx) " . &comma_numbers($error_info{$k}{count}) . " - $msg\n"; @@ -4460,14 +4486,8 @@ sub show_error_as_text my $j = 1; for (my $i = 0 ; $i <= $#{$error_info{$k}{date}} ; $i++) { last if ($i == $sample); - if ( ($error_info{$k}{error}[$i] =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (database system was)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (recovery has paused)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (skipping analyze of)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (using stale statistics)/LOG: $1/) - ) - { + ($error_info{$k}{error}[$i], $ret) = &revert_log_level($error_info{$k}{error}[$i]); + if ($msg) { $logs_type{ERROR}--; $logs_type{LOG}++; } @@ -4480,14 +4500,8 @@ sub show_error_as_text $j++; } } elsif ($error_info{$k}{error}[0]) { - if ( ($error_info{$k}{error}[0] =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (database system was)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (recovery has paused)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (skipping analyze of)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (using stale statistics)/LOG: $1/) - ) - { + ($error_info{$k}{error}[0], $ret) = &revert_log_level($error_info{$k}{error}[0]); + if ($msg) { $logs_type{ERROR}--; $logs_type{LOG}++; } @@ -9551,7 +9565,7 @@ sub print_time_consuming my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; $graph_data{duration} .= "['$h:$rd'," . (int($hourly_duration{"$h:$rd"} / ($hourly_count{"$h:$rd"} || 1)) || 0) . "],"; } } @@ -9569,7 +9583,7 @@ sub print_time_consuming $apps_involved = qq{}; } my $query_histo = - &jqplot_histograph($graphid++, 'timeconsuming_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Avg. queries', 'Avg. duration'); + &jqplot_histograph($graphid++, 'timeconsuming_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Queries', 'Avg. duration'); print $fh qq{ @@ -9783,7 +9797,7 @@ sub print_most_frequent my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; $graph_data{duration} .= "['$h:$rd'," . (int($hourly_duration{"$h:$rd"} / ($hourly_count{"$h:$rd"} || 1)) || 0) . "],"; } } @@ -9793,7 +9807,7 @@ sub print_most_frequent %hourly_duration = (); my $query_histo = - &jqplot_histograph($graphid++, 'mostfrequent_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Avg. queries', 'Avg. duration'); + &jqplot_histograph($graphid++, 'mostfrequent_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Queries', 'Avg. duration'); my $users_involved = ''; if (scalar keys %{$normalyzed_info{$k}{users}} > 0) { @@ -10020,7 +10034,7 @@ sub print_slowest_queries my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; $graph_data{duration} .= "['$h:$rd'," . (int($hourly_duration{"$h:$rd"} / ($hourly_count{"$h:$rd"} || 1)) || 0) . "],"; } } @@ -10030,7 +10044,7 @@ sub print_slowest_queries %hourly_duration = (); my $query_histo = - &jqplot_histograph($graphid++, 'normalizedslowest_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Avg. queries', 'Avg. duration'); + &jqplot_histograph($graphid++, 'normalizedslowest_graph_'.$rank, $graph_data{count}, $graph_data{duration}, 'Queries', 'Avg. duration'); my $users_involved = ''; if (scalar keys %{$normalyzed_info{$k}{users}} > 0) { @@ -10459,6 +10473,7 @@ sub escape_html sub print_log_level { my %infos = (); + my $ret = 0; # Some messages have seen their log level change during log parsing. # Set the real log level count back @@ -10466,27 +10481,15 @@ sub print_log_level next if (!$error_info{$k}{count}); if ($error_info{$k}{count} > 1) { for (my $i = 0 ; $i <= $#{$error_info{$k}{date}} ; $i++) { - if ( ($error_info{$k}{error}[$i] =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (database system was)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (recovery has paused)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (skipping analyze of)/LOG: $1/) - || ($error_info{$k}{error}[$i] =~ s/ERROR: (using stale statistics)/LOG: $1/) - ) - { + ($error_info{$k}{error}[$i], $ret) = &revert_log_level($error_info{$k}{error}[$i]); + if ($ret) { $logs_type{ERROR}--; $logs_type{LOG}++; } } } else { - if ( ($error_info{$k}{error}[0] =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (database system was)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (recovery has paused)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (skipping analyze of)/LOG: $1/) - || ($error_info{$k}{error}[0] =~ s/ERROR: (using stale statistics)/LOG: $1/) - ) - { + ($error_info{$k}{error}[0], $ret) = &revert_log_level($error_info{$k}{error}[0]); + if ($ret) { $logs_type{ERROR}--; $logs_type{LOG}++; } @@ -10687,13 +10690,7 @@ sub show_error_as_html foreach my $k (sort {$error_info{$b}{count} <=> $error_info{$a}{count}} keys %error_info) { next if (!$error_info{$k}{count}); my $count = &comma_numbers($error_info{$k}{count}); - my $msg = $k; - $msg =~ s/ERROR: (parameter "[^"]+" changed to)/LOG: $1/; - $msg =~ s/ERROR: (database system was)/LOG: $1/; - $msg =~ s/ERROR: (recovery has paused)/LOG: $1/; - $msg =~ s/ERROR: (sending cancel to blocking autovacuum)/LOG: $1/; - $msg =~ s/ERROR: (skipping analyze of)/LOG: $1/; - $msg =~ s/ERROR: (using stale statistics)/LOG: $1/; + my ($msg, $ret) = &revert_log_level($k); my $error_level_class = 'text-error'; if ($msg =~ /^WARNING: /) { $error_level_class = 'text-warning'; @@ -10735,14 +10732,14 @@ sub show_error_as_html my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; } } $graph_data{count} =~ s/,$//; %hourly_count = (); my $error_histo = - &jqplot_histograph($graphid++, 'error_graph_'.$rank, $graph_data{count}, '', 'Avg. events', ''); + &jqplot_histograph($graphid++, 'error_graph_'.$rank, $graph_data{count}, '', 'Events', ''); # Escape HTML code in error message $msg = &escape_html($msg); @@ -10909,14 +10906,14 @@ sub show_pgb_error_as_html my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; } } $graph_data{count} =~ s/,$//; %hourly_count = (); my $error_histo = - &jqplot_histograph($graphid++, 'pgberror_graph_'.$rank, $graph_data{count}, '', 'Avg. events', ''); + &jqplot_histograph($graphid++, 'pgberror_graph_'.$rank, $graph_data{count}, '', 'Events', ''); # Escape HTML code in error message $msg = &escape_html($msg); @@ -11064,7 +11061,7 @@ sub show_pgb_reserved_pool my %graph_data = (); foreach my $h ("00" .. "23") { foreach my $rd (@histo_avgs) { - $graph_data{count} .= "['$h:$rd'," . (int($hourly_count{"$h:$rd"}/$days) || 0) . "],"; + $graph_data{count} .= "['$h:$rd'," . ($hourly_count{"$h:$rd"} || 0) . "],"; } } $graph_data{count} =~ s/,$//; @@ -12102,19 +12099,8 @@ sub parse_query # Force some LOG messages to be ERROR messages so that they will appear # in the event/error/warning messages report. if ($prefix_vars{'t_loglevel'} eq 'LOG') { - if ($prefix_vars{'t_query'} =~ /parameter "[^"]+" changed to "[^"]+"/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } elsif ($prefix_vars{'t_query'} =~ /database system was/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } elsif ($prefix_vars{'t_query'} =~ /recovery has paused/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } elsif ($prefix_vars{'t_query'} =~ /ending cancel to blocking autovacuum/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } elsif ($prefix_vars{'t_query'} =~ /skipping analyze of/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } elsif ($prefix_vars{'t_query'} =~ /using stale statistics/) { - $prefix_vars{'t_loglevel'} = 'ERROR'; - } + + $prefix_vars{'t_loglevel'} = 'ERROR' if (&change_log_level($prefix_vars{'t_query'})); } elsif (($prefix_vars{'t_loglevel'} eq 'ERROR') && !$error_only) { @@ -13682,7 +13668,7 @@ sub jqplot_histograph
NO DATASET
}; } - $legend1 ||= 'Avg. queries'; + $legend1 ||= 'Queries'; my $y2decl = ''; my $y2vals = ''; if ($data2) {