From 7dd62e0a65cbd1db78688ef15d9e8739a786bce7 Mon Sep 17 00:00:00 2001 From: "David E. Wheeler" Date: Tue, 31 Dec 2024 10:52:51 -0500 Subject: [PATCH] Improve unknown engine error and error details Add the `details_string` method to App::Sqitch::X. It includes just the previous error and the stack trace. Then teach the `go` method in `App::Sqitch` to use it for unexpected errors, and to use `as_string` for unexpected DEV errors. This adds additional context to error output for DEV errors and for other errors when trace mode is enabled (by `-vvv`). Then change the error loading an engine package from a DEV error to an engine error, and provide a localized error message. This results in the much less noisy error "Unknown engine: foo" when a user specifies an unknown engine URI, such as `db:foo:`. Fixes #838. --- Changes | 6 ++++++ lib/App/Sqitch.pm | 10 +++++----- lib/App/Sqitch/Engine.pm | 5 ++++- lib/App/Sqitch/X.pm | 17 ++++++++++++++++- t/base.t | 40 +++++++++++++++++++++++++++++----------- t/engine.t | 4 ++-- t/x.t | 19 +++++++++++++++++-- 7 files changed, 79 insertions(+), 22 deletions(-) diff --git a/Changes b/Changes index a0b21874b..d92818d79 100644 --- a/Changes +++ b/Changes @@ -17,6 +17,12 @@ Revision history for Perl extension App::Sqitch - Removed a wayward mention of the long-deprecated `SQITCH_URI` environment variable from the Oracle tutorial. Thanks to Austin Hanson for the report (#845). + - Improved error output by including any previous exception. + - Improved the unknown engine error to be a runtime error, rather than + development time, and to provide a localized error message. The stack + underlying error loading the engine package and the stack trace remain + available by using triple verbosity (`-vvv`). Thanks to Martin Fischer + for the report (#838). 1.4.1 2024-02-04T16:35:32Z - Removed the quoting of the role and warehouse identifiers that was diff --git a/lib/App/Sqitch.pm b/lib/App/Sqitch.pm index b8813fd3c..a23d3f625 100644 --- a/lib/App/Sqitch.pm +++ b/lib/App/Sqitch.pm @@ -213,13 +213,13 @@ sub go { if ($_->exitval == 1) { # Non-fatal exception; just send the message to info. $sqitch->info($_->message); + } elsif ($_->ident eq 'DEV') { + # Vent complete details of fatal DEV error. + $sqitch->vent($_->as_string); } else { - # Fatal exception; vent. + # Vent fatal error message, trace details. $sqitch->vent($_->message); - - # Emit the stack trace. DEV errors should be vented; otherwise trace. - my $meth = $_->ident eq 'DEV' ? 'vent' : 'trace'; - $sqitch->$meth($_->stack_trace->as_string); + $sqitch->trace($_->details_string); } # Bail. diff --git a/lib/App/Sqitch/Engine.pm b/lib/App/Sqitch/Engine.pm index 32ba15a1a..7b2dee32a 100644 --- a/lib/App/Sqitch/Engine.pm +++ b/lib/App/Sqitch/Engine.pm @@ -169,7 +169,10 @@ sub load { ); my $pkg = __PACKAGE__ . '::' . $target->engine_key; - eval "require $pkg" or hurl "Unable to load $pkg"; + eval "require $pkg" or hurl engine => __x( + 'Unknown engine: {engine}', + engine => $ekey, + ); return $pkg->new( $p ); } diff --git a/lib/App/Sqitch/X.pm b/lib/App/Sqitch/X.pm index 8221998a1..8ddbacc9b 100644 --- a/lib/App/Sqitch/X.pm +++ b/lib/App/Sqitch/X.pm @@ -54,13 +54,21 @@ sub hurl { sub as_string { my $self = shift; - join "\n", grep { defined } ( + join "\n", grep { $_ } ( $self->message, $self->previous_exception, $self->stack_trace ); } +sub details_string { + my $self = shift; + join "\n", grep { $_ } ( + $self->previous_exception, + $self->stack_trace + ); +} + 1; __END__ @@ -148,6 +156,13 @@ used for string overloading of the exception object, which means it is the output shown for uncaught exceptions. Its contents are the concatenation of the exception message, the previous exception (if any), and the stack trace. +=head3 C + + my $errstr = $x->details; + +Returns the the stringified version of the previous exception (if any), and +the stack trace. + =head1 Handling Exceptions use L to do exception handling, like so: diff --git a/t/base.t b/t/base.t index 87bc80b18..9326e3952 100644 --- a/t/base.t +++ b/t/base.t @@ -2,7 +2,7 @@ use strict; use warnings; -use Test::More tests => 214; +use Test::More tests => 224; # use Test::More 'no_plan'; use Test::MockModule 0.17; use Path::Class; @@ -138,8 +138,8 @@ GO: { my $sqitch_mock = Test::MockModule->new($CLASS); my @vented; $sqitch_mock->mock(vent => sub { shift; push @vented => @_ }); - my $traced; - $sqitch_mock->mock(trace => sub { $traced = $_[1]; }); + my @traced; + $sqitch_mock->mock(trace => sub { shift; push @traced => @_ }); my @infoed; $sqitch_mock->mock(info => sub { shift; push @infoed => @_ }); my @emitted; @@ -153,29 +153,47 @@ GO: { is_deeply \@vented, ['OMGWTF!'], 'The error should have been vented'; is_deeply \@infoed, [], 'Should have no info output'; is_deeply \@emitted, [], 'Should have no emitted output'; - is $traced, $ex->stack_trace->as_string, + is_deeply \@traced, [$ex->stack_trace->as_string], 'The stack trace should have been sent to trace'; + # Make it die with a previous exception. + $ex = puke(ident => 'yikes', message => 'Yikes!', previous_exception => 'Invalid snicker'); + @vented = @traced = (); + is $sqitch->go, 2, 'Go should return 2 on next Sqitch exception'; + is_deeply \@vented, ['Yikes!'], 'The next error should have been vented'; + is_deeply \@infoed, [], 'Should have no info output'; + is_deeply \@emitted, [], 'Should have no emitted output'; + is_deeply \@traced, ["Invalid snicker\n" . $ex->stack_trace->as_string], + 'The previous exceptin and stack trace should have been sent to trace'; + # Make it die with a developer exception. - @vented = (); - $traced = undef; + @vented = @traced = (); $ex = puke( message => 'OUCH!', exitval => 4 ); is $sqitch->go, 4, 'Go should return exitval on another exception'; - is_deeply \@vented, ['OUCH!', $ex->stack_trace->as_string], + is_deeply \@vented, ["OUCH!\n" . $ex->stack_trace->as_string], 'Both the message and the trace should have been vented'; is_deeply \@infoed, [], 'Should still have no info output'; is_deeply \@emitted, [], 'Should still have no emitted output'; - is $traced, undef, 'Nothing should have been traced'; + is_deeply \@traced, [], 'Nothing should have been traced'; + + # Make it die with a developer previous exception. + @vented = @traced = (); + $ex = puke( message => 'OOOF!', exitval => 3, previous_exception => 'Cannot open file' ); + is $sqitch->go, 3, 'Go should return exitval on wrapped exception'; + is_deeply \@vented, ["OOOF!\nCannot open file\n" . $ex->stack_trace->as_string], + 'Should have vented the message, previous exception, and trace'; + is_deeply \@infoed, [], 'Should still have no info output'; + is_deeply \@emitted, [], 'Should still have no emitted output'; + is_deeply \@traced, [], 'Nothing should have been traced'; # Make it die with a non-fatal exception (error code 1) @vented = (); - $traced = undef; $ex = puke( message => 'OOPS!', exitval => 1 ); is $sqitch->go, 1, 'Go should return exitval on non-fatal exception'; is_deeply \@vented, [], 'Should not have vented'; is_deeply \@infoed, ['OOPS!'], 'Should have sent the message to message'; is_deeply \@emitted, [], 'Should still have no emitted output'; - is $traced, undef, 'Nothing should have been traced'; + is_deeply \@traced, [], 'Nothing should have been traced'; # Make it die without an exception object. $ex = 'LOLZ'; @@ -185,7 +203,7 @@ GO: { like $vented[0], qr/^LOLZ\b/, 'And it should include our message'; is_deeply \@infoed, [], 'Should again have no info output'; is_deeply \@emitted, [], 'Should still have no emitted output'; - is $traced, undef, 'Nothing should have been traced'; + is_deeply \@traced, [], 'Nothing should have been traced'; } ############################################################################## diff --git a/t/engine.t b/t/engine.t index f7bfa8e8a..99c468315 100755 --- a/t/engine.t +++ b/t/engine.t @@ -159,7 +159,7 @@ my $unknown_target = App::Sqitch::Target->new( ); throws_ok { $CLASS->load({ sqitch => $sqitch, target => $unknown_target }) } 'App::Sqitch::X', 'Should die on unknown target'; -is $@->message, 'Unable to load App::Sqitch::Engine::nonexistent', +is $@->message, __x('Unknown engine: {engine}', engine => 'nonexistent'), 'Should get load error message'; like $@->previous_exception, qr/\QCan't locate/, 'Should have relevant previoius exception'; @@ -180,7 +180,7 @@ my $bad_target = App::Sqitch::Target->new( ); throws_ok { $CLASS->load({ sqitch => $sqitch, target => $bad_target }) } 'App::Sqitch::X', 'Should die on bad engine module'; -is $@->message, 'Unable to load App::Sqitch::Engine::bad', +is $@->message, __x('Unknown engine: {engine}', engine => 'bad'), 'Should get another load error message'; like $@->previous_exception, qr/^LOL BADZ/, 'Should have relevant previoius exception from the bad module'; diff --git a/t/x.t b/t/x.t index dbd5778e2..6d9f7962e 100644 --- a/t/x.t +++ b/t/x.t @@ -45,19 +45,34 @@ is $x->message, 'OMFG!', 'The message should have been passed'; is $x->exitval, 2, 'Exit val should again be 2'; is $x->previous_exception, 'Yo dawg', 'Previous exception should have been passed'; +is $x->as_string, join("\n", + $x->message, + $x->previous_exception, + $x->stack_trace +), 'Stringification should work'; + +is $x->as_string, "$x", 'Stringification should work'; + +is $x->details_string, join("\n", + $x->previous_exception, + $x->stack_trace +), 'Details string should work'; throws_ok { hurl {ident => 'blah', message => 'OMFG!', exitval => 1} } $CLASS; isa_ok $x = $@, $CLASS, 'Thrown object'; is $x->message, 'OMFG!', 'The params should have been passed'; is $x->exitval, 1, 'Exit val should be 1'; -is $x->as_string, join("\n", grep { defined } +is $x->as_string, join("\n", $x->message, - $x->previous_exception, $x->stack_trace ), 'Stringification should work'; is $x->as_string, "$x", 'Stringification should work'; +is $x->details_string, join("\n", + $x->stack_trace +), 'Details string should work'; + # Do some actual exception handling. try { hurl io => 'Cannot open file';