diff --git a/ChangeLog.md b/ChangeLog.md index b8e2766..d0ca95c 100644 --- a/ChangeLog.md +++ b/ChangeLog.md @@ -13,6 +13,8 @@ repository history](https://github.com/ddclient/ddclient/commits/master). * The default web service for `--webv4` and `--webv6` has changed from Google Domains (which is shutting down) to ipify. [5b104ad1](https://github.com/ddclient/ddclient/commit/5b104ad116c023c3760129cab6e141f04f72b406) + * All log messages are now written to STDERR, not a mix of STDOUT and STDERR. + [#676](https://github.com/ddclient/ddclient/pull/676) ### New features @@ -36,6 +38,9 @@ repository history](https://github.com/ddclient/ddclient/commits/master). [#639](https://github.com/ddclient/ddclient/pull/639) * Updated sample systemd service unit file to improve logging in the systemd journal. [#669](https://github.com/ddclient/ddclient/pull/669) + * The second and subsequent lines in a multi-line log message are now prefixed + with a `|` character. + [#676](https://github.com/ddclient/ddclient/pull/676) ### Bug fixes diff --git a/Makefile.am b/Makefile.am index 6412ede..9503c04 100644 --- a/Makefile.am +++ b/Makefile.am @@ -68,6 +68,7 @@ handwritten_tests = \ t/is-and-extract-ipv4.pl \ t/is-and-extract-ipv6.pl \ t/is-and-extract-ipv6-global.pl \ + t/logmsg.pl \ t/parse_assignments.pl \ t/skip.pl \ t/ssl-validate.pl \ diff --git a/ddclient.in b/ddclient.in index 84f7863..f6bf5ae 100755 --- a/ddclient.in +++ b/ddclient.in @@ -125,8 +125,8 @@ if ($program =~ /test/i) { $savedir = 'URL'; } -my $msgs = ''; -my $last_msgs = ''; +our $emailbody = ''; +my $last_emailbody = ''; ## If run as *d (e.g., ddclientd) then daemonize by default (but allow ## flags and options to override). @@ -2311,19 +2311,19 @@ sub sendmail { if (opt('mail-failure') && ($result ne 'OK' && $result ne '0')) { $recipients = opt('mail-failure'); } - if ($msgs && $recipients && $msgs ne $last_msgs) { + if ($emailbody && $recipients && $emailbody ne $last_emailbody) { pipecmd("sendmail -oi $recipients", "To: $recipients", "Subject: status report from $program\@$hostname", "\r\n", - $msgs, + $emailbody, "", - "regards,", + "-- ", # https://en.wikipedia.org/wiki/Signature_block#Standard_delimiter " $program\@$hostname (version $version)" ); } - $last_msgs = $msgs; - $msgs = ''; + $last_emailbody = $emailbody; + $emailbody = ''; } ###################################################################### ## split_by_comma @@ -2382,50 +2382,55 @@ sub ynu { return $undef; } ###################################################################### -## msg -## debug -## warning -## fatal +## Logging ###################################################################### -my $_in_msg = 0; -sub _msg { - my $fh = shift; - my $log = shift; - my $prefix = shift; - my $format = shift; - my $buffer = sprintf $format, @_; +my $_in_logmsg = 0; +sub logmsg { + my %args = ( + msg => '', + pfx => '', + fh => *STDERR, + email => 0, # If truthy, the message is also included in the next email. + (@_ % 2) ? (msg => pop) : (), + @_, + ); + my $buffer = $args{msg}; chomp($buffer); - $prefix = sprintf "%-9s ", $prefix if $prefix; + my $prefix = $args{pfx}; + $prefix = sprintf "%-9s ", $prefix if $prefix; if ($file) { $prefix .= "file $file"; $prefix .= ", line $lineno" if $lineno; - $prefix .= ": "; + $prefix .= ": "; } if ($prefix) { $buffer = "$prefix$buffer"; + $prefix =~ s/ $/| /; $buffer =~ s/\n/\n$prefix/g; } $buffer .= "\n"; - print $fh $buffer; + print({$args{fh}} $buffer); - $msgs .= $buffer if $log; - if ($log && !$_in_msg) { - ++$_in_msg; # avoid infinite recursion if logger calls _msg - logger($buffer); - --$_in_msg; + if ($args{email}) { + $emailbody .= $buffer; + if (!$_in_logmsg) { + ++$_in_logmsg; # avoid infinite recursion if logger calls logmsg + logger($buffer); + --$_in_logmsg; + } } - } -sub msg { _msg(*STDOUT, 0, '', @_); } -sub verbose { _msg(*STDOUT, 1, @_) if opt('verbose'); } -sub info { _msg(*STDOUT, 1, 'INFO:', @_) if opt('verbose'); } -sub debug { _msg(*STDOUT, 0, 'DEBUG:', @_) if opt('debug'); } -sub debug2 { _msg(*STDOUT, 0, 'DEBUG:', @_) if opt('debug') && opt('verbose'); } -sub warning { _msg(*STDERR, 1, 'WARNING:', @_); } -sub fatal { _msg(*STDERR, 1, 'FATAL:', @_); sendmail(); exit(1); } -sub success { _msg(*STDOUT, 1, 'SUCCESS:', @_); } -sub failed { _msg(*STDERR, 1, 'FAILED:', @_); $result = 'FAILED'; } +sub _logmsg_fmt { return (@_ > 1) ? sprintf(shift, @_) : shift; } +sub msg { logmsg( _logmsg_fmt(@_)); } +sub verbose { logmsg(email => 1, pfx => shift, _logmsg_fmt(@_)) if opt('verbose'); } +sub info { logmsg(email => 1, pfx => 'INFO:', _logmsg_fmt(@_)) if opt('verbose'); } +sub debug { logmsg( pfx => 'DEBUG:', _logmsg_fmt(@_)) if opt('debug'); } +sub debug2 { logmsg( pfx => 'DEBUG:', _logmsg_fmt(@_)) if opt('debug') && opt('verbose'); } +sub warning { logmsg(email => 1, pfx => 'WARNING:', _logmsg_fmt(@_)); } +sub fatal { logmsg(email => 1, pfx => 'FATAL:', _logmsg_fmt(@_)); sendmail(); exit(1); } +sub success { logmsg(email => 1, pfx => 'SUCCESS:', _logmsg_fmt(@_)); } +sub failed { logmsg(email => 1, pfx => 'FAILED:', _logmsg_fmt(@_)); $result = 'FAILED'; } sub prettytime { return scalar(localtime(shift)); } sub prettyinterval { diff --git a/t/logmsg.pl b/t/logmsg.pl new file mode 100644 index 0000000..347a69e --- /dev/null +++ b/t/logmsg.pl @@ -0,0 +1,139 @@ +use Test::More; +SKIP: { eval { require Test::Warnings; } or skip($@, 1); } +eval { require 'ddclient'; } or BAIL_OUT($@); + +{ + my $output; + open(my $fh, '>', \$output); + local *STDERR = $fh; + ddclient::logmsg('to STDERR'); + close($fh); + is($output, "to STDERR\n", 'logs to STDERR by default'); +} + +{ + my $output; + open(my $fh, '>', \$output); + ddclient::logmsg(fh => $fh, 'to file handle'); + close($fh); + is($output, "to file handle\n", 'logs to provided file handle'); +} + +my @test_cases = ( + { + desc => 'adds a newline', + args => ['xyz'], + want => "xyz\n", + }, + { + desc => 'removes one trailing newline (before adding a newline)', + args => ["xyz \n\t\n\n"], + want => "xyz \n\t\n\n", + }, + { + desc => 'accepts msg keyword parameter', + args => [msg => 'xyz'], + want => "xyz\n", + }, + { + desc => 'msg keyword parameter trumps message parameter', + args => [msg => 'kw', 'pos'], + want => "kw\n", + }, + { + desc => 'msg keyword parameter trumps message parameter', + args => [msg => 'kw', 'pos'], + want => "kw\n", + }, + { + desc => 'email appends to email body', + args => [email => 1, 'foo'], + init_email => "preexisting message\n", + want_email => "preexisting message\nfoo\n", + want => "foo\n", + }, + { + desc => 'single-line prefix', + args => [pfx => 'PFX:', 'foo'], + want => "PFX: foo\n", + }, + { + desc => 'multi-line prefix', + args => [pfx => 'PFX:', "foo\nbar"], + want => "PFX: foo\nPFX: | bar\n", + }, + { + desc => 'single-line long prefix', + args => [pfx => 'VERY LONG PREFIX:', 'foo'], + want => "VERY LONG PREFIX: foo\n", + }, + { + desc => 'multi-line long prefix', + args => [pfx => 'VERY LONG PREFIX:', "foo\nbar"], + want => "VERY LONG PREFIX: foo\nVERY LONG PREFIX:| bar\n", + }, + { + desc => 'single line, no prefix, file', + args => ['foo'], + file => 'name', + want => "file name: foo\n", + }, + { + desc => 'single line, no prefix, file, and line number', + args => ['foo'], + file => 'name', + lineno => 42, + want => "file name, line 42: foo\n", + }, + { + desc => 'single line, prefix, file, and line number', + args => [pfx => 'PFX:', 'foo'], + file => 'name', + lineno => 42, + want => "PFX: file name, line 42: foo\n", + }, + { + desc => 'multiple lines, prefix, file, and line number', + args => [pfx => 'PFX:', "foo\nbar"], + file => 'name', + lineno => 42, + want => "PFX: file name, line 42: foo\nPFX: file name, line 42:| bar\n", + }, +); + +for my $tc (@test_cases) { + subtest $tc->{desc} => sub { + $tc->{wantemail} //= ''; + my $output; + open(my $fh, '>', \$output); + $ddclient::emailbody = $tc->{init_email} // ''; + local $ddclient::file = $tc->{file} // ''; + $ddclient::file if 0; # suppress spurious warning "Name used only once: possible typo" + local $ddclient::lineno = $tc->{lineno} // ''; + $ddclient::lineno if 0; # suppress spurious warning "Name used only once: possible typo" + ddclient::logmsg(fh => $fh, @{$tc->{args}}); + close($fh); + is($output, $tc->{want}, 'output text matches'); + is($ddclient::emailbody, $tc->{want_email} // '', 'email content matches'); + } +} + +{ + my $output; + open(my $fh, '>', \$output); + local *STDERR = $fh; + ddclient::msg('%%'); + close($fh); + is($output, "%%\n", 'single argument is printed directly, not via sprintf'); +} + +{ + my $output; + open(my $fh, '>', \$output); + local *STDERR = $fh; + ddclient::msg('%s', 'foo'); + close($fh); + is($output, "foo\n", 'multiple arguments are formatted via sprintf'); +} + +done_testing();