From d965b1ba846c4074b4bfc7b063870d1b44976773 Mon Sep 17 00:00:00 2001 From: Samuel Ng Date: Fri, 21 Apr 2023 14:40:05 -0400 Subject: Added logic for scrubbing args from stack traces by default which can be overridden by setting the show_args flag --- lib/Log/Any/Proxy/WithStackTrace.pm | 32 +++++++++++++++++++++++++++++++- 1 file changed, 31 insertions(+), 1 deletion(-) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index 6e8390a..5d3ebbe 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -11,6 +11,7 @@ use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; use Devel::StackTrace 2.00; +use Devel::StackTrace::Extract qw(extract_stack_trace); use Log::Any::Adapter::Util (); use overload; @@ -66,6 +67,7 @@ trace. stack_trace => Devel::StackTrace->new( # Filter e.g "Log::Any::Proxy", "My::Log::Any::Proxy", etc. ignore_package => [ qr/(?:^|::)Log::Any(?:::|$)/ ], + (!$self->{show_args} ? no_args => 1 : ()) ), }, $class; } @@ -82,7 +84,7 @@ trace. This is an internal use method that will convert a non-reference scalar message into a C object with a C method. A string overload is provided to return the -original message. +original message. Args are scrubbed out in case they contain sensitive data. =cut @@ -93,6 +95,15 @@ sub maybe_upgrade_with_stack_trace # Only want a non-ref arg, optionally followed by a structured data # context hashref: # + + unless ($self->{show_args}) { + for my $i (0 .. $#args) { # Check if there's a stack trace to scrub args from + my $trace = extract_stack_trace($args[$i]); + $self->delete_args_from_stack_trace($trace); + $args[$i] = $trace; + } + } + return @args unless @args == 1 || ( @args == 2 && ref $args[1] eq 'HASH' ); return @args if ref $args[0]; @@ -118,5 +129,24 @@ foreach my $name ( Log::Any::Adapter::Util::logging_methods(), keys(%aliases) ) }; } +=head2 delete_args_from_stack_trace($trace) + + $self->delete_args_from_stack_trace($trace) + +To scrub potentially sensitive data from C arguments, this method deletes +arguments from all of the C in the trace. + +=cut + +sub delete_args_from_stack_trace { + assert_argc(2); + my ($self, $trace) = @_; + assert_object_isa($trace, 'Devel::StackTrace'); + + foreach my $frame ($trace->frames) { + delete $frame->{args}; + } +} + 1; -- cgit v1.2.3 From d958196f06cf6b1d46b91d8e77b8b4b0688a6032 Mon Sep 17 00:00:00 2001 From: Samuel Ng Date: Fri, 21 Apr 2023 17:05:49 -0400 Subject: Wrote unit tests for testing show_args and default argument scrubbing --- lib/Log/Any/Proxy/WithStackTrace.pm | 25 +++++++++------- t/proxy-with-stack-trace.t | 58 ++++++++++++++++++++++++++++--------- 2 files changed, 59 insertions(+), 24 deletions(-) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index 5d3ebbe..c84340c 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -60,14 +60,14 @@ trace. sub new { - my ($class, $message) = @_; + my ($class, $show_args, $message) = @_; croak 'no "message"' unless defined $message; return bless { message => $message, stack_trace => Devel::StackTrace->new( # Filter e.g "Log::Any::Proxy", "My::Log::Any::Proxy", etc. ignore_package => [ qr/(?:^|::)Log::Any(?:::|$)/ ], - (!$self->{show_args} ? no_args => 1 : ()) + no_args => !$show_args, ), }, $class; } @@ -95,12 +95,13 @@ sub maybe_upgrade_with_stack_trace # Only want a non-ref arg, optionally followed by a structured data # context hashref: # - - unless ($self->{show_args}) { + unless (!!$self->{show_args}) { for my $i (0 .. $#args) { # Check if there's a stack trace to scrub args from my $trace = extract_stack_trace($args[$i]); - $self->delete_args_from_stack_trace($trace); - $args[$i] = $trace; + if ($trace) { + $self->delete_args_from_stack_trace($trace); + $args[$i] = $trace; + } } } @@ -108,7 +109,8 @@ sub maybe_upgrade_with_stack_trace ( @args == 2 && ref $args[1] eq 'HASH' ); return @args if ref $args[0]; - $args[0] = Log::Any::MessageWithStackTrace->new($args[0]); + + $args[0] = Log::Any::MessageWithStackTrace->new(!!$self->{show_args}, $args[0]); return @args; } @@ -138,13 +140,14 @@ arguments from all of the C in the trace. =cut -sub delete_args_from_stack_trace { - assert_argc(2); +sub delete_args_from_stack_trace +{ my ($self, $trace) = @_; - assert_object_isa($trace, 'Devel::StackTrace'); + + return unless $trace; foreach my $frame ($trace->frames) { - delete $frame->{args}; + $frame->{args} = []; } } diff --git a/t/proxy-with-stack-trace.t b/t/proxy-with-stack-trace.t index 3f69917..8d25757 100644 --- a/t/proxy-with-stack-trace.t +++ b/t/proxy-with-stack-trace.t @@ -2,9 +2,10 @@ use strict; use warnings; use Test::More; +use List::Util qw( any ); use Log::Any; -plan tests => 48; +plan tests => 61; use FindBin; use lib $FindBin::RealBin; @@ -31,33 +32,43 @@ BEGIN { use Log::Any::Proxy::WithStackTrace; # necessary? -my $default_log = Log::Any->get_logger; -my $log = Log::Any->get_logger( proxy_class => 'WithStackTrace' ); +my $default_log = Log::Any->get_logger; +my $log = Log::Any->get_logger( proxy_class => 'WithStackTrace' ); +my $log_show_args = Log::Any->get_logger( proxy_class => 'WithStackTrace', show_args => 1); -is ref $default_log, 'Log::Any::Proxy::Null', +is ref $default_log, 'Log::Any::Proxy::Null', 'no adapter default proxy is Null'; -is ref $log, 'Log::Any::Proxy::WithStackTrace', +is ref $log, 'Log::Any::Proxy::WithStackTrace', 'no adapter explicit proxy is WithStackTrace'; +is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', + 'no adapter explicit proxy with show_args flag is WithStackTrace'; -$default_log->info("test"); -$log ->info("test"); +$default_log ->info("test"); +$log ->info("test"); +$log_show_args->info("test"); -is ref $default_log, 'Log::Any::Proxy::Null', +is ref $default_log, 'Log::Any::Proxy::Null', 'no adapter default proxy is still Null after logging'; -is ref $log, 'Log::Any::Proxy::WithStackTrace', +is ref $log, 'Log::Any::Proxy::WithStackTrace', 'no adapter explicit proxy is still WithStackTrace after logging'; +is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', + 'no adapter explicit proxy with show_args flag is still WithStackTrace after logging'; Log::Any->set_adapter('+TestAdapters::Structured'); -is ref $default_log, 'Log::Any::Proxy', +is ref $default_log, 'Log::Any::Proxy', 'existing default proxy is reblessed after adapter'; -is ref $log, 'Log::Any::Proxy::WithStackTrace', +is ref $log, 'Log::Any::Proxy::WithStackTrace', 'existing explicit proxy is still WithStackTrace after adapter'; +is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', + 'existing explicit proxy with show_args flag is still WithStackTrace after adapter'; -is ref $default_log->adapter, 'TestAdapters::Structured', +is ref $default_log->adapter, 'TestAdapters::Structured', 'existing default proxy has correct adapter'; -is ref $log->adapter, 'TestAdapters::Structured', +is ref $log->adapter, 'TestAdapters::Structured', 'existing explicit proxy has correct adapter'; +is ref $log_show_args->adapter, 'TestAdapters::Structured', + 'existing explicit proxy with show_args flag has correct adapter'; my @test_cases = ( [ @@ -132,6 +143,27 @@ sub check_test_cases { is_deeply $more_data, $args->[1], "expected structured data from $type logger"; } + foreach my $frame ($trace->frames) { + is scalar @{ $frame->{args} }, 0, + "stack_trace frame does not have args by default"; + } + + @TestAdapters::STRUCTURED_LOG = (); + $log_show_args->$method(@$args); + $msgs = \@TestAdapters::STRUCTURED_LOG; + $msg = $msgs->[0]->{data}->[0]; # "data" for non-text + + $trace = $msg->stack_trace; + + ok( + any ( + sub { + ($_->args >= 1); + }, + $trace->frames + ), + "stack_trace frame has args if show_args => 1 is passed to logger", + ); } } -- cgit v1.2.3 From 9d15a7610d143b0650b651391f401ea442393457 Mon Sep 17 00:00:00 2001 From: Samuel Ng Date: Mon, 24 Apr 2023 09:16:10 -0400 Subject: Updated POD --- lib/Log/Any/Proxy/WithStackTrace.pm | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index c84340c..b8abfa7 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -41,7 +41,8 @@ that is a non-reference scalar, that message will be upgraded into a C object with a C method, and that method will return a trace relative to where the logging method was called. A string overload is provided on the object to return the -original message. +original message. Unless a C flag is specified, arguments +in the stack trace will be scrubbed. B This proxy should be used with a L that is configured to handle structured data. Otherwise the object created -- cgit v1.2.3 From e0079361803a6675ed9a74bd24a8e8eefadd5c5a Mon Sep 17 00:00:00 2001 From: Samuel Ng Date: Tue, 2 May 2023 11:34:30 -0400 Subject: Removed unnecessary exclamation marks. Renamed show_args to proxy_show_stack_trace_args --- lib/Log/Any/Proxy/WithStackTrace.pm | 14 +++++++------- t/proxy-with-stack-trace.t | 12 ++++++------ 2 files changed, 13 insertions(+), 13 deletions(-) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index b8abfa7..6f86c6c 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -41,7 +41,7 @@ that is a non-reference scalar, that message will be upgraded into a C object with a C method, and that method will return a trace relative to where the logging method was called. A string overload is provided on the object to return the -original message. Unless a C flag is specified, arguments +original message. Unless a C flag is specified, arguments in the stack trace will be scrubbed. B This proxy should be used with a L that @@ -61,14 +61,14 @@ trace. sub new { - my ($class, $show_args, $message) = @_; + my ($class, $proxy_show_stack_trace_args, $message) = @_; croak 'no "message"' unless defined $message; return bless { message => $message, stack_trace => Devel::StackTrace->new( # Filter e.g "Log::Any::Proxy", "My::Log::Any::Proxy", etc. ignore_package => [ qr/(?:^|::)Log::Any(?:::|$)/ ], - no_args => !$show_args, + no_args => !$proxy_show_stack_trace_args, ), }, $class; } @@ -85,7 +85,8 @@ trace. This is an internal use method that will convert a non-reference scalar message into a C object with a C method. A string overload is provided to return the -original message. Args are scrubbed out in case they contain sensitive data. +original message. Args are scrubbed out in case they contain sensitive data, +unless the C option has been set. =cut @@ -96,7 +97,7 @@ sub maybe_upgrade_with_stack_trace # Only want a non-ref arg, optionally followed by a structured data # context hashref: # - unless (!!$self->{show_args}) { + unless ($self->{proxy_show_stack_trace_args}) { for my $i (0 .. $#args) { # Check if there's a stack trace to scrub args from my $trace = extract_stack_trace($args[$i]); if ($trace) { @@ -110,8 +111,7 @@ sub maybe_upgrade_with_stack_trace ( @args == 2 && ref $args[1] eq 'HASH' ); return @args if ref $args[0]; - - $args[0] = Log::Any::MessageWithStackTrace->new(!!$self->{show_args}, $args[0]); + $args[0] = Log::Any::MessageWithStackTrace->new($self->{proxy_show_stack_trace_args}, $args[0]); return @args; } diff --git a/t/proxy-with-stack-trace.t b/t/proxy-with-stack-trace.t index 8d25757..f8cfcf4 100644 --- a/t/proxy-with-stack-trace.t +++ b/t/proxy-with-stack-trace.t @@ -34,14 +34,14 @@ use Log::Any::Proxy::WithStackTrace; # necessary? my $default_log = Log::Any->get_logger; my $log = Log::Any->get_logger( proxy_class => 'WithStackTrace' ); -my $log_show_args = Log::Any->get_logger( proxy_class => 'WithStackTrace', show_args => 1); +my $log_show_args = Log::Any->get_logger( proxy_class => 'WithStackTrace', proxy_show_stack_trace_args => 1); is ref $default_log, 'Log::Any::Proxy::Null', 'no adapter default proxy is Null'; is ref $log, 'Log::Any::Proxy::WithStackTrace', 'no adapter explicit proxy is WithStackTrace'; is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', - 'no adapter explicit proxy with show_args flag is WithStackTrace'; + 'no adapter explicit proxy with proxy_show_stack_trace_args flag is WithStackTrace'; $default_log ->info("test"); $log ->info("test"); @@ -52,7 +52,7 @@ is ref $default_log, 'Log::Any::Proxy::Null', is ref $log, 'Log::Any::Proxy::WithStackTrace', 'no adapter explicit proxy is still WithStackTrace after logging'; is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', - 'no adapter explicit proxy with show_args flag is still WithStackTrace after logging'; + 'no adapter explicit proxy with proxy_show_stack_trace_args flag is still WithStackTrace after logging'; Log::Any->set_adapter('+TestAdapters::Structured'); @@ -61,14 +61,14 @@ is ref $default_log, 'Log::Any::Proxy', is ref $log, 'Log::Any::Proxy::WithStackTrace', 'existing explicit proxy is still WithStackTrace after adapter'; is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', - 'existing explicit proxy with show_args flag is still WithStackTrace after adapter'; + 'existing explicit proxy with proxy_show_stack_trace_args flag is still WithStackTrace after adapter'; is ref $default_log->adapter, 'TestAdapters::Structured', 'existing default proxy has correct adapter'; is ref $log->adapter, 'TestAdapters::Structured', 'existing explicit proxy has correct adapter'; is ref $log_show_args->adapter, 'TestAdapters::Structured', - 'existing explicit proxy with show_args flag has correct adapter'; + 'existing explicit proxy with proxy_show_stack_trace_args flag has correct adapter'; my @test_cases = ( [ @@ -162,7 +162,7 @@ sub check_test_cases { }, $trace->frames ), - "stack_trace frame has args if show_args => 1 is passed to logger", + "stack_trace frame has args if proxy_show_stack_trace_args => 1 is passed to logger", ); } } -- cgit v1.2.3 From f2c27cbfed53e076eef60a38f9f3954c49438769 Mon Sep 17 00:00:00 2001 From: Samuel Ng Date: Tue, 2 May 2023 11:37:13 -0400 Subject: Added example with proxy_show_stack_trace_args flag to POD --- lib/Log/Any/Proxy/WithStackTrace.pm | 3 +++ 1 file changed, 3 insertions(+) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index 6f86c6c..c8e13ce 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -19,6 +19,9 @@ use overload; use Log::Any qw( $log, proxy_class => 'WithStackTrace' ); + # Turns on argument logging in stack traces + use Log::Any qw( $log, proxy_class => 'WithStackTrace', proxy_show_stack_trace_args => 1 ); + # Some adapter that knows how to handle both structured data, # and log messages which are actually objects with a # "stack_trace" method: -- cgit v1.2.3 From e7493757b1fcd442ce6bf8a807203123a59c59b8 Mon Sep 17 00:00:00 2001 From: Doug Bell Date: Thu, 4 May 2023 13:09:38 -0500 Subject: incrementing version after release --- Changes | 2 ++ Makefile.PL | 2 +- lib/Log/Any.pm | 2 +- lib/Log/Any/Adapter.pm | 2 +- lib/Log/Any/Adapter/Base.pm | 2 +- lib/Log/Any/Adapter/Capture.pm | 2 +- lib/Log/Any/Adapter/File.pm | 2 +- lib/Log/Any/Adapter/Multiplex.pm | 2 +- lib/Log/Any/Adapter/Null.pm | 2 +- lib/Log/Any/Adapter/Stderr.pm | 2 +- lib/Log/Any/Adapter/Stdout.pm | 2 +- lib/Log/Any/Adapter/Syslog.pm | 2 +- lib/Log/Any/Adapter/Test.pm | 2 +- lib/Log/Any/Adapter/Util.pm | 2 +- lib/Log/Any/Manager.pm | 2 +- lib/Log/Any/Proxy.pm | 2 +- lib/Log/Any/Proxy/Null.pm | 2 +- lib/Log/Any/Proxy/Test.pm | 2 +- lib/Log/Any/Proxy/WithStackTrace.pm | 2 +- lib/Log/Any/Test.pm | 2 +- 20 files changed, 21 insertions(+), 19 deletions(-) diff --git a/Changes b/Changes index 8081a7a..bc32e59 100644 --- a/Changes +++ b/Changes @@ -4,6 +4,8 @@ Revision history for Log-Any {{ $NEXT }} +1.715 2023-05-04 13:09:22-05:00 America/Chicago + [Fixed] - Fixed Multiplex adapter losing context details. Normally, the diff --git a/Makefile.PL b/Makefile.PL index 21a7486..aac7b3f 100644 --- a/Makefile.PL +++ b/Makefile.PL @@ -23,7 +23,7 @@ my %WriteMakefileArgs = ( "IPC::Open3" => 0, "Test::More" => 0 }, - "VERSION" => "1.715", + "VERSION" => "1.716", "test" => { "TESTS" => "t/*.t" } diff --git a/lib/Log/Any.pm b/lib/Log/Any.pm index 1f275f9..0ee5d8c 100644 --- a/lib/Log/Any.pm +++ b/lib/Log/Any.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any; # ABSTRACT: Bringing loggers and listeners together -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Manager; use Log::Any::Proxy::Null; diff --git a/lib/Log/Any/Adapter.pm b/lib/Log/Any/Adapter.pm index ad1076c..73eca45 100644 --- a/lib/Log/Any/Adapter.pm +++ b/lib/Log/Any/Adapter.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter; # ABSTRACT: Tell Log::Any where to send its logs -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any; our @CARP_NOT = ( 'Log::Any::Manager' ); diff --git a/lib/Log/Any/Adapter/Base.pm b/lib/Log/Any/Adapter/Base.pm index a715dc9..1b37222 100644 --- a/lib/Log/Any/Adapter/Base.pm +++ b/lib/Log/Any/Adapter/Base.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Adapter::Base; -our $VERSION = '1.715'; +our $VERSION = '1.716'; our @CARP_NOT = ( 'Log::Any::Adapter' ); # we import these in case any legacy adapter uses them as class methods diff --git a/lib/Log/Any/Adapter/Capture.pm b/lib/Log/Any/Adapter/Capture.pm index d91a145..d539fcd 100644 --- a/lib/Log/Any/Adapter/Capture.pm +++ b/lib/Log/Any/Adapter/Capture.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Capture; # ABSTRACT: Adapter for capturing log messages into an arrayref -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/File.pm b/lib/Log/Any/Adapter/File.pm index feea347..ccb475a 100644 --- a/lib/Log/Any/Adapter/File.pm +++ b/lib/Log/Any/Adapter/File.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::File; # ABSTRACT: Simple adapter for logging to files -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Config; use Fcntl qw/:flock/; diff --git a/lib/Log/Any/Adapter/Multiplex.pm b/lib/Log/Any/Adapter/Multiplex.pm index 94327e3..79b10de 100644 --- a/lib/Log/Any/Adapter/Multiplex.pm +++ b/lib/Log/Any/Adapter/Multiplex.pm @@ -1,6 +1,6 @@ package Log::Any::Adapter::Multiplex; # ABSTRACT: Adapter to use allow structured logging across other adapters -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any; use Log::Any::Adapter; diff --git a/lib/Log/Any/Adapter/Null.pm b/lib/Log/Any/Adapter/Null.pm index af0b936..3eb992b 100644 --- a/lib/Log/Any/Adapter/Null.pm +++ b/lib/Log/Any/Adapter/Null.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Null; # ABSTRACT: Discards all log messages -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Base; our @ISA = qw/Log::Any::Adapter::Base/; diff --git a/lib/Log/Any/Adapter/Stderr.pm b/lib/Log/Any/Adapter/Stderr.pm index 301de37..aa670cb 100644 --- a/lib/Log/Any/Adapter/Stderr.pm +++ b/lib/Log/Any/Adapter/Stderr.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Stderr; # ABSTRACT: Simple adapter for logging to STDERR -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/Stdout.pm b/lib/Log/Any/Adapter/Stdout.pm index 7f16f0a..969dd9a 100644 --- a/lib/Log/Any/Adapter/Stdout.pm +++ b/lib/Log/Any/Adapter/Stdout.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Stdout; # ABSTRACT: Simple adapter for logging to STDOUT -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/Syslog.pm b/lib/Log/Any/Adapter/Syslog.pm index b4b31e8..0a8107e 100644 --- a/lib/Log/Any/Adapter/Syslog.pm +++ b/lib/Log/Any/Adapter/Syslog.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Syslog; # ABSTRACT: Send Log::Any logs to syslog -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util qw{make_method}; use base qw{Log::Any::Adapter::Base}; diff --git a/lib/Log/Any/Adapter/Test.pm b/lib/Log/Any/Adapter/Test.pm index d8c1c86..44aabb3 100644 --- a/lib/Log/Any/Adapter/Test.pm +++ b/lib/Log/Any/Adapter/Test.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Adapter::Test; -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util qw/dump_one_line/; use Test::Builder; diff --git a/lib/Log/Any/Adapter/Util.pm b/lib/Log/Any/Adapter/Util.pm index ecb5ee1..35a89d3 100644 --- a/lib/Log/Any/Adapter/Util.pm +++ b/lib/Log/Any/Adapter/Util.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Util; # ABSTRACT: Common utility functions for Log::Any -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Exporter; our @ISA = qw/Exporter/; diff --git a/lib/Log/Any/Manager.pm b/lib/Log/Any/Manager.pm index 8e4272c..4c80ab8 100644 --- a/lib/Log/Any/Manager.pm +++ b/lib/Log/Any/Manager.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Manager; -our $VERSION = '1.715'; +our $VERSION = '1.716'; sub new { my $class = shift; diff --git a/lib/Log/Any/Proxy.pm b/lib/Log/Any/Proxy.pm index 45b2b2b..2958377 100644 --- a/lib/Log/Any/Proxy.pm +++ b/lib/Log/Any/Proxy.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy; # ABSTRACT: Log::Any generator proxy object -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util (); use overload; diff --git a/lib/Log/Any/Proxy/Null.pm b/lib/Log/Any/Proxy/Null.pm index 73a5485..049256c 100644 --- a/lib/Log/Any/Proxy/Null.pm +++ b/lib/Log/Any/Proxy/Null.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy::Null; # ABSTRACT: Log::Any generator proxy for no adapters -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Adapter::Util (); use Log::Any::Proxy; diff --git a/lib/Log/Any/Proxy/Test.pm b/lib/Log/Any/Proxy/Test.pm index 4031fd0..708c5f6 100644 --- a/lib/Log/Any/Proxy/Test.pm +++ b/lib/Log/Any/Proxy/Test.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Proxy::Test; -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index 6e8390a..a1a35f5 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy::WithStackTrace; # ABSTRACT: Log::Any proxy to upgrade string errors to objects with stack traces -our $VERSION = '1.715'; +our $VERSION = '1.716'; use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; diff --git a/lib/Log/Any/Test.pm b/lib/Log/Any/Test.pm index 97f44d0..ebe2a24 100644 --- a/lib/Log/Any/Test.pm +++ b/lib/Log/Any/Test.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Test; # ABSTRACT: Test what you're logging with Log::Any -our $VERSION = '1.715'; +our $VERSION = '1.716'; no warnings 'once'; $Log::Any::OverrideDefaultAdapterClass = 'Log::Any::Adapter::Test'; -- cgit v1.2.3 From 231050862f157efac294f89f1a98dc60662ca525 Mon Sep 17 00:00:00 2001 From: Doug Bell Date: Mon, 26 Jun 2023 14:12:31 -0500 Subject: fix stacktrace proxy test to bypass optional module --- t/proxy-with-stack-trace.t | 20 ++++++++++++-------- 1 file changed, 12 insertions(+), 8 deletions(-) diff --git a/t/proxy-with-stack-trace.t b/t/proxy-with-stack-trace.t index f8cfcf4..2f06d8e 100644 --- a/t/proxy-with-stack-trace.t +++ b/t/proxy-with-stack-trace.t @@ -19,14 +19,18 @@ BEGIN { if ( $@ ) { plan skip_all => 'Devel::StackTrace >= 2.00 is required for this test'; } - else { - eval { - require Storable; - Storable->VERSION( 3.08 ); - }; - if ( $@ ) { - plan skip_all => 'Storable >= 3.08 is required for this test'; - } + eval { + require Storable; + Storable->VERSION( 3.08 ); + }; + if ( $@ ) { + plan skip_all => 'Storable >= 3.08 is required for this test'; + } + eval { + require Devel::StackTrace::Extract; + }; + if ( $@ ) { + plan skip_all => 'Devel::StackTrace::Extract is required for this test'; } } -- cgit v1.2.3 From 6730073948a82ef063c570e36a6a9cb4f6a07102 Mon Sep 17 00:00:00 2001 From: Doug Bell Date: Mon, 26 Jun 2023 14:15:03 -0500 Subject: release v1.716 [Added] - Added a parameter to show stack trace arguments when using the WithStackTrace proxy. Since these arguments may contain sensitive information, they are now removed by default. Thanks @sam-ng and @GrantStreetGroup for submitting this patch! [Github #97] --- Changes | 7 +++++++ README.mkdn | 5 ++++- 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/Changes b/Changes index bc32e59..4d2eb1c 100644 --- a/Changes +++ b/Changes @@ -4,6 +4,13 @@ Revision history for Log-Any {{ $NEXT }} + [Added] + + - Added a parameter to show stack trace arguments when using the + WithStackTrace proxy. Since these arguments may contain sensitive + information, they are now removed by default. Thanks @sam-ng and + @GrantStreetGroup for submitting this patch! [Github #97] + 1.715 2023-05-04 13:09:22-05:00 America/Chicago [Fixed] diff --git a/README.mkdn b/README.mkdn index 863575b..b7b9232 100644 --- a/README.mkdn +++ b/README.mkdn @@ -4,7 +4,7 @@ Log::Any - Bringing loggers and listeners together # VERSION -version 1.715 +version 1.716 # SYNOPSIS @@ -317,6 +317,7 @@ To detect if a consumer exists, use `Log::Any->has_consumer`. # CONTRIBUTORS - Andrew Grechkin +- Andrew Hewus Fresh <andrew+github@afresh1.com> - bj5004 - cm-perl - Doug Bell @@ -334,6 +335,8 @@ To detect if a consumer exists, use `Log::Any->has_consumer`. - Paul Durden - Philipp Gortan - Phill Legault +- Samuel Ng +- Samuel Ng - Shlomi Fish - Sven Willenbuecher - XSven -- cgit v1.2.3 From b81d79a3d4d7016b57cd1791c524ec24b1f3336e Mon Sep 17 00:00:00 2001 From: Doug Bell Date: Mon, 26 Jun 2023 14:15:03 -0500 Subject: incrementing version after release --- Changes | 2 ++ Makefile.PL | 2 +- lib/Log/Any.pm | 2 +- lib/Log/Any/Adapter.pm | 2 +- lib/Log/Any/Adapter/Base.pm | 2 +- lib/Log/Any/Adapter/Capture.pm | 2 +- lib/Log/Any/Adapter/File.pm | 2 +- lib/Log/Any/Adapter/Multiplex.pm | 2 +- lib/Log/Any/Adapter/Null.pm | 2 +- lib/Log/Any/Adapter/Stderr.pm | 2 +- lib/Log/Any/Adapter/Stdout.pm | 2 +- lib/Log/Any/Adapter/Syslog.pm | 2 +- lib/Log/Any/Adapter/Test.pm | 2 +- lib/Log/Any/Adapter/Util.pm | 2 +- lib/Log/Any/Manager.pm | 2 +- lib/Log/Any/Proxy.pm | 2 +- lib/Log/Any/Proxy/Null.pm | 2 +- lib/Log/Any/Proxy/Test.pm | 2 +- lib/Log/Any/Proxy/WithStackTrace.pm | 2 +- lib/Log/Any/Test.pm | 2 +- 20 files changed, 21 insertions(+), 19 deletions(-) diff --git a/Changes b/Changes index 4d2eb1c..cf863b9 100644 --- a/Changes +++ b/Changes @@ -4,6 +4,8 @@ Revision history for Log-Any {{ $NEXT }} +1.716 2023-06-26 14:14:46-05:00 America/Chicago + [Added] - Added a parameter to show stack trace arguments when using the diff --git a/Makefile.PL b/Makefile.PL index aac7b3f..3536ac9 100644 --- a/Makefile.PL +++ b/Makefile.PL @@ -23,7 +23,7 @@ my %WriteMakefileArgs = ( "IPC::Open3" => 0, "Test::More" => 0 }, - "VERSION" => "1.716", + "VERSION" => "1.717", "test" => { "TESTS" => "t/*.t" } diff --git a/lib/Log/Any.pm b/lib/Log/Any.pm index 0ee5d8c..9a311d3 100644 --- a/lib/Log/Any.pm +++ b/lib/Log/Any.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any; # ABSTRACT: Bringing loggers and listeners together -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Manager; use Log::Any::Proxy::Null; diff --git a/lib/Log/Any/Adapter.pm b/lib/Log/Any/Adapter.pm index 73eca45..3febab3 100644 --- a/lib/Log/Any/Adapter.pm +++ b/lib/Log/Any/Adapter.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter; # ABSTRACT: Tell Log::Any where to send its logs -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any; our @CARP_NOT = ( 'Log::Any::Manager' ); diff --git a/lib/Log/Any/Adapter/Base.pm b/lib/Log/Any/Adapter/Base.pm index 1b37222..c6273f3 100644 --- a/lib/Log/Any/Adapter/Base.pm +++ b/lib/Log/Any/Adapter/Base.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Adapter::Base; -our $VERSION = '1.716'; +our $VERSION = '1.717'; our @CARP_NOT = ( 'Log::Any::Adapter' ); # we import these in case any legacy adapter uses them as class methods diff --git a/lib/Log/Any/Adapter/Capture.pm b/lib/Log/Any/Adapter/Capture.pm index d539fcd..006753d 100644 --- a/lib/Log/Any/Adapter/Capture.pm +++ b/lib/Log/Any/Adapter/Capture.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Capture; # ABSTRACT: Adapter for capturing log messages into an arrayref -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/File.pm b/lib/Log/Any/Adapter/File.pm index ccb475a..213b39e 100644 --- a/lib/Log/Any/Adapter/File.pm +++ b/lib/Log/Any/Adapter/File.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::File; # ABSTRACT: Simple adapter for logging to files -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Config; use Fcntl qw/:flock/; diff --git a/lib/Log/Any/Adapter/Multiplex.pm b/lib/Log/Any/Adapter/Multiplex.pm index 79b10de..43290fb 100644 --- a/lib/Log/Any/Adapter/Multiplex.pm +++ b/lib/Log/Any/Adapter/Multiplex.pm @@ -1,6 +1,6 @@ package Log::Any::Adapter::Multiplex; # ABSTRACT: Adapter to use allow structured logging across other adapters -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any; use Log::Any::Adapter; diff --git a/lib/Log/Any/Adapter/Null.pm b/lib/Log/Any/Adapter/Null.pm index 3eb992b..b5ee1df 100644 --- a/lib/Log/Any/Adapter/Null.pm +++ b/lib/Log/Any/Adapter/Null.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Null; # ABSTRACT: Discards all log messages -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Base; our @ISA = qw/Log::Any::Adapter::Base/; diff --git a/lib/Log/Any/Adapter/Stderr.pm b/lib/Log/Any/Adapter/Stderr.pm index aa670cb..74d46fa 100644 --- a/lib/Log/Any/Adapter/Stderr.pm +++ b/lib/Log/Any/Adapter/Stderr.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Stderr; # ABSTRACT: Simple adapter for logging to STDERR -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/Stdout.pm b/lib/Log/Any/Adapter/Stdout.pm index 969dd9a..a36bd19 100644 --- a/lib/Log/Any/Adapter/Stdout.pm +++ b/lib/Log/Any/Adapter/Stdout.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Stdout; # ABSTRACT: Simple adapter for logging to STDOUT -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util (); diff --git a/lib/Log/Any/Adapter/Syslog.pm b/lib/Log/Any/Adapter/Syslog.pm index 0a8107e..95ecc63 100644 --- a/lib/Log/Any/Adapter/Syslog.pm +++ b/lib/Log/Any/Adapter/Syslog.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Syslog; # ABSTRACT: Send Log::Any logs to syslog -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util qw{make_method}; use base qw{Log::Any::Adapter::Base}; diff --git a/lib/Log/Any/Adapter/Test.pm b/lib/Log/Any/Adapter/Test.pm index 44aabb3..22e2dd6 100644 --- a/lib/Log/Any/Adapter/Test.pm +++ b/lib/Log/Any/Adapter/Test.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Adapter::Test; -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util qw/dump_one_line/; use Test::Builder; diff --git a/lib/Log/Any/Adapter/Util.pm b/lib/Log/Any/Adapter/Util.pm index 35a89d3..cf64d61 100644 --- a/lib/Log/Any/Adapter/Util.pm +++ b/lib/Log/Any/Adapter/Util.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Adapter::Util; # ABSTRACT: Common utility functions for Log::Any -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Exporter; our @ISA = qw/Exporter/; diff --git a/lib/Log/Any/Manager.pm b/lib/Log/Any/Manager.pm index 4c80ab8..fc086b0 100644 --- a/lib/Log/Any/Manager.pm +++ b/lib/Log/Any/Manager.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Manager; -our $VERSION = '1.716'; +our $VERSION = '1.717'; sub new { my $class = shift; diff --git a/lib/Log/Any/Proxy.pm b/lib/Log/Any/Proxy.pm index 2958377..fc8ef83 100644 --- a/lib/Log/Any/Proxy.pm +++ b/lib/Log/Any/Proxy.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy; # ABSTRACT: Log::Any generator proxy object -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util (); use overload; diff --git a/lib/Log/Any/Proxy/Null.pm b/lib/Log/Any/Proxy/Null.pm index 049256c..ef52faa 100644 --- a/lib/Log/Any/Proxy/Null.pm +++ b/lib/Log/Any/Proxy/Null.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy::Null; # ABSTRACT: Log::Any generator proxy for no adapters -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Adapter::Util (); use Log::Any::Proxy; diff --git a/lib/Log/Any/Proxy/Test.pm b/lib/Log/Any/Proxy/Test.pm index 708c5f6..321897e 100644 --- a/lib/Log/Any/Proxy/Test.pm +++ b/lib/Log/Any/Proxy/Test.pm @@ -4,7 +4,7 @@ use warnings; package Log::Any::Proxy::Test; -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index ae8df58..419f156 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Proxy::WithStackTrace; # ABSTRACT: Log::Any proxy to upgrade string errors to objects with stack traces -our $VERSION = '1.716'; +our $VERSION = '1.717'; use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; diff --git a/lib/Log/Any/Test.pm b/lib/Log/Any/Test.pm index ebe2a24..272a107 100644 --- a/lib/Log/Any/Test.pm +++ b/lib/Log/Any/Test.pm @@ -5,7 +5,7 @@ use warnings; package Log::Any::Test; # ABSTRACT: Test what you're logging with Log::Any -our $VERSION = '1.716'; +our $VERSION = '1.717'; no warnings 'once'; $Log::Any::OverrideDefaultAdapterClass = 'Log::Any::Adapter::Test'; -- cgit v1.2.3 From 1c459069557d957f683b4321d57eb7780b482ec6 Mon Sep 17 00:00:00 2001 From: Larry Leszczynski Date: Mon, 14 Aug 2023 13:52:08 -0600 Subject: Fix stack trace scrubbing in Log::Any::Proxy::WithStackTrace The previous logic was all wrong - it extracted the stack trace from any exception objects sent as log messages, and scrubbed them, but then threw away the exception objects entirely and just sent the stack trace as if it was the log message. The new logic logic scrubs the stack traces in-place within the exception objects. --- lib/Log/Any/Proxy/WithStackTrace.pm | 141 +++++++---- t/proxy-with-stack-trace.t | 460 ++++++++++++++++++++++++++++-------- 2 files changed, 465 insertions(+), 136 deletions(-) diff --git a/lib/Log/Any/Proxy/WithStackTrace.pm b/lib/Log/Any/Proxy/WithStackTrace.pm index 419f156..cab4219 100644 --- a/lib/Log/Any/Proxy/WithStackTrace.pm +++ b/lib/Log/Any/Proxy/WithStackTrace.pm @@ -11,24 +11,25 @@ use Log::Any::Proxy; our @ISA = qw/Log::Any::Proxy/; use Devel::StackTrace 2.00; -use Devel::StackTrace::Extract qw(extract_stack_trace); use Log::Any::Adapter::Util (); +use Scalar::Util qw/blessed reftype/; use overload; =head1 SYNOPSIS use Log::Any qw( $log, proxy_class => 'WithStackTrace' ); - # Turns on argument logging in stack traces - use Log::Any qw( $log, proxy_class => 'WithStackTrace', proxy_show_stack_trace_args => 1 ); + # Allow stack trace call stack arguments to be logged: + use Log::Any qw( $log, proxy_class => 'WithStackTrace', + proxy_show_stack_trace_args => 1 ); - # Some adapter that knows how to handle both structured data, - # and log messages which are actually objects with a - # "stack_trace" method: - # + # Configure some adapter that knows how to: + # 1) handle structured data, and + # 2) handle message objects which have a "stack_trace" method: Log::Any::Adapter->set($adapter); - $log->error("Help!"); # stack trace gets automatically added + $log->error("Help!"); # stack trace gets automatically added, + # starting from this line of code =head1 DESCRIPTION @@ -39,13 +40,20 @@ used to generate one, the resulting trace can be confusing if it begins relative to where the log adapter was called, and not relative to where the logging method was originally called. -With this proxy in place, if any logging method is called with a message -that is a non-reference scalar, that message will be upgraded into a -C object with a C method, -and that method will return a trace relative to where the logging method -was called. A string overload is provided on the object to return the -original message. Unless a C flag is specified, arguments -in the stack trace will be scrubbed. +With this proxy in place, if any logging method is called with a log +message that is a non-reference scalar (i.e. a string), that log message +will be upgraded into a C object with a +C method, and that method will return a trace relative to +where the logging method was called. A string overload is provided on +the object to return the original log message. + +Additionally, any call stack arguments in the stack trace will be +deleted before logging, to avoid accidentally logging sensitive data. +This happens both for message objects that were auto-generated from +string messages, as well as for message objects that were passed in +directly (if they appear to have a stack trace method). This default +argument scrubbing behavior can be turned off by specifying a true value +for the C import flag. B This proxy should be used with a L that is configured to handle structured data. Otherwise the object created @@ -60,18 +68,16 @@ trace. use overload '""' => \&stringify; - use Carp qw( croak ); - sub new { - my ($class, $proxy_show_stack_trace_args, $message) = @_; - croak 'no "message"' unless defined $message; + my ($class, $message, %opts) = @_; + return bless { message => $message, stack_trace => Devel::StackTrace->new( # Filter e.g "Log::Any::Proxy", "My::Log::Any::Proxy", etc. ignore_package => [ qr/(?:^|::)Log::Any(?:::|$)/ ], - no_args => !$proxy_show_stack_trace_args, + no_args => $opts{no_args}, ), }, $class; } @@ -85,10 +91,14 @@ trace. =head2 maybe_upgrade_with_stack_trace -This is an internal use method that will convert a non-reference scalar + @args = $self->maybe_upgrade_with_stack_trace(@args); + +This is an internal-use method that will convert a non-reference scalar message into a C object with a C method. A string overload is provided to return the -original message. Args are scrubbed out in case they contain sensitive data, +original message. + +Stack trace args are scrubbed out in case they contain sensitive data, unless the C option has been set. =cut @@ -97,28 +107,73 @@ sub maybe_upgrade_with_stack_trace { my ($self, @args) = @_; - # Only want a non-ref arg, optionally followed by a structured data - # context hashref: - # - unless ($self->{proxy_show_stack_trace_args}) { - for my $i (0 .. $#args) { # Check if there's a stack trace to scrub args from - my $trace = extract_stack_trace($args[$i]); - if ($trace) { - $self->delete_args_from_stack_trace($trace); - $args[$i] = $trace; - } - } - } - + # We expect a message, optionally followed by a structured data + # context hashref. Bail if we get anything other than that rather + # than guess what the caller might be trying to do: return @args unless @args == 1 || ( @args == 2 && ref $args[1] eq 'HASH' ); - return @args if ref $args[0]; - $args[0] = Log::Any::MessageWithStackTrace->new($self->{proxy_show_stack_trace_args}, $args[0]); + if (ref $args[0]) { + $self->maybe_delete_stack_trace_args($args[0]) + unless $self->{proxy_show_stack_trace_args}; + } + else { + $args[0] = Log::Any::MessageWithStackTrace->new( + $args[0], + no_args => !$self->{proxy_show_stack_trace_args}, + ); + } return @args; } +=head2 maybe_delete_stack_trace_args + + $self->maybe_delete_stack_trace_args($arg); + +This is an internal-use method that, given a single argument that is a +reference, tries to figure out whether the argument is an object with a +stack trace, and if so tries to delete any stack trace args. + +The logic is based on L. + +It specifically looks for objects with a C method (which +should catch anything that does L, including anything +that does L), or a C method (used by +L and L and friends). + +It specifically ignores L objects, because their stack +traces don't contain any call stack args. + +=cut + +sub maybe_delete_stack_trace_args +{ + my ($self, $arg) = @_; + + return unless blessed $arg; + + if ($arg->can('stack_trace')) { + # This should catch anything that does StackTrace::Auto, + # including anything that does Throwable::Error. + my $trace = $arg->stack_trace; + $self->delete_args_from_stack_trace($trace); + } + elsif ($arg->isa('Mojo::Exception')) { + # Skip these, they don't have args in their stack traces. + } + elsif ($arg->can('trace')) { + # This should catch Exception::Class and Moose::Exception and + # friends. Make sure to check for the "trace" method *after* + # skipping the Mojo::Exception objects, because those also have + # a "trace" method. + my $trace = $arg->trace; + $self->delete_args_from_stack_trace($trace); + } + + return; +} + my %aliases = Log::Any::Adapter::Util::log_level_aliases(); # Set up methods/aliases and detection methods/aliases @@ -137,10 +192,11 @@ foreach my $name ( Log::Any::Adapter::Util::logging_methods(), keys(%aliases) ) =head2 delete_args_from_stack_trace($trace) - $self->delete_args_from_stack_trace($trace) + $self->delete_args_from_stack_trace($trace) -To scrub potentially sensitive data from C arguments, this method deletes -arguments from all of the C in the trace. +To scrub potentially sensitive data from C arguments, +this method deletes arguments from all of the C +in the trace. =cut @@ -148,11 +204,14 @@ sub delete_args_from_stack_trace { my ($self, $trace) = @_; - return unless $trace; + return unless $trace && $trace->can('frames'); foreach my $frame ($trace->frames) { + next unless $frame->{args}; $frame->{args} = []; } + + return; } 1; diff --git a/t/proxy-with-stack-trace.t b/t/proxy-with-stack-trace.t index 2f06d8e..4d49b63 100644 --- a/t/proxy-with-stack-trace.t +++ b/t/proxy-with-stack-trace.t @@ -4,36 +4,50 @@ use warnings; use Test::More; use List::Util qw( any ); use Log::Any; - -plan tests => 61; +use Scalar::Util qw( blessed ); +use Storable qw( dclone ); use FindBin; use lib $FindBin::RealBin; use TestAdapters; +my ( + $num_tests, + $have_Mojo_Exception, + $have_Moose_Exception, + $have_Throwable_Error, +); BEGIN { + + $num_tests = 152; eval { - require Devel::StackTrace; - Devel::StackTrace->VERSION( 2.00 ); + require Mojo::Exception; + $have_Mojo_Exception = 1; + $num_tests += 27; }; - if ( $@ ) { - plan skip_all => 'Devel::StackTrace >= 2.00 is required for this test'; - } eval { - require Storable; - Storable->VERSION( 3.08 ); + require Throwable::Error; + $have_Throwable_Error = 1; + $num_tests += 31; }; - if ( $@ ) { - plan skip_all => 'Storable >= 3.08 is required for this test'; - } eval { - require Devel::StackTrace::Extract; + require Moose::Exception; + $have_Moose_Exception = 1; + $num_tests += 31; + }; + + eval { + require Devel::StackTrace; + Devel::StackTrace->VERSION( 2.00 ); }; if ( $@ ) { - plan skip_all => 'Devel::StackTrace::Extract is required for this test'; + plan skip_all => 'Devel::StackTrace >= 2.00 is required for this test'; + $num_tests = 0; } } +plan tests => $num_tests if $num_tests; + use Log::Any::Proxy::WithStackTrace; # necessary? my $default_log = Log::Any->get_logger; @@ -62,10 +76,16 @@ Log::Any->set_adapter('+TestAdapters::Structured'); is ref $default_log, 'Log::Any::Proxy', 'existing default proxy is reblessed after adapter'; +is !!$default_log->{proxy_show_stack_trace_args}, '', + 'Defauly log does not proxy_show_stack_trace_args'; is ref $log, 'Log::Any::Proxy::WithStackTrace', 'existing explicit proxy is still WithStackTrace after adapter'; +is !!$log->{proxy_show_stack_trace_args}, '', + 'WithStackTrace does not proxy_show_stack_trace_args'; is ref $log_show_args, 'Log::Any::Proxy::WithStackTrace', 'existing explicit proxy with proxy_show_stack_trace_args flag is still WithStackTrace after adapter'; +is !!$log_show_args->{proxy_show_stack_trace_args}, 1, + 'WithStackTrace does proxy_show_stack_trace_args'; is ref $default_log->adapter, 'TestAdapters::Structured', 'existing default proxy has correct adapter'; @@ -74,102 +94,352 @@ is ref $log->adapter, 'TestAdapters::Structured', is ref $log_show_args->adapter, 'TestAdapters::Structured', 'existing explicit proxy with proxy_show_stack_trace_args flag has correct adapter'; -my @test_cases = ( +################################################################### + +# Dummy default for initial call: +my $logger = $default_log; +my $message = "dummy"; +my $extra_args = []; + +my ($Mojo_Exception, $Moose_Exception, $Throwable_Error); + +sub foo +{ + sub bar { + + # Log with a stack trace that is 3 frames deep (main->foo->bar): + $logger->info($message, @$extra_args); + + # Create a Mojo::Exception with a similar stack trace: + if ($have_Mojo_Exception && !$Mojo_Exception) { + local $@; + eval { Mojo::Exception->throw("Help!") }; + $Mojo_Exception = $@; + } + + # Create a Moose::Exception with a similar stack trace: + if ($have_Moose_Exception && !$Moose_Exception) { + $Moose_Exception = Moose::Exception->new(message => "Help!"); + } + + # Create a Throwable::Error with a similar stack trace: + if ($have_Throwable_Error && !$Throwable_Error) { + local $@; + eval { Throwable::Error->throw("Help!") }; + $Throwable_Error = $@; + # Default log adapter doesn't like coderefs: + $Throwable_Error->stack_trace->{frame_filter} = undef; + $Throwable_Error->{stack_trace_args} = undef; + } + } + + bar("quux"); +} + +# Make sure exception objects get initialized: +foo("bar", "baz") if $have_Mojo_Exception || + $have_Moose_Exception || + $have_Throwable_Error; + +my ($desc, $expected_by_type); + +foreach my $t ( [ - 'simple', - [ 'test' ], - 'test', + "with string", + "Help!", + [], + { + "default log" => "Help!", + "proxy log" => [ + "Help!", + "Log::Any::MessageWithStackTrace", + ], + "proxy log show args" => [ + "Help!", + "Log::Any::MessageWithStackTrace", + ], + }, ], [ - 'with structured data', - [ 'test', { foo => 1 } ], - 'test', + "with string and extra args", + "Help!", + [ {extra => "data"} ], + { + "default log" => "Help!", + "proxy log" => [ + "Help!", + "Log::Any::MessageWithStackTrace", + ], + "proxy log show args" => [ + "Help!", + "Log::Any::MessageWithStackTrace", + ], + }, ], [ - 'formatted', - [ 'test %s', 'extra' ], - 'test extra', + "with string and bad extra args", + "Help!", + [ {extra => "data"}, "huh?" ], + { + "default log" => "Help!", + # no automatic object inflation if unexpected args: + "proxy log" => "Help!", + "proxy log show args" => "Help!", + }, ], -); - -sub check_test_cases { - foreach my $test_case (@test_cases) { - my ($desc, $args, $expected) = @$test_case; + [ + "with string and bad non-hashref extra args", + "Help!", + [ "huh?" ], + { + "default log" => "Help!", + # no automatic object inflation if unexpected args: + "proxy log" => "Help!", + "proxy log show args" => "Help!", + }, + ], + [ + "with non-string unblessed message", + {foo => "bar"}, + [], + { + "default log" => [ + {foo => "bar"}, + "HASH", + ], + # no automatic object inflation if non-string message: + "proxy log" => [ + {foo => "bar"}, + "HASH", + ], + "proxy log show args" => [ + {foo => "bar"}, + "HASH", + ], + }, + ], + [ + "with dummy blessed object", + bless({foo => "bar"}, "DummyError"), + [], + { + "default log" => [ + qr{^DummyError=HASH\(0x[0-9a-f]+\)}, + "DummyError", + ], + # no automatic object inflation if random blessed message: + "proxy log" => [ + qr{^DummyError=HASH\(0x[0-9a-f]+\)}, + "DummyError", + ], + "proxy log show args" => [ + qr{^DummyError=HASH\(0x[0-9a-f]+\)}, + "DummyError", + ], + }, + ], + [ + "with Mojo::Exception message", + $Mojo_Exception, + [], + { + "default log" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\.}, + "Mojo::Exception", + ], + "proxy log" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\.}, + "Mojo::Exception", + ], + "proxy log show args" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\.}, + "Mojo::Exception", + ], + }, + ], + [ + "with Moose::Exception message", + $Moose_Exception, + [], + { + "default log" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\n}, + "Moose::Exception", + ], + "proxy log" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\n}, + "Moose::Exception", + ], + "proxy log show args" => [ + qr{^Help! at t/proxy-with-stack-trace\.t line \d+\n}, + "Moose::Exception", + ], + }, + ], + [ + "with Throwable::Error message", + $Throwable_Error, + [], + { + "default log" => [ + qr{^Help!\n\nTrace begun at t/proxy-with-stack-trace\.t line \d+\n}, + "Throwable::Error", + ], + "proxy log" => [ + qr{^Help!\n\nTrace begun at t/proxy-with-stack-trace\.t line \d+\n}, + "Throwable::Error", + ], + "proxy log show args" => [ + qr{^Help!\n\nTrace begun at t/proxy-with-stack-trace\.t line \d+\n}, + "Throwable::Error", + ], + }, + ], +) { + my $orig_message; + ($desc, $orig_message, $extra_args, $expected_by_type) = @$t; - my $is_formatted = $args->[0] =~ /%/; + # This can happen if one of the optional exception modules is not + # loaded: + next unless $orig_message; - my $method = $is_formatted ? 'infof' : 'info'; + foreach my $type (sort keys %$expected_by_type) { - my ($msgs, $msg); + $message = ref $orig_message ? dclone $orig_message : $orig_message; - my $type = 'default'; + $logger = { + "default log" => $default_log, + "proxy log" => $log, + "proxy log show args" => $log_show_args, + }->{$type}; @TestAdapters::STRUCTURED_LOG = (); - $default_log->$method(@$args); - $msgs = \@TestAdapters::STRUCTURED_LOG; - is @$msgs, 1, "$desc expected number of structured messages from $type logger"; - is $msgs->[0]->{category}, 'main', - "$desc expected category from $type logger"; - is $msgs->[0]->{level}, 'info', - "$desc expected level from $type logger"; - $msg = $msgs->[0]->{messages}->[0]; # "messages" for text - is $msg, $expected, - "$desc expected message from $type logger"; - - $type = 'stack trace'; + foo("bar", "baz"); - @TestAdapters::STRUCTURED_LOG = (); - $log->$method(@$args); - $msgs = \@TestAdapters::STRUCTURED_LOG; - is @$msgs, 1, "$desc expected number of structured messages from $type logger"; - is $msgs->[0]->{category}, 'main', - "$desc expected category from $type logger"; - is $msgs->[0]->{level}, 'info', - "$desc expected level from $type logger"; - $msg = $msgs->[0]->{data}->[0]; # "data" for non-text - is ref $msg, 'Log::Any::MessageWithStackTrace', - "$desc expected message object from $type logger"; - is "$msg", $expected, - "$desc expected stringified message from $type logger"; - my $trace = $msg->stack_trace; - is ref $trace, 'Devel::StackTrace', - "$desc expected stack_trace object from $type logger"; - is $trace->frame_count, 2, - "$desc stack_trace object has expected number of frames from $type logger"; - # first frame should be the call to "info" inside this sub (19 lines up), - # second frame should be the call to this sub from main - is $trace->frame(0)->line, __LINE__ - 19, - "$desc stack_trace object has expected first frame from $type logger"; - is $trace->frame(1)->subroutine, 'main::check_test_cases', - "$desc stack_trace object has expected second frame from $type logger"; - if (!$is_formatted && @$args > 1) { - my $more_data = $msgs->[0]->{data}->[1]; - is_deeply $more_data, $args->[1], - "expected structured data from $type logger"; + my $logged = \@TestAdapters::STRUCTURED_LOG; + + my $long_desc = "$type $desc"; + + is @$logged, 1, + "$long_desc - got expected number of log messages"; + my $msg = $logged->[0]; + is $msg->{category}, 'main', + "$long_desc - got expected category"; + is $msg->{level}, 'info', + "$long_desc - got expected level"; + + my $expected = $expected_by_type->{$type}; + + if (ref $expected) { + my $messages = $msg->{messages}; + is $messages, undef, + "$long_desc - got expected number of structured messages"; + my $data = $msg->{data}; + if (@$extra_args == 0) { + is @$data, 1, + "$long_desc - got expected number of structured data"; + } + elsif (@$extra_args == 1 && ref $extra_args->[0] eq 'HASH') { + is @$data, 2, + "$long_desc - got expected number of structured data"; + is_deeply $data->[1], $extra_args->[0], + "$long_desc - got expected extra structured data"; + } + else { + is $data, undef, + "$long_desc - got expected number of structured data"; + } + my $thing = $data->[0]; + my $blessed = blessed $thing; + + my $expected_value = $expected->[0]; + my $expected_type = $expected->[1]; + + if ($blessed || ! ref $expected_value) { + + if (ref $expected_value eq 'Regexp') { + like "$thing", $expected_value, + "$long_desc - message stringifies correctly"; + } + else { + is "$thing", $expected_value, + "$long_desc - message stringifies correctly"; + } + } + is ref $thing, $expected_type, + "$long_desc - expected type of structured data got logged"; + + my (@frames, $stack_trace); + if ($blessed) { + @frames = $thing->can("frames") ? $thing->frames : (); + unless (@frames) { + $stack_trace = $thing->can("stack_trace") + ? $thing->stack_trace + : $thing->can("trace") + ? $thing->trace : undef; + @frames = $stack_trace->frames if $stack_trace; + } + } + if (@frames) { + + # Mojo::Exception returns a listref istead of a list: + @frames = @{$frames[0]} if @frames == 1 && + ref $frames[0] eq 'ARRAY'; + + my $frame = $frames[-1]; + my $sub = $expected_type eq "Mojo::Exception" + ? $frame->[3] : $frame->subroutine; + is $sub, "main::foo", + "$long_desc - first frame has correct sub"; + unless ($expected_type eq "Mojo::Exception") { + if ($type eq "proxy log") { + is_deeply [$frame->args], [], + "$long_desc - first frame has expected args"; + } + elsif ($type eq "proxy log show args") { + is_deeply [$frame->args], ["bar","baz"], + "$long_desc - first frame has expected args"; + } + } + $frame = $frames[-2]; + $sub = $expected_type eq "Mojo::Exception" + ? $frame->[3] : $frame->subroutine; + is $sub, "main::bar", + "$long_desc - second frame has correct sub"; + unless ($expected_type eq "Mojo::Exception") { + if ($type eq "proxy log") { + is_deeply [$frame->args], [], + "$long_desc - second frame has expected args"; + } + elsif ($type eq "proxy log show args") { + is_deeply [$frame->args], ["quux"], + "$long_desc - second frame has expected args"; + } + } + } } - foreach my $frame ($trace->frames) { - is scalar @{ $frame->{args} }, 0, - "stack_trace frame does not have args by default"; + else { + my $messages = $msg->{messages}; + my @expected = ($expected); + push @expected, $extra_args->[0] if $extra_args->[0] && + ref $extra_args->[0] ne 'HASH'; + push @expected, $extra_args->[1] if $extra_args->[1]; + is @$messages, @expected, + "$long_desc - got expected number of structured messages"; + is_deeply $messages, \@expected, + "$long_desc - expected structured message got logged"; + my $data = $msg->{data}; + if (ref $extra_args->[0] eq 'HASH') { + is @$data, 1, + "$long_desc - got expected number of structured data"; + is_deeply $data->[0], $extra_args->[0], + "$long_desc - got expected structured data"; + } + else { + is $data, undef, + "$long_desc - got expected number of structured data"; + } } - - @TestAdapters::STRUCTURED_LOG = (); - $log_show_args->$method(@$args); - $msgs = \@TestAdapters::STRUCTURED_LOG; - $msg = $msgs->[0]->{data}->[0]; # "data" for non-text - - $trace = $msg->stack_trace; - - ok( - any ( - sub { - ($_->args >= 1); - }, - $trace->frames - ), - "stack_trace frame has args if proxy_show_stack_trace_args => 1 is passed to logger", - ); } } -check_test_cases(); - -- cgit v1.2.3 From a2abc631d6a3f48e82775db7a8f5416b39c306c3 Mon Sep 17 00:00:00 2001 From: Doug Bell Date: Thu, 17 Aug 2023 10:52:42 -0500 Subject: release v1.717 [Fixed] - Fixed WithStackTrace proxy to remove arguments in-place instead of always stringifying the exception object immediately. This means we need to handle different exception objects differently, but it also means a better log message. Thanks @larryl and @GrantStreetGroup for submitting this fix! [Github #100] --- Changes | 8 ++++++++ README.mkdn | 2 +- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/Changes b/Changes index cf863b9..0d41ead 100644 --- a/Changes +++ b/Changes @@ -4,6 +4,14 @@ Revision history for Log-Any {{ $NEXT }} + [Fixed] + + - Fixed WithStackTrace proxy to remove arguments in-place instead of + always stringifying the exception object immediately. This means we + need to handle different exception objects differently, but it also + means a better log message. Thanks @larryl and @GrantStreetGroup for + submitting this fix! [Github #100] + 1.716 2023-06-26 14:14:46-05:00 America/Chicago [Added] diff --git a/README.mkdn b/README.mkdn index b7b9232..f6daf18 100644 --- a/README.mkdn +++ b/README.mkdn @@ -4,7 +4,7 @@ Log::Any - Bringing loggers and listeners together # VERSION -version 1.716 +version 1.717 # SYNOPSIS -- cgit v1.2.3