"Problem Messages" - what's happening?

[David Lee]

On Sun, 10 May 2009, Mark Sapiro wrote:

> On Sun, May 10, 2009 at 10:44:01AM +0100, Paul Hutchings wrote:
>> Hmm OK seeing a few of the below in my Postmaster inbox.
>>
>> Doing a grep of the logs shows this:
>>
>> May  9 17:03:19 relay postfix/cleanup[7749]: 8BE611FCC8:
>> message-id=<06A07D7DB16C417C8990A7FACEE37518 at Desktop>
>> May  9 17:09:19 relay MailScanner[7940]: Making attempt 2 at processing
>> message 8BE611FCC8.A5E8C
>> May  9 17:09:19 relay MailScanner[7940]: Expanding TNEF archive at
>> /var/spool/MailScanner/incoming/7940/8BE611FCC8.A5E8C/winmail.dat
> [...]
>> May  9 17:27:30 relay MailScanner[9522]: Warning: skipping message
>> 8BE611FCC8.A5E8C as it has been attempted too many times
>> May  9 17:27:30 relay MailScanner[9522]: Quarantined message
>> 8BE611FCC8.A5E8C as it caused MailScanner to crash several times
>> May  9 17:27:30 relay MailScanner[9522]: Saved entire message to
>> /var/spool/MailScanner/quarantine/20090509/8BE611FCC8.A5E8C
>
>
> I suspect the problem is the TNEF decoder is timing out trying to
> decode the TNEF (winmail.dat) part of the message. The part is likely
> corrupt.
>
> You could verify this by retrieving the message from the quarantine,
> saving the winmail.dat attachment and then trying to expand it with
> /usr/bin/tnef which is the default decoder.

To confirm the problem and possible workaround: I, too, have just started 
seeing a tiny number of such instances.  It recurred even of quiet 
machines.  But I don't think it is the timeout (at least, nor directly).

In my "MailScanner.conf" we have historically had:
    TNEF Expander  = internal

Quick fix: When I switched this to use the "/usr/bin/tnef" version, the 
emails (rescued from quarantine and replaced into the MS inbound queue) 
seemed to go through OK.  I got the correct setting from a ".rpmnew" file 
which seems to be:
    TNEF Expander  = /usr/bin/tnef --maxsize=100000000


A little deeper:  When I ran them through MS in debug mode (with TNEF 
setting "internal") I got:
    In Debugging mode, not forking...
    Trying to setlogsock(unix)
    Building a message batch to scan...
    Have a batch of 2 messages.
    Can't call method "path" on an undefined value at /usr/lib/MailScanner/MailScanner/TNEF.pm line 178.

Not the "Can't call ..." line.

The MS run took less than four seconds.  I had initially suspected TNEF 
timeout, but it seems to be something different, related to the "internal" 
setting of "TNEF Expander".

That 'Can't call method "path"...' doesn't appear in the "maillog" file 
(which, in retrospect, is a pity, because that would have been a more 
obvious clue to follow).

Anyway: summary:

1. Problem seems to coincide with "TNEF Expander = internal".  For 
end-users, using "/usr/bin/tnef ..." seems to be a workaround for the 
moment.

2. For those who sometimes look a little deeper in the "why", MS in 
'-debug' mode seems to indicate a perl coding error which doesn't get 
shown in the 'maillog' file.

Hope that helps.

-- 

:  David Lee                                I.T. Service          :
:  Senior Systems Programmer                Computer Centre       :
:  UNIX Team Leader                         Durham University     :
:                                           South Road            :
:  http://www.dur.ac.uk/t.d.lee/            Durham DH1 3LE        :
:  Phone: +44 191 334 2752                  U.K.                  :