SA Bugzilla – Bug 6028
[review] Logger in infinite loop when logging encounters an error
Last modified: 2009-01-07 02:20:19 UTC
I'm opening this PR to explain my change r724958. The immediate problem the change solves is that a command-line 'spamassassin -D' when piping its stderr and stdout into another program like more(1) or less(1) can enter an infinite loop when a pipe breaks. In my particular case I admit the problem was caused by my addition of a call to 'warn' in Logger::Stderr::log_message, so if print failed a warn was called, which was intercepted by a __WARN__ handler and log_message called again. Several solutions come to mind: - ban calling warn or die or dbg from any routine that may be called from Logger::log_message. That is doable, but requires some discipline, and if a caller supplies his own logging modules we still have no control over it; - override __WARN__ and __DIE__ handlers within Logger::log_message - or like I did, add a flag (poor man semaphore) to protect the inside of Logger::log_message from re-entering. Probably the #2 is cleanest, but I thought testing and flipping a single boolean scalar is the cheapest, so I chose #3. I also added a: local $SIG{PIPE} = 'IGNORE'; into Logger::Stderr::log_message to prevent broken pipe signalling, but I'm now considering reverting that change because is is not particularly lightweight, involving several system service calls. I see that sa-learn.raw and spamassassin.raw already neutralize the PIPE signal, so it is unnecessary to do it again in logger, although I'm not sure about other callers (spamd, mass-check, third-party code).
(In reply to comment #0) > I'm opening this PR to explain my change r724958. > > The immediate problem the change solves is that a command-line > 'spamassassin -D' when piping its stderr and stdout into another > program like more(1) or less(1) can enter an infinite loop > when a pipe breaks. > > In my particular case I admit the problem was caused by my > addition of a call to 'warn' in Logger::Stderr::log_message, > so if print failed a warn was called, which was intercepted > by a __WARN__ handler and log_message called again. > > Several solutions come to mind: > - ban calling warn or die or dbg from any routine that may be > called from Logger::log_message. That is doable, but requires > some discipline, and if a caller supplies his own logging > modules we still have no control over it; > - override __WARN__ and __DIE__ handlers within Logger::log_message > - or like I did, add a flag (poor man semaphore) to protect > the inside of Logger::log_message from re-entering. > > Probably the #2 is cleanest, but I thought testing and flipping > a single boolean scalar is the cheapest, so I chose #3. cool, fine by me. +1 Thanks for the explanation! > I also added a: > local $SIG{PIPE} = 'IGNORE'; > into Logger::Stderr::log_message to prevent broken pipe signalling, > but I'm now considering reverting that change because is is not > particularly lightweight, involving several system service calls. > I see that sa-learn.raw and spamassassin.raw already neutralize > the PIPE signal, so it is unnecessary to do it again in logger, > although I'm not sure about other callers (spamd, mass-check, > third-party code). I agree that reverting it would be best. The callers need to monitor the status of SIGPIPE, imo; it's not appropriate for the logging code to do it, and as you note, it imposes a performance penalty.
> > I also added a: > > local $SIG{PIPE} = 'IGNORE'; > > into Logger::Stderr::log_message to prevent broken pipe signalling, > > but I'm now considering reverting that change ... > > I agree that reverting it would be best. The callers need to monitor the > status of SIGPIPE, imo; it's not appropriate for the logging code to do it, > and as you note, it imposes a performance penalty. Ok, done that. $ svn -m 'Logger/Stderr.pm: remove expensive neutralization of $SIG{PIPE} (bug 6028, partially reverting r724958)' ci Sending lib/Mail/SpamAssassin/Logger/Stderr.pm Committed revision 725664.
Ok, so this is fixed now in 3.3. Do I just close this PR, or does it need voting?
(In reply to comment #3) > Ok, so this is fixed now in 3.3. > Do I just close this PR, or does it need voting? just close. hey, I'll do it for you since I'm here anyway ;)