perl 5.8.8 syslog tests failing on MacOS X (sometimes)

Mark Blackman mark at blackmans.org
Fri Dec 15 17:32:07 GMT 2006


Edmund von der Burg wrote:
> This is odd - and I think I know the cause but I want to check if
> anyone else has seen it:
> 
> evdb at cindy ~/cdb/ext/build/perl-5.8.8/t $ ./perl harness
> ../ext/Sys/Syslog/t/syslog.t
> ../ext/Sys/Syslog/t/syslog....ok
>        50/119 skipped: various reasons
> All tests successful, 50 subtests skipped.
> Files=1, Tests=119,  1 wallclock secs ( 0.07 cusr +  0.03 csys =  0.10 CPU)
> 
> And then again a few seconds later:
> 
> evdb at cindy ~/cdb/ext/build/perl-5.8.8/t $ ./perl harness
> ../ext/Sys/Syslog/t/syslog.t
> ../ext/Sys/Syslog/t/syslog....ok 1/119
> ../ext/Sys/Syslog/t/syslog....NOK 83#   Failed test 'syslog() called
> with level 'info''
> #   in ../ext/Sys/Syslog/t/syslog.t at line 108.
> #          got: 'no connection to syslog available
> #       - udp connect: nobody listening at
> ../ext/Sys/Syslog/t/syslog.t line 107# '
> #     expected: ''
> 
> #   Failed test 'syslog() should return true: '0''
> ../ext/Sys/Syslog/t/syslog....NOK 84#   in
> ../ext/Sys/Syslog/t/syslog.t at line 109.
> 
> #   Failed test 'syslog() called with level 'info''
> ../ext/Sys/Syslog/t/syslog....NOK 85#   in
> ../ext/Sys/Syslog/t/syslog.t at line 113.
> #          got: 'no connection to syslog available
> #       - udp connect: nobody listening at
> ../ext/Sys/Syslog/t/syslog.t line 112# '
> #     expected: ''
> 
> #   Failed test 'syslog() should return true: '0''
> ../ext/Sys/Syslog/t/syslog....NOK 86#   in
> ../ext/Sys/Syslog/t/syslog.t at line 114.
> # Looks like you failed 4 tests of 119.
> ../ext/Sys/Syslog/t/syslog....dubious
>        Test returned status 4 (wstat 1024, 0x400)
> DIED. FAILED tests 83-86
>        Failed 4/119 tests, 96.64% okay (less 38 skipped tests: 77
> okay, 64.71%)Failed Test                  Stat Wstat Total Fail
> Failed  List of Failed
> ------------------------------------------------------------------------------- 
> 
> ../ext/Sys/Syslog/t/syslog.t    4  1024   119    4   3.36%  83-86
> 38 subtests skipped.
> Failed 1/1 test scripts, 0.00% okay. 4/119 subtests failed, 96.64% okay.
> 
> 
> the test works / fails in roughly the same proportion.
> 
> My guess is that the tests should always be skipped, but that
> occasionally the error being returned is not recognized as valid: ie
> the 'udp connect' bit is unexpected.
> 
> Anyone confirm / deny this?

confirmed, but I suspect it's because your Mac is too fast (as is mine).

1) syslogd on OS X isn't listening on a UDP port by default,
so the Sys::Syslog tests shouldn't be testing UDP.

2) Sys::Syslog fails to detect this state (and consequently skip
tests) because it's not waiting long enough (some of the time) to hear 
the ICMP 'udp port 514 unreachable' message come back when it tests the
connection.

I'd guess your Mac happens to be just fast enough between the 
'_syslog_send_socket' and 'connection_ok' calls below, that it misses
the ICMP port unreachable packet (some of the time) and so it continues
attempts to test the UDP syslog functionality erroneously.

     880     # We want to check that the UDP connect worked. However the 
only
     881     # way to do that is to send a message and see if an ICMP is 
returned
     882     _syslog_send_socket("");
     883     if (!connection_ok()) {
     884         push(@{$errs}, "udp connect: nobody listening");
     885         return 0;
     886     }

It takes about 25 microseconds for the ICMP message to come back
on the loopback interface on my machine, but clearly it could be
much longer for an external UDP listener. However, for the purposes
of testing using the loopback interface, I suppose sticking a short
sleep, ~1ms, between 880 and 881 is fine as a kludge. Ideally, 
Sys::SysLog would have a configurable timeout associated with UDP 
connection testing  to permit making the listener present/not-present 
decision somewhat more reliably. OTOH, you're not likely to be sending 
syslog messages to Timbuktu with any hope of receiving them, so I'd 
suggest a standard timeout of 1 second would cover most real-world 
cases, but might be too much for the common case. I've not yet
tested this theory.

Cheers,
Mark
> 
> If that is it I'll submit a patch and become immortal :)
> 
> Cheers,
>  Edmund.
> 
> 



More information about the london.pm mailing list