Skip Menu |
 

This queue is for tickets about the Sys-Syslog CPAN distribution.

Report information
The Basics
Id: 35189
Status: resolved
Priority: 0/
Queue: Sys-Syslog

People
Owner: Nobody in particular
Requestors: david.verdin [...] cru.fr
Cc:
AdminCc:

Bug Information
Severity: (no value)
Broken in: (no value)
Fixed in: 0.25



Subject: Sys::Syslog fails for unknown reasons.
Date: Fri, 18 Apr 2008 16:56:09 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: David Verdin <david.verdin [...] cru.fr>
Download (untitled) / with headers
text/plain 4.5k
Hi, I am one of the developers of the mailing list manager Sympa (http://www.sympa.org). It is entirely written in perl. We recently added a control over our logs so that, if a log fail, the server administrator is warned. Some users updated their version of Sys:Syslog to the latest (0.24) and reported that they received a considerable amount of warning regarding failures to log with the error: syslog: invalid level/facility: info at /home/sympa/bin/Log.pm line 101 This also happens with the "notice" facility. No other facility is concerned. That's when we found that, sometimes, the xlate function of Sys::Syslog seems to be failing to return the correct value. It is hard to determine the exact causes, but I can describe the main symptoms: I added some traces in xlate: # xlate() # ----- # private function to translate names to numeric values # sub xlate { my($name) = @_; return $name+0 if $name =~ /^\s*\d+\s*$/; $name = uc $name; $name = "LOG_$name" unless $name =~ /^LOG_/; $name = "Sys::Syslog::$name"; # Can't have just eval { &$name } || -1 because some LOG_XXX may be zero. my $value = eval { no strict 'refs'; &$name }; open DUMP, ">>/tmp/out"; print DUMP "###########################################################\n"; print DUMP "name: $name\n"; print DUMP "value: $value\n"; print DUMP "error:$@\n"; close DUMP; $@ = ""; return defined $value ? $value : -1; } And this is some of the output I obtained when launchin the sympa.pl script (see attached file): ########################################################### name: Sys::Syslog::LOG_ERR value: 3 error: ########################################################### name: Sys::Syslog::LOG_INFO value: error:Bizarre copy of CODE in leavesub at /usr/lib/perl5/5.8.8/i386-linux-thread-multi/Sys/Syslog.pm line 474. ########################################################### name: Sys::Syslog::LOG_INFO value: error:Bizarre copy of CODE in leavesub at /usr/lib/perl5/5.8.8/i386-linux-thread-multi/Sys/Syslog.pm line 474. ########################################################### name: Sys::Syslog::LOG_ERR value: 3 error: ########################################################### name: Sys::Syslog::LOG_LOCAL5 value: 168 error: ########################################################### name: Sys::Syslog::LOG_INFO value: error:Bizarre copy of CODE in leavesub at /usr/lib/perl5/5.8.8/i386-linux-thread-multi/Sys/Syslog.pm line 474. ########################################################### name: Sys::Syslog::LOG_NOTICE value: 5 error: ########################################################### name: Sys::Syslog::LOG_LOCAL5 value: 168 error: ########################################################### name: Sys::Syslog::LOG_NOTICE value: 5 error: ########################################################### name: Sys::Syslog::LOG_LOCAL5 value: 168 error: ########################################################### name: Sys::Syslog::LOG_INFO value: error:Bizarre copy of CODE in leavesub at /usr/lib/perl5/5.8.8/i386-linux-thread-multi/Sys/Syslog.pm line 474. ########################################################### name: Sys::Syslog::LOG_NOTICE value: 5 error: ########################################################### name: Sys::Syslog::LOG_LOCAL5 value: 168 error: So this is the elements I have: 1- the error happens with "info" and "notice" log levels only; 2- The error is not systematic. in the previous output, some logs with the level "notice" work and other don't. 3- in Sympa, the logs are handled through a specialized module, Log.pm (attached) which is called in the Sympa dameons by the line "use Log;". This module imports Sys::syslog with the line "use Sys::Syslog;". 4- A simple script just calling ths syslog function doesn't give any bad result. The logs are performed without any problem. 5- It looks like the "eval { no strict 'refs'; &$name }" doesn't always work and it is probably related to the way we import the Syslog module. But I have no clue what exactly this line is supposed to do. I suppose that it returns the indice of the entry containing the value of the log level in the array corresponding to the "macros" export tag. Bu I must admit that what you wrote is far beyond my comprehension of perl. I really don't know what happens when you evaluates "&$name". So do you have any clue about what's happening and how it is possible that, in the same script, we can successively fail and succeed in recognizing the log level? Regards, -- David Verdin Comité réseau des universités
Download Log.pm
text/x-perl 13.3k

Message body is not shown because it is too large.

Download sympa.pl
text/x-perl 83.3k

Message body is not shown because it is too large.

Subject: Re: [rt.cpan.org #35189] Sys::Syslog fails for unknown reasons.
Date: Sat, 19 Apr 2008 01:37:19 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: Sébastien Aperghis-Tramoni <saper [...] cpan.org>
Download (untitled) / with headers
text/plain 4.8k
Hello, David Verdin wrote: Show quoted text
> I am one of the developers of the mailing list manager Sympa > (http://www.sympa.org). It is entirely written in perl. > We recently added a control over our logs so that, if a log fail, the > server administrator is warned. > > Some users updated their version of Sys:Syslog to the latest (0.24) > and > reported that they received a considerable amount of warning regarding > failures to log with the error: > > syslog: invalid level/facility: info at /home/sympa/bin/Log.pm line > 101
Hmm.. a problem is that there is nothing at line 101 that calls syslog (). I see 4 calls to syslog() in Log.pm, at lines 50, 51, 111 and 113. The faulty call is probably the one at line 111, but to be sure, could you re-run your program with Devel::SimpleTrace loaded? Or could you give me the steps to reproduce this problem? Show quoted text
> This also happens with the "notice" facility. No other facility is > concerned.
I don't understand why the LOG_INFO and LOG_NOTICE facilities fails, and why only these. They're both used in the tests so a problem with these should have been detected at this stage. Show quoted text
> That's when we found that, sometimes, the xlate function of > Sys::Syslog > seems to be failing to return the correct value. It is hard to > determine > the exact causes, but I can describe the main symptoms: > > I added some traces in xlate:[...] > And this is some of the output I obtained when launchin the sympa.pl > script (see attached file): > > ########################################################### > name: Sys::Syslog::LOG_INFO > value: > error:Bizarre copy of CODE in leavesub at > /usr/lib/perl5/5.8.8/i386-linux-thread-multi/Sys/Syslog.pm line 474.
Ah.. A "biazrre copy".. AIUI, it's typically the kind of error that indicate a small bug in Perl leaking to user code. Unfortunately, it quite hard to understand at my level. I'm trying to write a reduced snippet that could expose the same problem, alas with no luck for now. Here again, the same trace with Devel::SimpleTrace could provide more information. Show quoted text
> So this is the elements I have: > 1- the error happens with "info" and "notice" log levels only; > 2- The error is not systematic. in the previous output, some logs > with > the level "notice" work and other don't. > 3- in Sympa, the logs are handled through a specialized module, > Log.pm > (attached) which is called in the Sympa dameons by the line "use > Log;". > This module imports Sys::syslog with the line "use Sys::Syslog;".
This is fine per se but reading the module, and particularly the functions related to logging, I find them awfully complex just to wrap Sys::Syslog. I guess like they were written for old versions of this module. I also see you're using setlogsock(), which is now discouraged because Sys::Syslog now usually know better than the user how to send messages on the running system. (I see the actual value comes from user configuration, but haven't checked what is the default value. I would strongly suggest "native".) Show quoted text
> 4- A simple script just calling ths syslog function doesn't give any > bad result. The logs are performed without any problem. > 5- It looks like the "eval { no strict 'refs'; &$name }" doesn't > always > work and it is probably related to the way we import the Syslog > module. > But I have no clue what exactly this line is supposed to do. I suppose > that it returns the indice of the entry containing the value of the > log > level in the array corresponding to the "macros" export tag. Bu I must > admit that what you wrote is far beyond my comprehension of perl. I > really don't know what happens when you evaluates "&$name".
I am not the original author of Sys::Syslog, just the current maintainer. This module was originally written by Larry Wall, Tom Christiansen, and many other people. What this line does is using a symbolic reference, which are strongly discouraged and no allowed under "use strict". Hence the "no strict 'refs'" inside the eval. It's a ugly hack, but I don't know how to replace it with a less exotic code. Show quoted text
> So do you have any clue about what's happening and how it is possible > that, in the same script, we can successively fail and succeed in > recognizing the log level?
As I said, currently, I have no idea why you see failures with (and only with) the LOG_INFO and the LOG_NOTICE facilities. Another thing you may try is to use this version of xlate(): sub xlate { my($name) = @_; return $name+0 if $name =~ /^\s*\d+\s*$/; $name = uc $name; $name = "LOG_$name" unless $name =~ /^LOG_/; $name = "Sys::Syslog::$name"; # Can't have just eval { &$name } || -1 because some LOG_XXX may be zero. local $@; my $value = eval { no strict 'refs'; &$name }; return defined $value ? $value : -1; } FYI, the line that resets $@ was added in version 0.22 while trying to address CPAN-RT#29875 -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.
Subject: Re: [rt.cpan.org #35189] Sys::Syslog fails for unknown reasons.
Date: Sun, 20 Apr 2008 03:59:43 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: Sébastien Aperghis-Tramoni <saper [...] cpan.org>
Download (untitled) / with headers
text/plain 366b
Hello, I made several eval()-related changes in the code, and even chainsawed the one in xlate(), so there is a good possibility that the problem seen with Sympa will disappear. Could you test with the development version of Sys::Syslog, available at svn:// svn.mongueurs.net/Sys-Syslog ? -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.
Subject: Re: [rt.cpan.org #35189] Sys::Syslog fails for unknown reasons.
Date: Wed, 23 Apr 2008 13:51:59 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: David Verdin <david.verdin [...] cru.fr>
Download (untitled) / with headers
text/plain 712b
This seem to be working like a charm to me! No more errors since this morning. When do you think it could be released as a new version? We need to inform our users about the fix. Anyway, thanks for this great work! Cheers, David Sébastien Aperghis-Tramoni via RT a écrit : Show quoted text
> <URL: http://rt.cpan.org/Ticket/Display.html?id=35189 > > > Hello, > > I made several eval()-related changes in the code, and even > chainsawed the one in xlate(), so there is a good possibility that > the problem seen with Sympa will disappear. Could you test with the > development version of Sys::Syslog, available at svn:// > svn.mongueurs.net/Sys-Syslog ? > > >
-- David Verdin Comité réseau des universités
Subject: Re: [rt.cpan.org #35189] Sys::Syslog fails for unknown reasons.
Date: Wed, 23 Apr 2008 15:17:04 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: Sébastien Aperghis-Tramoni <maddingue [...] free.fr>
Download (untitled) / with headers
text/plain 574b
David Verdin wrote: Show quoted text
> This seem to be working like a charm to me! No more errors since this > morning. > When do you think it could be released as a new version? We need to > inform our users about the fix.
Given there are already three bugfixes in the current devel version, I consider it a good time to make a release. If tests pass on all the combination of Perl/OS I have access to, I'll make a release before the end of the week. Show quoted text
> Anyway, thanks for this great work!
You're welcome. Best Regards -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.
Subject: Re: [rt.cpan.org #35189] Sys::Syslog fails for unknown reasons.
Date: Sun, 8 Jun 2008 03:09:54 +0200
To: bug-Sys-Syslog [...] rt.cpan.org
From: Sébastien Aperghis-Tramoni <maddingue [...] free.fr>
Download (untitled) / with headers
text/plain 130b
This issue is fixed in version 0.25. Thanks for your report. -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.


This service is sponsored and maintained by Best Practical Solutions and runs on Perl.org infrastructure.

Please report any issues with rt.cpan.org to rt-cpan-admin@bestpractical.com.