Amavisd logging question

[Bill Landry]

On 3/8/2011 10:28 AM, Bill Landry wrote:
> On 3/8/2011 6:57 AM, Mark Martinec wrote:
>> Bill,
>>
>>>>> I have been noticing for quite some time that amavisd-new logs test
>>>>> results messages to the maillog differently at time. For example:
>>>>>
>>>>> Feb 27 14:22:06 mail amavis[27931]: (27931-08) Passed CLEAN
>>>>> Feb 27 14:22:56 mail ch4-03611-04)[3611]: (03611-04) Passed CLEAN
>>>>>
>>>>> These are 2 different message that amavisd-new tested and reported to
>>>>> the maillog as "Passed CLEAN". However, notice that the first log
>>>>> entry
>>>>> clearly shows it came from "amavis", but the second log entry show it
>>>>> came from "ch4-03611-04)". Note that there is also a closing ")" is
>>>>> the
>>>>> second log entry but no opening "(".
>>>>>
>>>>> Any ideas why this is happening and what I can do to fix it? I am
>>>>> currently running amavisd-new-2.6.4 (20090625).
>>>>
>>>> What syslog variant are you using?
>>>> Looks like part of a process name ($0) ends up as a syslog ident.
>>
>>> I'm running Fedora 12:
>>> Linux mail.inetmsg.com 2.6.32.26-175.fc12.i686.PAE #1 SMP Wed Dec 1
>>> 21:45:50 UTC 2010 i686 athlon i386 GNU/Linux
>>> rsyslogd 4.4.2, compiled with: [...]
>>
>> I just came across a note in the syslog(3) man page on Linux:
>>
>> The argument 'ident' in the call of openlog() is probably stored as-is.
>> Thus, if the string it points to is changed, syslog() may start
>> prepending
>> the changed string, and if the string it points to ceases to exist,
>> the results
>> are undefined.
>>
>> Perhaps using a static variable would help, in case the Unix::Syslog
>> module does not cope with this detail.
>>
>> Could you please try the attached patch for 2.6.4 (same for 2.7.0).
>
> Mark, I've applied the patch and so far things are looking good. Usually
> I see about 500 of these "Mar 8 04:26:36 mail ch25-04407-25)" type
> entries in the maillog per day, so I'll report back tomorrow on whether
> the patched resolved this or not.

Well, it looks like it got better, only about 100 of these "ch..." type 
entries in the past 24 hours.  Here is a sample from this afternoon:

Mar  9 14:07:51 mail ch20-21366-20)[21366]: (21366-20) Passed SPAM...
Mar  9 14:22:09 mail ch21-21366-21)[21366]: (21366-21) Passed CLEAN...
Mar  9 14:27:30 mail ch22-21366-22)[21366]: (21366-22) Passed SPAM...

Thanks,

Bill