| Subject: | Use the default socket timeout on GNU/kFreeBSD too |
We're seeing a non-deterministic Sys-Syslog-0.27 test failure
when building Perl 5.12.4 on Debian GNU/kFreeBSD (see
http://www.debian.org/ports/kfreebsd-gnu/ for information on this Debian
port.) I have also been able to reproduce it on FreeBSD 8.2-RELEASE.
The Debian bug log can be found at http://bugs.debian.org/627821 .
Symptoms include
# Failed test '[inet] syslog() should return true: '0''
# at t/syslog.t line 166.
cpan/Sys-Syslog/t/syslog.......................................FAILED
at test 142
and
# Failed test '[inet] syslog() called with level 'info' (string)'
# at t/syslog.t line 165.
# got: 'no connection to syslog available
# - getservbyname failed for syslog/tcp and syslogng/tcp
# - udp connect: nobody listening at t/syslog.t line 164
# '
# expected: ''
cpan/Sys-Syslog/t/syslog.......................................FAILED
at test 141
In a nutshell, the problem seems to be that doing openlog() on a udp
socket does not fail reliably on the FreeBSD kernel when syslogd
isn't configured for UDP reception. While this mainly happens on a
multiprocessor system, I've been able to trigger it on a uniprocessor
system too. (All tested on KVM virtual machines FWIW.)
I think this is the infamous MacOS X timeout issue revisited; Darwin is
FreeBSD under the hood AFAIK. I suppose the immediate fix is to set the
connection_ok() timeout when $^O matches /darwin|gnukfreebsd/.
(As I mentioned, I've also reproduced this on a FreeBSD-8.2 virtual
machine, so /darwin|freebsd/ might be more correct, but a more
conservative approach might be in order until there's a report from a
real FreeBSD user too.)
However, you might want to revisit the timeout value; the london.pm post
referenced in the code mentioned a measurement of 25 microseconds and
suggested a delay of 1 millisecond, but you're using 250 milliseconds
which seems excessive and enough even for a human to notice. Perhaps
the suggested one millisecond would be better? Just 250 microseconds
fixes this completely in my setup FWIW.
Please note that this behaviour isn't visible on 0.28 or 0.29 because
changes to setlogsock() mask the behaviour there. I have filed separate
tickets ([rt.cpan.org #69986] and [rt.cpan.org #69992]) on those.
I'm attaching proposed patches for your convenience.
Thanks for your work on Sys-Syslog,
--
Niko Tyni ntyni@debian.org
| Subject: | 0001-Use-the-MacOS-X-socket-timeout-fix-on-Debian-GNU-kFr.patch |
From 1ebf50c63fc400230d0eef6e86f1391ee3314b41 Mon Sep 17 00:00:00 2001
From: Niko Tyni <ntyni@debian.org>
Date: Wed, 3 Aug 2011 22:01:53 +0300
Subject: [PATCH 1/2] Use the MacOS X socket timeout fix on Debian
GNU/kFreeBSD too
See http://bugs.debian.org/627821
It seems probable that all FreeBSD-based systems suffer from the
same issue, but err on the conservative side and only include
GNU/kFreeBSD for now.
---
Syslog.pm | 6 +++++-
1 files changed, 5 insertions(+), 1 deletions(-)
diff --git a/Syslog.pm b/Syslog.pm
index bc6752f..51ca74a 100644
--- a/Syslog.pm
+++ b/Syslog.pm
@@ -139,7 +139,11 @@ my @fallbackMethods = ();
# happy, the timeout is now zero by default on all systems
# except on OSX where it is set to 250 msec, and can be set
# with the infamous setlogsock() function.
-$sock_timeout = 0.25 if $^O =~ /darwin/;
+#
+# Update 2011-08: this issue is also been seen on multiprocessor
+# Debian GNU/kFreeBSD systems. See http://bugs.debian.org/627821
+
+$sock_timeout = 0.25 if $^O =~ /darwin|gnukfreebsd/;
# coderef for a nicer handling of errors
my $err_sub = $options{nofatal} ? \&warnings::warnif : \&croak;
--
1.7.5.4
| Subject: | 0002-Lower-the-MacOS-X-FreeBSD-ICMP-unreachable-timeout-t.patch |
From e8f4ab74ce32d4e46d552aee069c66cd80d8ee90 Mon Sep 17 00:00:00 2001
From: Niko Tyni <ntyni@debian.org>
Date: Wed, 3 Aug 2011 22:13:46 +0300
Subject: [PATCH 2/2] Lower the MacOS X / FreeBSD ICMP unreachable timeout to
1 ms
250 milliseconds seems to be excessive, the original suggestion in the
above london.pm message was one millisecond and the measured delay was
25 microseconds.
Use one millisecond to be on the safe side.
---
Syslog.pm | 7 ++++++-
1 files changed, 6 insertions(+), 1 deletions(-)
diff --git a/Syslog.pm b/Syslog.pm
index 51ca74a..8b7b187 100644
--- a/Syslog.pm
+++ b/Syslog.pm
@@ -142,8 +142,13 @@ my @fallbackMethods = ();
#
# Update 2011-08: this issue is also been seen on multiprocessor
# Debian GNU/kFreeBSD systems. See http://bugs.debian.org/627821
+#
+# Update 2011-08: 250 milliseconds seems to be excessive,
+# the original suggestion in the above london.pm message was one
+# millisecond and the measured delay was 25 microseconds.
+# Use one millisecond to be on the safe side.
-$sock_timeout = 0.25 if $^O =~ /darwin|gnukfreebsd/;
+$sock_timeout = 0.001 if $^O =~ /darwin|gnukfreebsd/;
# coderef for a nicer handling of errors
my $err_sub = $options{nofatal} ? \&warnings::warnif : \&croak;
--
1.7.5.4