Skip to content

Commit 1c45906

Browse files
author
Larry Leszczynski
committed
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.
1 parent b81d79a commit 1c45906

File tree

2 files changed

+465
-136
lines changed

2 files changed

+465
-136
lines changed

lib/Log/Any/Proxy/WithStackTrace.pm

Lines changed: 100 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -11,24 +11,25 @@ use Log::Any::Proxy;
1111
our @ISA = qw/Log::Any::Proxy/;
1212

1313
use Devel::StackTrace 2.00;
14-
use Devel::StackTrace::Extract qw(extract_stack_trace);
1514
use Log::Any::Adapter::Util ();
15+
use Scalar::Util qw/blessed reftype/;
1616
use overload;
1717

1818
=head1 SYNOPSIS
1919
2020
use Log::Any qw( $log, proxy_class => 'WithStackTrace' );
2121
22-
# Turns on argument logging in stack traces
23-
use Log::Any qw( $log, proxy_class => 'WithStackTrace', proxy_show_stack_trace_args => 1 );
22+
# Allow stack trace call stack arguments to be logged:
23+
use Log::Any qw( $log, proxy_class => 'WithStackTrace',
24+
proxy_show_stack_trace_args => 1 );
2425
25-
# Some adapter that knows how to handle both structured data,
26-
# and log messages which are actually objects with a
27-
# "stack_trace" method:
28-
#
26+
# Configure some adapter that knows how to:
27+
# 1) handle structured data, and
28+
# 2) handle message objects which have a "stack_trace" method:
2929
Log::Any::Adapter->set($adapter);
3030
31-
$log->error("Help!"); # stack trace gets automatically added
31+
$log->error("Help!"); # stack trace gets automatically added,
32+
# starting from this line of code
3233
3334
=head1 DESCRIPTION
3435
@@ -39,13 +40,20 @@ used to generate one, the resulting trace can be confusing if it begins
3940
relative to where the log adapter was called, and not relative to where
4041
the logging method was originally called.
4142
42-
With this proxy in place, if any logging method is called with a message
43-
that is a non-reference scalar, that message will be upgraded into a
44-
C<Log::Any::MessageWithStackTrace> object with a C<stack_trace> method,
45-
and that method will return a trace relative to where the logging method
46-
was called. A string overload is provided on the object to return the
47-
original message. Unless a C<proxy_show_stack_trace_args> flag is specified, arguments
48-
in the stack trace will be scrubbed.
43+
With this proxy in place, if any logging method is called with a log
44+
message that is a non-reference scalar (i.e. a string), that log message
45+
will be upgraded into a C<Log::Any::MessageWithStackTrace> object with a
46+
C<stack_trace> method, and that method will return a trace relative to
47+
where the logging method was called. A string overload is provided on
48+
the object to return the original log message.
49+
50+
Additionally, any call stack arguments in the stack trace will be
51+
deleted before logging, to avoid accidentally logging sensitive data.
52+
This happens both for message objects that were auto-generated from
53+
string messages, as well as for message objects that were passed in
54+
directly (if they appear to have a stack trace method). This default
55+
argument scrubbing behavior can be turned off by specifying a true value
56+
for the C<proxy_show_stack_trace_args> import flag.
4957
5058
B<Important:> This proxy should be used with a L<Log::Any::Adapter> that
5159
is configured to handle structured data. Otherwise the object created
@@ -60,18 +68,16 @@ trace.
6068

6169
use overload '""' => \&stringify;
6270

63-
use Carp qw( croak );
64-
6571
sub new
6672
{
67-
my ($class, $proxy_show_stack_trace_args, $message) = @_;
68-
croak 'no "message"' unless defined $message;
73+
my ($class, $message, %opts) = @_;
74+
6975
return bless {
7076
message => $message,
7177
stack_trace => Devel::StackTrace->new(
7278
# Filter e.g "Log::Any::Proxy", "My::Log::Any::Proxy", etc.
7379
ignore_package => [ qr/(?:^|::)Log::Any(?:::|$)/ ],
74-
no_args => !$proxy_show_stack_trace_args,
80+
no_args => $opts{no_args},
7581
),
7682
}, $class;
7783
}
@@ -85,10 +91,14 @@ trace.
8591
8692
=head2 maybe_upgrade_with_stack_trace
8793
88-
This is an internal use method that will convert a non-reference scalar
94+
@args = $self->maybe_upgrade_with_stack_trace(@args);
95+
96+
This is an internal-use method that will convert a non-reference scalar
8997
message into a C<Log::Any::MessageWithStackTrace> object with a
9098
C<stack_trace> method. A string overload is provided to return the
91-
original message. Args are scrubbed out in case they contain sensitive data,
99+
original message.
100+
101+
Stack trace args are scrubbed out in case they contain sensitive data,
92102
unless the C<proxy_show_stack_trace_args> option has been set.
93103
94104
=cut
@@ -97,28 +107,73 @@ sub maybe_upgrade_with_stack_trace
97107
{
98108
my ($self, @args) = @_;
99109

100-
# Only want a non-ref arg, optionally followed by a structured data
101-
# context hashref:
102-
#
103-
unless ($self->{proxy_show_stack_trace_args}) {
104-
for my $i (0 .. $#args) { # Check if there's a stack trace to scrub args from
105-
my $trace = extract_stack_trace($args[$i]);
106-
if ($trace) {
107-
$self->delete_args_from_stack_trace($trace);
108-
$args[$i] = $trace;
109-
}
110-
}
111-
}
112-
110+
# We expect a message, optionally followed by a structured data
111+
# context hashref. Bail if we get anything other than that rather
112+
# than guess what the caller might be trying to do:
113113
return @args unless @args == 1 ||
114114
( @args == 2 && ref $args[1] eq 'HASH' );
115-
return @args if ref $args[0];
116115

117-
$args[0] = Log::Any::MessageWithStackTrace->new($self->{proxy_show_stack_trace_args}, $args[0]);
116+
if (ref $args[0]) {
117+
$self->maybe_delete_stack_trace_args($args[0])
118+
unless $self->{proxy_show_stack_trace_args};
119+
}
120+
else {
121+
$args[0] = Log::Any::MessageWithStackTrace->new(
122+
$args[0],
123+
no_args => !$self->{proxy_show_stack_trace_args},
124+
);
125+
}
118126

119127
return @args;
120128
}
121129

130+
=head2 maybe_delete_stack_trace_args
131+
132+
$self->maybe_delete_stack_trace_args($arg);
133+
134+
This is an internal-use method that, given a single argument that is a
135+
reference, tries to figure out whether the argument is an object with a
136+
stack trace, and if so tries to delete any stack trace args.
137+
138+
The logic is based on L<Devel::StackTrace::Extract>.
139+
140+
It specifically looks for objects with a C<stack_trace> method (which
141+
should catch anything that does L<StackTrace::Auto>, including anything
142+
that does L<Throwable::Error>), or a C<trace> method (used by
143+
L<Exception::Class> and L<Moose::Exception> and friends).
144+
145+
It specifically ignores L<Mojo::Exception> objects, because their stack
146+
traces don't contain any call stack args.
147+
148+
=cut
149+
150+
sub maybe_delete_stack_trace_args
151+
{
152+
my ($self, $arg) = @_;
153+
154+
return unless blessed $arg;
155+
156+
if ($arg->can('stack_trace')) {
157+
# This should catch anything that does StackTrace::Auto,
158+
# including anything that does Throwable::Error.
159+
my $trace = $arg->stack_trace;
160+
$self->delete_args_from_stack_trace($trace);
161+
}
162+
elsif ($arg->isa('Mojo::Exception')) {
163+
# Skip these, they don't have args in their stack traces.
164+
}
165+
elsif ($arg->can('trace')) {
166+
# This should catch Exception::Class and Moose::Exception and
167+
# friends. Make sure to check for the "trace" method *after*
168+
# skipping the Mojo::Exception objects, because those also have
169+
# a "trace" method.
170+
my $trace = $arg->trace;
171+
$self->delete_args_from_stack_trace($trace);
172+
}
173+
174+
return;
175+
}
176+
122177
my %aliases = Log::Any::Adapter::Util::log_level_aliases();
123178

124179
# Set up methods/aliases and detection methods/aliases
@@ -137,22 +192,26 @@ foreach my $name ( Log::Any::Adapter::Util::logging_methods(), keys(%aliases) )
137192

138193
=head2 delete_args_from_stack_trace($trace)
139194
140-
$self->delete_args_from_stack_trace($trace)
195+
$self->delete_args_from_stack_trace($trace)
141196
142-
To scrub potentially sensitive data from C<Devel::StackTrace> arguments, this method deletes
143-
arguments from all of the C<Devel::StackTrace::Frame> in the trace.
197+
To scrub potentially sensitive data from C<Devel::StackTrace> arguments,
198+
this method deletes arguments from all of the C<Devel::StackTrace::Frame>
199+
in the trace.
144200
145201
=cut
146202

147203
sub delete_args_from_stack_trace
148204
{
149205
my ($self, $trace) = @_;
150206

151-
return unless $trace;
207+
return unless $trace && $trace->can('frames');
152208

153209
foreach my $frame ($trace->frames) {
210+
next unless $frame->{args};
154211
$frame->{args} = [];
155212
}
213+
214+
return;
156215
}
157216

158217
1;

0 commit comments

Comments
 (0)