[Pkg-clamav-devel] Bug#749027: Bug#749027: The ClamAV daemon stops working.
Jim Barber
jim.barber at ddihealth.com
Tue May 27 05:18:26 UTC 2014
The ClamAV daemon hung again after rolling back to 0.98.3.
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
Sun May 25 08:51:01 2014 -> clamd daemon 0.98.3 (OS: linux-gnu, ARCH: x86_64, CPU: x86_64)
Sun May 25 08:51:01 2014 -> Log file size limited to 4294967295 bytes.
Sun May 25 08:51:01 2014 -> Reading databases from /var/lib/clamav
Sun May 25 08:51:01 2014 -> Not loading PUA signatures.
Sun May 25 08:51:01 2014 -> Bytecode: Security mode set to "TrustSigned".
Sun May 25 08:51:05 2014 -> Loaded 3384653 signatures.
Sun May 25 08:51:05 2014 -> LOCAL: Unix socket file /var/run/clamav/clamd.ctl
Sun May 25 08:51:05 2014 -> LOCAL: Setting connection queue length to 15
Sun May 25 08:51:05 2014 -> Limits: Global size limit set to 104857600 bytes.
Sun May 25 08:51:05 2014 -> Limits: File size limit set to 26214400 bytes.
Sun May 25 08:51:05 2014 -> Limits: Recursion level limit set to 10.
Sun May 25 08:51:05 2014 -> Limits: Files limit set to 10000.
Sun May 25 08:51:05 2014 -> Limits: MaxEmbeddedPE limit set to 10485760 bytes.
Sun May 25 08:51:05 2014 -> Limits: MaxHTMLNormalize limit set to 10485760 bytes.
Sun May 25 08:51:05 2014 -> Limits: MaxHTMLNoTags limit set to 2097152 bytes.
Sun May 25 08:51:05 2014 -> Limits: MaxScriptNormalize limit set to 5242880 bytes.
Sun May 25 08:51:05 2014 -> Limits: MaxZipTypeRcg limit set to 1048576 bytes.
Sun May 25 08:51:05 2014 -> Limits: MaxPartitions limit set to 50.
Sun May 25 08:51:05 2014 -> Limits: MaxIconsPE limit set to 100.
Sun May 25 08:51:05 2014 -> Archive support enabled.
Sun May 25 08:51:05 2014 -> Algorithmic detection enabled.
Sun May 25 08:51:05 2014 -> Portable Executable support enabled.
Sun May 25 08:51:05 2014 -> ELF support enabled.
Sun May 25 08:51:05 2014 -> Mail files support enabled.
Sun May 25 08:51:05 2014 -> OLE2 support enabled.
Sun May 25 08:51:05 2014 -> PDF support enabled.
Sun May 25 08:51:05 2014 -> SWF support enabled.
Sun May 25 08:51:05 2014 -> HTML support enabled.
Sun May 25 08:51:05 2014 -> Self checking every 3600 seconds.
Sun May 25 08:51:05 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Sun May 25 08:51:05 2014 -> ScanOnAccess: clamd must be started by root
Sun May 25 08:51:59 2014 -> /var/spool/havp/havp-UoR2B0: Eicar-Test-Signature(003059cf287f00005a591fce287f0000:68) FOUND
Sun May 25 09:51:06 2014 -> No stats for Database check - forcing reload
Sun May 25 09:51:06 2014 -> Restarting on-access scan
Sun May 25 09:51:07 2014 -> Reading databases from /var/lib/clamav
Sun May 25 09:51:11 2014 -> Database correctly reloaded (3384653 signatures)
Sun May 25 09:51:11 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Sun May 25 09:51:11 2014 -> ScanOnAccess: clamd must be started by root
Sun May 25 10:51:10 2014 -> Restarting on-access scan
Sun May 25 10:51:11 2014 -> Reading databases from /var/lib/clamav
Sun May 25 10:51:15 2014 -> Database correctly reloaded (3385141 signatures)
Sun May 25 10:51:15 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Sun May 25 10:51:15 2014 -> ScanOnAccess: clamd must be started by root
Sun May 25 12:45:23 2014 -> SelfCheck: Database status OK.
Sun May 25 14:12:17 2014 -> SelfCheck: Database status OK.
Sun May 25 15:12:17 2014 -> SelfCheck: Database status OK.
Sun May 25 16:12:17 2014 -> SelfCheck: Database status OK.
Sun May 25 17:16:51 2014 -> SelfCheck: Database status OK.
Sun May 25 18:27:02 2014 -> SelfCheck: Database status OK.
Sun May 25 20:15:13 2014 -> SelfCheck: Database status OK.
Sun May 25 21:24:16 2014 -> SelfCheck: Database status OK.
Sun May 25 22:45:52 2014 -> SelfCheck: Database status OK.
Sun May 25 22:51:29 2014 -> Restarting on-access scan
Sun May 25 22:51:29 2014 -> Reading databases from /var/lib/clamav
Sun May 25 22:51:33 2014 -> Database correctly reloaded (3385585 signatures)
Sun May 25 22:51:33 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Sun May 25 22:51:33 2014 -> ScanOnAccess: clamd must be started by root
Mon May 26 00:20:03 2014 -> SelfCheck: Database status OK.
Mon May 26 01:20:03 2014 -> SelfCheck: Database status OK.
Mon May 26 02:20:03 2014 -> SelfCheck: Database status OK.
Mon May 26 03:20:03 2014 -> SelfCheck: Database status OK.
Mon May 26 04:20:10 2014 -> SelfCheck: Database status OK.
Mon May 26 04:51:40 2014 -> Restarting on-access scan
Mon May 26 04:51:40 2014 -> Reading databases from /var/lib/clamav
Mon May 26 04:51:44 2014 -> Database correctly reloaded (3386039 signatures)
Mon May 26 04:51:44 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Mon May 26 04:51:44 2014 -> ScanOnAccess: clamd must be started by root
Mon May 26 05:51:44 2014 -> SelfCheck: Database status OK.
Mon May 26 07:31:37 2014 -> SelfCheck: Database status OK.
Mon May 26 08:47:39 2014 -> SelfCheck: Database status OK.
Mon May 26 10:42:09 2014 -> SelfCheck: Database status OK.
Mon May 26 10:51:55 2014 -> Restarting on-access scan
Mon May 26 10:51:56 2014 -> Reading databases from /var/lib/clamav
Mon May 26 10:52:00 2014 -> Database correctly reloaded (3386627 signatures)
Mon May 26 10:52:00 2014 -> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
Mon May 26 10:52:00 2014 -> ScanOnAccess: clamd must be started by root
Mon May 26 11:52:00 2014 -> SelfCheck: Database status OK.
Mon May 26 12:52:00 2014 -> SelfCheck: Database status OK.
Mon May 26 13:56:47 2014 -> SelfCheck: Database status OK.
Mon May 26 14:56:58 2014 -> SelfCheck: Database status OK.
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 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.
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?
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?
Is the problem perhaps related to these messages?
-> ERROR: ScanOnAccess: fanotify_init failed: Operation not permitted
-> ScanOnAccess: clamd must be started by root
Jim.
More information about the Pkg-clamav-devel
mailing list