Merge pull request #1522 from uralm1/load_rexfile_test_and_fix

Fix #1521 lib/Rex/CLI.pm: Use $SIG{__WARN__} when loading Rexfile instead of stderr redirection

Author: ferki

ChangeLog

@@ -5,6 +5,7 @@ Revision history for Rex
 
  [BUG FIXES]
  - Detect invalid hostgroup expressions
+ - Prevent empty log lines upon Rexfile warnings
 
  [DOCUMENTATION]
  - Clarify optional arguments of file commands
@@ -20,6 +21,8 @@ Revision history for Rex
  [NEW FEATURES]
 
  [REVISION]
+ - Fix handling of warnings during Rexfile loading
+ - Mask internal naming in Rexfile loading output
 
 1.13.4 2021-07-05 Ferenc Erki <[email protected]>
  [DOCUMENTATION]

MANIFEST.SKIP

@@ -28,7 +28,6 @@ vars\..*
 passwd
 upload
 .*\.conf
-.*\.log
 ^images
 projects
 Rex\-\d+.*

lib/Rex/CLI.pm

@@ -69,7 +69,7 @@ sub __run__ {
   %opts = Rex::Args->getopts;
 
   if ( $opts{'Q'} ) {
-    my ( $stdout, $stderr );
+    my $stdout;
     open( my $newout, '>', \$stdout );
     select $newout;
     close(STDERR);
@@ -744,14 +744,11 @@ sub load_rexfile {
       }
     };
 
-    my ( $stdout, $stderr, $default_stderr );
-    open $default_stderr, ">&", STDERR;
-
-    # we close STDERR here because we don't want to see the
-    # normal perl error message on the screen. Instead we print
-    # the error message in the catch-if below.
-    local *STDERR;
-    open( STDERR, ">>", \$stderr );
+    # we don't want to see the
+    # normal perl warning message on the screen. Instead we print
+    # the warning message in the catch-if below
+    my @warnings;
+    local $SIG{__WARN__} = sub { push @warnings, $_[0] };
 
     # we can't use $rexfile here, because if the variable contains dots
     # the perl interpreter try to load the file directly without using @INC
@@ -761,13 +758,19 @@ sub load_rexfile {
     # update %INC so that we can later use it to find the rexfile
     $INC{"__Rexfile__.pm"} = $rexfile;
 
-    # reopen STDERR
-    open STDERR, ">&", $default_stderr;
-
-    if ($stderr) {
-      my @lines = split( $/, $stderr );
+    if (@warnings) {
       Rex::Logger::info( "You have some code warnings:", 'warn' );
-      Rex::Logger::info( "\t$_",                         'warn' ) for @lines;
+      for (@warnings) {
+        chomp;
+
+        # remove /loader/.../ prefix before filename
+        s{/loader/[^/]+/}{}sxm;
+
+        # convert Rexfile to human-friendly name
+        s{__Rexfile__.pm}{Rexfile}msx;
+
+        Rex::Logger::info( "\t$_", 'warn' );
+      }
     }
 
     1;
@@ -781,6 +784,9 @@ sub load_rexfile {
     # we load the Rexfile via our custom code block.
     $e =~ s|/loader/[^/]+/||smg;
 
+    # convert Rexfile to human-friendly name
+    $e =~ s{__Rexfile__.pm}{Rexfile}msx;
+
     my @lines = split( $/, $e );
 
     Rex::Logger::info( "Compile time errors:", 'error' );

lib/Rex/Logger.pm

@@ -60,11 +60,6 @@ Setting this variable to 1 will enable debug logging.
 
 our $debug = 0;
 
-# we store the default handle to stderr
-# so that we can restore the handle inside the logging functions
-my $DEFAULT_STDERR;
-open $DEFAULT_STDERR, ">&", STDERR;
-
 =item $silent
 
 If you set this variable to 1 nothing will be logged.
@@ -125,9 +120,6 @@ sub info {
 
   return if $silent;
 
-  local *STDERR;
-  open STDERR, ">&", $DEFAULT_STDERR;
-
   if ( defined($type) ) {
     $msg = format_string( $msg, uc($type) );
   }
@@ -186,9 +178,6 @@ sub debug {
   return if $silent;
   return unless $debug;
 
-  local *STDERR;
-  open STDERR, ">&", $DEFAULT_STDERR;
-
   $msg = format_string( $msg, "DEBUG" );
 
   # workaround for windows Sys::Syslog behaviour on forks

t/load_rexfile.t

@@ -0,0 +1,81 @@
+#!/usr/bin/env perl
+
+use 5.010001;
+use strict;
+use warnings;
+use autodie;
+
+our $VERSION = '9999.99.99_99'; # VERSION
+
+use Test::More;
+
+use File::Spec;
+use File::Temp;
+use Rex::CLI;
+use Rex::Commands::File;
+use Sub::Override;
+use Test::Output;
+
+$Rex::Logger::format   = '%l - %s';
+$Rex::Logger::no_color = 1;
+
+my $testdir      = File::Spec->join( 't', 'rexfiles' );
+my $rex_cli_path = $INC{'Rex/CLI.pm'};
+my $empty        = q();
+
+my ( $dh, $exit_was_called, $expected );
+
+my $override =
+  Sub::Override->new( 'Rex::CLI::exit' => sub { $exit_was_called = 1 } );
+
+my $logfile = File::Temp->new->filename;
+Rex::Config->set_log_filename($logfile);
+
+opendir $dh, $testdir;
+my @rexfiles = grep { !/[.]/msx } readdir $dh;
+closedir $dh;
+
+push @rexfiles, 'no_Rexfile';
+
+plan tests => scalar @rexfiles;
+
+for my $rexfile (@rexfiles) {
+  subtest "Testing with $rexfile" => sub {
+    $rexfile = File::Spec->join( $testdir, $rexfile );
+
+    _setup_test($rexfile);
+
+    output_is { Rex::CLI::load_rexfile($rexfile); } $expected->{stdout},
+      $expected->{stderr}, 'Expected console output';
+
+    is( $exit_was_called, $expected->{exit}, 'Expected exit status' );
+    is( cat($logfile),    $expected->{log},  'Expected log content' );
+  };
+}
+
+sub _setup_test {
+  my $rexfile = shift;
+
+  Rex::TaskList->create->clear_tasks();
+
+  $exit_was_called = 0;
+
+  $expected->{exit} = $rexfile =~ qr{fatal}ms ? 1 : 0;
+
+  for my $extension (qw(log stdout stderr)) {
+    my $file            = "$rexfile.$extension";
+    my $default_content = $extension eq 'stderr' ? $expected->{log} : $empty;
+
+    $expected->{$extension} = -r $file ? cat($file) : $default_content;
+    $expected->{$extension} =~ s{%REX_CLI_PATH%}{$rex_cli_path}msx;
+  }
+
+  # reset log
+  open my $fh, '>', $logfile;
+  close $fh;
+
+  # reset require
+  delete $INC{'__Rexfile__.pm'};
+
+  return;
+}

t/rexfiles/Rexfile_fatal

@@ -0,0 +1,5 @@
+use Rex;
+
+abc
+
+task 'test', sub { };

t/rexfiles/Rexfile_fatal.log

@@ -0,0 +1,5 @@
+ERROR - Compile time errors:
+ERROR - 	syntax error at Rexfile line 5, near "abc
+ERROR - 	
+ERROR - 	task "
+ERROR - 	Compilation failed in require at %REX_CLI_PATH% line 756.

t/rexfiles/Rexfile_fatal_print

@@ -0,0 +1,11 @@
+use Rex;
+
+print STDERR "This is STDERR message\n";
+print STDOUT "This is STDOUT message\n";
+
+abc
+
+print STDERR "This is STDERR message\n";
+print STDOUT "This is STDOUT message\n";
+
+task 'test', sub { };

t/rexfiles/Rexfile_fatal_print.log

@@ -0,0 +1,5 @@
+ERROR - Compile time errors:
+ERROR - 	syntax error at Rexfile line 8, near "abc
+ERROR - 	
+ERROR - 	print"
+ERROR - 	Compilation failed in require at %REX_CLI_PATH% line 756.

t/rexfiles/Rexfile_noerror

@@ -0,0 +1,3 @@
+use Rex;
+
+task 'test', sub { };

t/rexfiles/Rexfile_noerror_print

@@ -0,0 +1,6 @@
+use Rex;
+
+print STDERR "This is STDERR message\n";
+print STDOUT "This is STDOUT message\n";
+
+task 'test', sub { };

t/rexfiles/Rexfile_noerror_print.stderr

@@ -0,0 +1 @@
+This is STDERR message

t/rexfiles/Rexfile_noerror_print.stdout

@@ -0,0 +1 @@
+This is STDOUT message

t/rexfiles/Rexfile_warnings

@@ -0,0 +1,8 @@
+use Rex;
+
+use warnings;
+
+warn 'This is warning';
+my $warn = 'warn' . undef;
+
+task 'test', sub { };

t/rexfiles/Rexfile_warnings.log

@@ -0,0 +1,3 @@
+WARN - You have some code warnings:
+WARN - 	This is warning at Rexfile line 5.
+WARN - 	Use of uninitialized value in concatenation (.) or string at Rexfile line 6.

t/rexfiles/Rexfile_warnings_print

@@ -0,0 +1,11 @@
+use Rex;
+
+use warnings;
+
+warn 'This is warning';
+my $warn = 'warn' . undef;
+
+print STDERR "This is STDERR message\n";
+print STDOUT "This is STDOUT message\n";
+
+task 'test', sub { };

t/rexfiles/Rexfile_warnings_print.log

@@ -0,0 +1,3 @@
+WARN - You have some code warnings:
+WARN - 	This is warning at Rexfile line 5.
+WARN - 	Use of uninitialized value in concatenation (.) or string at Rexfile line 6.

t/rexfiles/Rexfile_warnings_print.stderr

@@ -0,0 +1,4 @@
+This is STDERR message
+WARN - You have some code warnings:
+WARN - 	This is warning at Rexfile line 5.
+WARN - 	Use of uninitialized value in concatenation (.) or string at Rexfile line 6.

t/rexfiles/Rexfile_warnings_print.stdout

@@ -0,0 +1 @@
+This is STDOUT message

t/rexfiles/no_Rexfile.log

@@ -0,0 +1,4 @@
+WARN - No Rexfile found.
+WARN - Create a file named 'Rexfile' in this directory,
+WARN - or specify the file you want to use with:
+WARN -    rex -f file_to_use task_to_run