[clamav-users] log representation

G.W. Haywood clamav at jubileegroup.co.uk
Wed Oct 23 10:08:55 EDT 2019


Hi there,

On Wed, 23 Oct 2019, Frans de Boer wrote:
> On 22-10-2019 22:33, G.W. Haywood via clamav-users wrote:
>> On Tue, 22 Oct 2019, Frans de Boer wrote:
>> 
>>> Does anybody knows how to make the log output of the ClamAV daemons the 
>>> same as normal log's. That is, with an ISO date, followed by host name, 
>>> program/daemon name and concluding with the real message.
>> 
>> That's normally done by syslog (or equivalent: rsyslog, syslog-ng, ...)
>> so if you tell the daemon to log via syslog it should be taken care of
>> for you.
>> 
> Nope, 0.102.0 for instance does not pass the program name. I only get the 
> '->' characters.

Below is the debug log from your mail as it came in today.  The lines
are very long I'm afraid, if your mail client does silly things with
them then they all begin with the date and time.  The line from the
clamd scan result is approximately in the middle.  This is 0.102rc.

8<--------------------------------------------------------------------------------------------------------------------------------------------
Oct 23 14:05:05 mail6 xm[18320]   x9ND4sM7022360:             xm_eoh_callback(): [192.34.61.247], [AS14061], return [SMFIS_CONTINUE]
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:                    xm_stats(): [192.34.61.247] +++++++ END EOH CALLBACK +++++++
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:       xm_body_callback(464)  : [192.34.61.247]  + chunk length: [1618]
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-Originating-Country: US
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-AS-Number: AS14061 ([DIGITALOCEAN, LLC] [US] [192.34.61.247])
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter insert (0): header: Received-SPF: pass (mail6.jubileegroup.co.uk: lists.clamav.net: 192.34.61.247 is authorized to use 'clamav-users-bounces at lists.clamav.net' in 'mfrom' identity (mechanism 'mx' matched) client-ip=192.34.61.247; helo=mailmanlists.network)
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-SPF-hello: pass ([mailmanlists.network]=[v=spf1 mx a ip4:192.34.61.247 ip6:2604:A880:400:D0::C0E:2001 ~all])\n\t( DNS lookups=[2] void lookups=[0])
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-SPF-mfrom: pass ([lists.clamav.net]=[v=spf1 mx a ip4:192.34.61.247 ip6:2604:A880:400:D0::C0E:2001 ~all])\n\t( DNS lookups=[2] void lookups=[0])
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:        xm_greylist_interval(): [192.34.61.247] Rejection rate is [ 310/ 726]=[ 42.70] percent for [AS14061]
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:        xm_eom_callback(464)  : [192.34.61.247] not greylisting WHITELISTED IP
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-Greylist-Delay: WHITELISTED IP [192.34.61.247], transport not delayed by extensible-milter-6.842
Oct 23 14:05:06 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-DKIM-auth: none ([2019-10-23 13:05:06Z mail6.jubileegroup.co.uk] [result=No DKIM signature found in message])
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], Connnecting to ClamAV daemon on [192.168.44.47:3313]...
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], Connnected to ClamAV daemon (version [ClamAV 0.102.0-rc/25597/Wed Oct  9 09:39:14 2019]
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], Attempting to send [4446] bytes to ClamAV daemon from entire_message...
Oct 23 14:05:06 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], Sent [4446] bytes to clamd...
Oct 23 14:05:07 tornado clamd[10873]: instream(192.168.44.25 at 59038): OK
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], clamd on IP [192.168.44.47] port [3313] replied [stream: OK]
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:               xm_scan(9600)  : [192.34.61.247], clamd on IP [192.168.44.47] port [3313] scanned [4446] bytes in [0.195] seconds (22.819 kbytes/sec), nothing found in entire_message
Oct 23 14:05:07 mail6 sm-mta[22360] x9ND4sM8022360: Milter add: header: X-Scanned-OK: extensible-milter version 6.842 using ClamAV version [ClamAV 0.102.0-rc/25597/Wed Oct  9 09:39:14 2019], clamd on IP [192.168.44.47] port [3313], [4446] bytes in [0.652s] at 2019-10-23 13:05:07Z
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:                  xm_scripts(): [192.34.61.247] [eom] [ 56] MATCH (CONTINUE) eval(reciprule at line [ 219]) time [0.056393s] [return "CONTINUE" if(!(xm_blacklisted_envfrom($priv_data))...]
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:             xm_eom_callback(): [192.34.61.247], [AS14061], return [SMFIS_CONTINUE]
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:                    xm_stats(): [192.34.61.247] +++++++ END EOM CALLBACK +++++++
Oct 23 14:05:07 mail6 sm-mta[22360] x9ND4sM8022360: --- 250 2.0.0 x9ND4sM8022360 Message accepted for delivery
Oct 23 14:05:07 mail6 sm-mta[22360] x9ND4sM9022360: <-- QUIT
Oct 23 14:05:07 mail6 sm-mta[22360] x9ND4sM9022360: --- 221 2.0.0 mail6.jubileegroup.co.uk closing connection
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:           xm_close_callback(): [192.34.61.247] now has [0] open connections to MTA
Oct 23 14:05:07 mail6 xm[18320]   x9ND4sM7022360:           xm_close_callback(): [192.34.61.247], [AS14061], return [IGNORED_BY_SENDMAIL] [52]
Oct 23 14:05:09 mail6 xm[18320]   x9ND4sM7022360:        xm_log_endex_message(): [192.34.61.247] +ENDEX US =AS14061 0m 14.51s connect,260 mailmanlists.network P clamav@
Oct 23 14:05:09 mail6 xm[18320]   x9ND4sM7022360:                    xm_stats(): [192.34.61.247] +++++++ END CLOSE CALLBACK +++++++
Oct 23 14:05:22 mail6 clamd[22369] on tornado: Pong
Oct 23 14:06:22 mail6 clamd[22412] on tornado: Pong
Oct 23 14:07:23 mail6 clamd[22430] on tornado: Pong
Oct 23 14:08:22 mail6 clamd[22448] on tornado: Pong
8<--------------------------------------------------------------------------------------------------------------------------------------------

I wonder if we should compare some configurations?

Below I give the relevant part of the configuration file for the clamd
daemon which logged the line in the above log extract which reads:

"Oct 23 14:05:07 tornado clamd[10873]: instream(192.168.44.25 at 59038): OK"

8<----------------------------------------------------------------------
# Use system logger (can work together with LogFile).
# Default: no
LogSyslog yes
# Specify the type of syslog messages - please refer to 'man syslog'
# for facility names.
# Default: LOG_LOCAL6
LogFacility LOG_MAIL
8<----------------------------------------------------------------------

Does that help?

I'm afraid the logging daemon configuration probably won't help you
because the logging server here happens to be running rsyslog.  If it
matters, the times are all BST (+0100).

-- 

73,
Ged.


More information about the clamav-users mailing list