Hi Jim,

On 27.05.2014 07:18, Jim Barber wrote:
The ClamAV daemon hung again after rolling back to 0.98.3.

You could try it with 0.98.1, but I'm not sure if that would help.

It went longer than a day this time, but still less than 2 days.
Here's the havp log (with URL removed).

     25/05/2014 08:51:59 === Starting HAVP Version: 0.92
     25/05/2014 08:51:59 Running as user: havp, group: havp
     25/05/2014 08:51:59 Use parent proxy: localhost:3130
     25/05/2014 08:51:59 --- Initializing Clamd Socket Scanner
     25/05/2014 08:51:59 Clamd Socket Scanner passed EICAR virus test
(Eicar-Test-Signature)
     25/05/2014 08:51:59 --- All scanners initialized
     25/05/2014 08:51:59 Process ID: 23108
     26/05/2014 23:20:04 Error: Some scanner has timed out! (lasturl:
<url removed>)

The complete ClamAV log from when I started it after backing out to the
older
version, to when I restarted it when I noticed it was hung is as follows:

     Sun May 25 08:51:01 2014 -> +++ Started at Sun May 25 08:51:01 2014
[...]
     Mon May 26 15:59:42 2014 -> SelfCheck: Database status OK.
     Mon May 26 16:52:08 2014 -> Restarting on-access scan
     Mon May 26 16:52:09 2014 -> Reading databases from /var/lib/clamav
     Mon May 26 16:52:13 2014 -> Database correctly reloaded (3387113
signatures)
     Mon May 26 16:52:13 2014 -> ERROR: ScanOnAccess: fanotify_init
failed: Operation not permitted
     Mon May 26 16:52:13 2014 -> ScanOnAccess: clamd must be started by
root
     Mon May 26 17:52:13 2014 -> SelfCheck: Database status OK.
     Mon May 26 18:52:13 2014 -> SelfCheck: Database status OK.
     Mon May 26 19:52:13 2014 -> SelfCheck: Database status OK.
     Mon May 26 21:52:05 2014 -> SelfCheck: Database status OK.
     Mon May 26 22:52:19 2014 -> SelfCheck: Database modification
detected. Forcing reload.
     Mon May 26 22:52:19 2014 -> Restarting on-access scan
     Mon May 26 22:52:19 2014 -> Reading databases from /var/lib/clamav
     Mon May 26 22:52:23 2014 -> Database correctly reloaded (3387525
signatures)
     Mon May 26 22:52:23 2014 -> Restarting on-access scan
     Tue May 27 06:39:04 2014 -> +++ Started at Tue May 27 06:39:04 2014

It looks like it hung on 'Restarting on-access scan'.
It didn't follow up with the following messages that usually
happen seconds after:

     -> Reading databases from /var/lib/clamav
     -> Database correctly reloaded ([0-9]+ signatures)

I think the problem here is that there is a second 'Restarting on-access scan' message only 4 seconds after another one and without the usual 'ERROR: ScanOnAccess: fanotify_init [...]' between them.

This looks as if the reload is started again, while the previous reload is not yet finished. Probably this should not happen, as it seems to cause a deadlock.

I used to run this version of the ClamAV daemon without issue.
So maybe it is something to do with getting freshclam updates working
again.
I went back through my freshclam logs and it was fine up until the
evening of
Thu Apr 24th where I started getting the freshclam update error.
Prior to that I wasn't getting hangs either though.

Actually, when I ran 'dpkg-reconfigure clamav-freshclam' to fix the
freshclam
update errors, one of the questions asked was:

     Should clamd be notified after updates?

I think this may have been 'No' before as I thought that was strange I
would
leave it set that way and I selected 'Yes'.
So it is likely to be this that is now causing my hangs I guess.

This may be, as the hang happens precisely when clamd itself notices a 'Database modification' and triggers a reload, likely just before freshclam triggers a reload.

Nonetheless I think this is a bug in clamd, as it should handle this gracefully.

Looking back over my past logs, the 'Restarting on-access scan' message
used to happen infrequently:

     Fri Apr 25 00:01:13 2014 -> Restarting on-access scan
     Tue Apr 29 13:41:24 2014 -> Restarting on-access scan
     Mon May  5 00:07:08 2014 -> Restarting on-access scan
     Thu May  8 19:46:58 2014 -> Restarting on-access scan
     Sun May 11 18:47:52 2014 -> Restarting on-access scan
     Fri May 16 17:48:07 2014 -> Restarting on-access scan
     Mon May 19 23:15:10 2014 -> Restarting on-access scan

Then after the reconfigure of clamav-freshclam it is regular:

     Tue May 20 23:49:57 2014 -> Restarting on-access scan
     Wed May 21 00:50:01 2014 -> Restarting on-access scan
     Wed May 21 01:50:07 2014 -> Restarting on-access scan
     Wed May 21 01:50:12 2014 -> Restarting on-access scan
     Wed May 21 22:44:12 2014 -> Restarting on-access scan
     Wed May 21 23:44:06 2014 -> Restarting on-access scan
     Thu May 22 04:44:15 2014 -> Restarting on-access scan
     Thu May 22 04:44:19 2014 -> Restarting on-access scan
     Thu May 22 06:44:23 2014 -> Restarting on-access scan
     Thu May 22 06:44:28 2014 -> Restarting on-access scan
     Thu May 22 18:03:34 2014 -> Restarting on-access scan
     Thu May 22 18:03:38 2014 -> Restarting on-access scan
     Thu May 22 23:03:48 2014 -> Restarting on-access scan
     Thu May 22 23:03:52 2014 -> Restarting on-access scan
     Fri May 23 01:03:56 2014 -> Restarting on-access scan
     Fri May 23 01:04:01 2014 -> Restarting on-access scan
     Fri May 23 08:26:56 2014 -> Restarting on-access scan
     Fri May 23 10:25:41 2014 -> Restarting on-access scan
     Fri May 23 16:25:56 2014 -> Restarting on-access scan
     Fri May 23 23:26:10 2014 -> Restarting on-access scan
     Fri May 23 23:26:14 2014 -> Restarting on-access scan
     Sat May 24 04:26:28 2014 -> Restarting on-access scan
     Sat May 24 11:26:42 2014 -> Restarting on-access scan
     Sat May 24 16:26:51 2014 -> Restarting on-access scan
     Sat May 24 16:26:55 2014 -> Restarting on-access scan
     Sat May 24 21:17:05 2014 -> Restarting on-access scan
     Sat May 24 23:27:09 2014 -> Restarting on-access scan
     Sun May 25 05:27:23 2014 -> Restarting on-access scan
     and so on...

So this may be a bug that has always been around but only triggered
when freshclam prompts the ClamAV daemon to reload its definitions.

What steps would you like me to do now?

Shall I upgrade to 0.98.4~rc1 again and reconfigure freshclam to no longer
notify the ClamAV daemon when an update is available?

Yes, please try this and let us know, if it helps.

Also could you please check, if /var/log/clamav/freshclam.log contains 'Clamd successfully notified about the update.' around the time 'Mon May 26 22:52:23 2014', where the hang happened, or if there is a related error message.

Or shall I upgrade and leave the notificatons on and turn on some verbose
debugging messages in ClamAV to see if something more useful is logged?

You can set 'Debug true' in clamd.conf.

Is the problem perhaps related to these messages?

     -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
     -> ScanOnAccess: clamd must be started by root

I don't think this is related, but if the above doesn't help, you could try disabling ScanOnAccess or running clamd as root.

Best regards,
Andreas


--
To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org

Reply via email to