[9.000][BUG] POP3 Antivirus Problem

Hi

the Antivirus scan has problems with the POP3 Connector. On a lot of Mails we got this kind of error:

2012:07:09-11:15:26 firewall-1 pop3proxy[5747]: Accepted client connection from 192.168.xx.xx for 80.64.xx.xx
2012:07:09-11:15:26 firewall-1 pop3proxy[5747]: ***@***.*** logged in
2012:07:09-11:15:29 firewall-1 pop3proxy[5606]: Fatal: Scan failed due to some weird reason
2012:07:09-11:15:51 firewall-1 pop3proxy[5747]: Unknown cssd response: 500 Internal Server Error
2012:07:09-11:15:51 firewall-1 pop3proxy[5747]: Fatal: Scan failed due to some weird reason
2012:07:09-11:15:51 firewall-1 pop3proxy[5839]: Accepted client connection from 192.168.xx.xx for 80.64.xx.xx


its not importend, if i use a single or a dual scan and its only on a small range of mails. The size is not importend, it can be a small or a large mail. 

The Outlook Error you can see on the Image attached.


Task '***x@***x.xx - Receiving' reported error (0x80042112): 'The following 
e-mail messages on the mail server cannot be downloaded. Contact your Internet
service provider (ISP) or mail administrator if you continue to receive this error.
1341575030.11369.mail.viennacix.com, S=10914773'


If i turn off the POP Antivirus Scanning, this Mails will be transfered to the Client.

The default engine is Sophos.

kind regards

Alex
  • Hi Alex,

    please check the /var/log/fallback.log. Why does the cssd fail to scan the mail?

    Regards,
    mlenk
  • ok, here is the fallback.log:

    2012:07:09-05:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  removing old journal /var/log/reporting/rrd/rrd.journal.1341792881.285704
    2012:07:09-06:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  flushing old values
    2012:07:09-06:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  rotating journals
    2012:07:09-06:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  started new journal /var/log/reporting/rrd/rrd.journal.1341803681.285723
    2012:07:09-06:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  removing old journal /var/log/reporting/rrd/rrd.journal.1341796481.285721
    2012:07:09-07:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  flushing old values
    2012:07:09-07:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  rotating journals

    2012:07:09-08:48:59 firewall [daemon:info] cssd[7505]:  [     (nil)] saviscanner_log (saviscanner.c:25) Reloading SAVI thread data
    2012:07:09-08:49:16 firewall [daemon:info] cssd[7505]:  [     (nil)] saviscanner_log (saviscanner.c:25) Reloading SAVI thread data finished, engine 3.32.0, thread data 4.78 from 4/6/2012 (3666666 detected threads)
    2012:07:09-08:56:20 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-08:59:54 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:09:10 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:10:17 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:14:11 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  flushing old values
    2012:07:09-09:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  rotating journals
    2012:07:09-09:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  started new journal /var/log/reporting/rrd/rrd.journal.1341814481.285797
    2012:07:09-09:14:41 firewall [daemon[:D]ebug] rrdcached[3431]:  removing old journal /var/log/reporting/rrd/rrd.journal.1341807281.285711
    2012:07:09-09:18:47 firewall [daemon:info] cssd[7505]:  [0xf67248f0] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:25:20 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:25:44 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:26:07 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:31:18 firewall [daemon:info] cssd[7505]:  [0xf67248f0] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:31:54 firewall [daemon:info] cssd[7505]:  [0xf67248f0] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-09:32:00 firewall [daemon:info] cssd[7505]:  [0xf6748ed8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    :
    :
    :

    2012:07:09-11:08:37 firewall [daemon:info] cssd[7505]:  [0xed6ae8a8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-11:08:43 firewall [daemon:notice] haveged:  haveged stopping due to signal 15
    2012:07:09-11:08:44 firewall [daemon:notice] haveged:  haveged starting up
    2012:07:09-11:08:50 firewall [authpriv:info] shadow[10036]:  group already exists - group=postgres, by=0
    2012:07:09-11:08:50 firewall [authpriv:info] useradd[10045]:  account already exists - account=postgres, by=0
    2012:07:09-11:09:07 firewall [authpriv:info] shadow[10134]:  group already exists - group=rrdcache, by=0
    2012:07:09-11:09:07 firewall [authpriv:info] useradd[10143]:  account already exists - account=rrdcache, by=0
    2012:07:09-11:09:36 firewall [authpriv:info] shadow[12923]:  group already exists - group=httpproxy, by=0
    2012:07:09-11:09:36 firewall [authpriv:info] useradd[12932]:  account already exists - account=httpproxy, by=0
    2012:07:09-11:09:40 firewall [daemon:info] cssd[7505]:  [0xed6af298] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-11:10:38 firewall [daemon:info] cssd[7505]:  [0xf67248f0] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-11:11:41 firewall [authpriv:info] shadow[25728]:  group already exists - group=httpproxy, by=0
    2012:07:09-11:11:41 firewall [authpriv:info] useradd[25737]:  account already exists - account=httpproxy, by=0
    2012:07:09-11:12:11 firewall [daemon:info] admin-reporter[1004]:  Successful WebAdmin login
    2012:07:09-11:12:12 firewall [user:notice] shutdown[26222]:  shutting down for system reboot
    2012:07:09-11:12:14 firewall [daemon:info] irqd[3023]:  eth3 ether 00:1a:8c:12:98:93 
    2012:07:09-11:12:21 firewall [daemon:notice] acpid:  exiting
    2012:07:09-11:12:22 firewall [daemon:info] cssd[7505]:  [0xed6ae8a8] saviscanner_scan (saviscanner.c:95) Unknown SAVI error [0x8004021a]
    2012:07:09-11:12:30 smtpd [daemon:err]  [4769]: Cannot connect: Connection refused
    2012:07:09-11:12:33 firewall [daemon:notice] haveged:  haveged stopping due to signal 15
    2012:07:09-11:13:16 firewall [daemon:info] acpid:  starting up
    2012:07:09-11:13:16 firewall [daemon:info] acpid:  1 rule loaded

    2012:07:09-11:13:16 firewall [daemon:info] acpid:  waiting for events: event logging is off
    2012:07:09-11:13:17 firewall [user:notice] firmware.sh[2772]:  Cannot find  firmware file 'intel-ucode/06-1c-0a'
    2012:07:09-11:13:17 firewall [user:notice] firmware.sh[2778]:  Cannot find  firmware file 'intel-ucode/06-1c-0a'
    2012:07:09-11:13:20 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
    2012:07:09-11:13:20 firewall [daemon:err] /usr/local/bin/reporter/websec-reporter.pl[2707]:  Cannot connect: Connection refused
    2012:07:09-11:13:22 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
    2012:07:09-11:13:22 firewall [daemon:err] /usr/local/bin/reporter/websec-reporter.pl[2707]:  Cannot connect: Connection refused
    2012:07:09-11:13:24 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
    2012:07:09-11:13:24 firewall [daemon:err] /usr/local/bin/reporter/websec-reporter.pl[2707]:  Cannot connect: Connection refused
    2012:07:09-11:13:25 firewall [user:notice] rchal:  powersave cpufreq governor could not be loaded
    2012:07:09-11:13:25 firewall [user:notice] rchal:  userspace cpufreq governor could not be loaded
    2012:07:09-11:13:25 firewall [user:notice] rchal:  conservative cpufreq governor could not be loaded
    2012:07:09-11:13:26 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
    2012:07:09-11:13:26 firewall [daemon:err] /usr/local/bin/reporter/websec-reporter.pl[2707]:  Cannot connect: Connection refused
    2012:07:09-11:13:26 firewall [daemon:notice] acpid:  client connected from 2999[201:201]
    2012:07:09-11:13:26 firewall [daemon:info] acpid:  1 client rule loaded
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  getting interface notifications
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  lo loopback 
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  eth3 ether 00:1a:8c:12:98:93 
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  eth2 ether 00:1a:
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  eth1 ether 00:1a: 
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  eth0 ether 00:1a: 
    2012:07:09-11:13:27 firewall [daemon:info] irqd[3017]:  rebalance started (every 5 sec)
    2012:07:09-11:13:27 firewall [daemon:notice] haveged:  haveged starting up
    2012:07:09-11:13:28 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
    2012:07:09-11:13:28 firewall [daemon:err] /usr/local/bin/reporter/websec-reporter.pl[2707]:  Cannot connect: Connection refused
    2012:07:09-11:13:30 firewall [daemon:err] /usr/local/bin/reporter/pfilter-reporter.pl[2702]:  Cannot connect: Connection refused
  • This does not look like a UTM version 9.000. What does the shell command 'version' output?
  • here the output:

    loginuser@firewall:/var/log > version

    Current software version...: 9.000008
    Hardware type..............: 120r5
    Serial number..............: ************xx
    Installation image.........: 8.951-1.1
    Installation type..........: ssi
    Installed pattern version..: 25342
    Downloaded pattern version.: 25342
    Up2Dates applied...........: 5 (see below)
                                 sys-8.951-8.960-1.9.2.tgz (Jun  1 22:03)
                                 sys-8.960-8.965-9.7.1.tgz (Jun 15 08:10)
                                 sys-8.965-8.970-7.7.1.tgz (Jun 15 08:12)
                                 sys-8.970-8.980-7.7.1.tgz (Jul  9 11:10)
                                 sys-8.980-9.000-7.8.1.tgz (Jul  9 11:11)
    Up2Dates available.........: 0
    Factory resets.............: 0
    Timewarps detected.........: 0

    loginuser@firewall:/var/log >
  • Weird. I thought I fixed one of the seen typos in that version already. Did the cssd maybe survive several upgrades? What does the output of the following shell command yield?
    stat -c %z /proc/$(pgrep cssd)

    Additionally, what version of the SAVI pattern do you have installed?
    rpm -qv u2d-savi

    Regards,
    mlenk
  • ok, i have the probelm before i upgraded to the end version and after. 

    here is the output that you need:


    loginuser@firewall:/var/log > stat -c %z /proc/$(pgrep cssd)
    2012-07-09 12:38:43.220362889 +0300
    loginuser@firewall:/var/log > rpm -qv u2d-savi
    u2d-savi-9-858
    loginuser@firewall:/var/log >
  • Okay, I've investigated the reason for the "Unknown SAVI error [0x8004021a]". The error code provided in the square brackets indicates that the scanned file was corrupted. I will improve the SAVI scanner so that it treats corrupted files as unscannable files in the future.

    Regards,
    mlenk
  • What i have to do, to update the corrupt file?

    But you know, any Mails will be scanned, and any files will bring this error. So i don't thing its a curruption of the pattern file, its looks more a problem in the Sophos Virusscan engine.
  • Thanks for reporting. We are now tracking this as Mantis ID #22016
  • The Mantis ID #22016 is now being worked on. We are planning to release a fix for this issue in Version 9.001.