Bug #1865818 “clamav update failed - default timeout needs a bum...” : Bugs : clamav package : Ubuntu

Revision history for this message

cwf3wfwfswf (vdvegegeg-deactivatedaccount) wrote on 2020-03-03:

#1

clamav march.jpg Edit (186.0 KiB, image/jpeg)
.etc.clamav.clamd.conf.txt Edit (1.9 KiB, text/plain; charset="utf-8")
.etc.clamav.freshclam.conf.txt Edit (701 bytes, text/plain; charset="utf-8")
Dependencies.txt Edit (3.2 KiB, text/plain; charset="utf-8")
KernLog.txt Edit (3.9 KiB, text/plain; charset="utf-8")
ProcCpuinfoMinimal.txt Edit (1.0 KiB, text/plain; charset="utf-8")

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-03

description:

updated

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-05

information type:

Private Security → Public

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2020-03-06:

#2

Download full text (9.4 KiB)

Hi,
it seems to time out on you :-/

By default that should be done automatically in background by the service:

root@b:~# systemctl status clamav-freshclam.service
● clamav-freshclam.service - ClamAV virus database updater
   Loaded: loaded (/lib/systemd/system/clamav-freshclam.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2020-03-06 10:20:51 UTC; 3min 6s ago
     Docs: man:freshclam(1)
           man:freshclam.conf(5)
           https://www.clamav.net/documents
Main PID: 22378 (freshclam)
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/clamav-freshclam.service
           └─22378 /usr/bin/freshclam -d --foreground=true

Mar 06 10:21:11 b freshclam[22378]: Fri Mar 6 10:21:11 2020 -> daily.cvd updated (version: 25742, sigs: 2208177, f-level: 63, builder: raynman)
Mar 06 10:21:11 b freshclam[22378]: Fri Mar 6 10:21:11 2020 -> main database available for download (remote version: 59)
Mar 06 10:21:28 b freshclam[22378]: Fri Mar 6 10:21:28 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-ea8e6554afa4b49023af11272e09532f.tmp-main.cvd' ...
Mar 06 10:21:35 b freshclam[22378]: Fri Mar 6 10:21:35 2020 -> Database test passed.
Mar 06 10:21:35 b freshclam[22378]: Fri Mar 6 10:21:35 2020 -> main.cvd updated (version: 59, sigs: 4564902, f-level: 60, builder: sigmgr)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar 6 10:21:35 2020 -> bytecode database available for download (remote version: 331)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar 6 10:21:35 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-7daed3263eb26f753d70cec595669ca0.tmp-bytecode.cvd' ...
Mar 06 10:21:36 b freshclam[22378]: Fri Mar 6 10:21:36 2020 -> Database test passed.
Mar 06 10:21:36 b freshclam[22378]: Fri Mar 6 10:21:36 2020 -> bytecode.cvd updated (version: 331, sigs: 94, f-level: 63, builder: anvilleg)
Mar 06 10:21:36 b freshclam[22378]: Fri Mar 6 10:21:36 2020 -> !NotifyClamd: Can't find or parse configuration file /etc/clamav/clamd.conf

And its full log (could be usefull to attach that to the bug) would look like:
root@b:~# journalctl -u clamav-freshclam.service
-- Logs begin at Tue 2019-12-17 08:53:23 UTC, end at Fri 2020-03-06 10:23:51 UTC. --
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:51 b systemd[1]: Started ClamAV virus database updater.
Mar 06 10:20:51 b freshclam[22378]: Fri Mar 6 10:20:51 2020 -> ClamAV update process started at Fri Mar 6 10:20:51 2020
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:53 b freshclam[22378]: Fri Mar 6 10:20:53 2020 -> daily database available for download (remote version: 25742)
Mar 06 10:21:04 b freshclam[22378]: Fri Mar 6 10:21:04 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-d27d67a14d4730fa24f41ecf9e5e83a8.tmp-daily.cvd' ...
Mar 06 10:21:11 b freshclam[22378]: Fri Mar 6 10:21:11 2020 -> Database test passed.
Mar 06 10:21:11 b freshclam[22378]: Fri Mar 6 10:21:11 2020 -> daily.cvd updated (version...

Hi,
it seems to time out on you :-/

By default that should be done automatically in background by the service:

root@b:~# systemctl status clamav-freshclam.service
● clamav-freshclam.service - ClamAV virus database updater
   Loaded: loaded (/lib/systemd/system/clamav-freshclam.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2020-03-06 10:20:51 UTC; 3min 6s ago
     Docs: man:freshclam(1)
           man:freshclam.conf(5)
           https://www.clamav.net/documents
 Main PID: 22378 (freshclam)
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/clamav-freshclam.service
           └─22378 /usr/bin/freshclam -d --foreground=true

Mar 06 10:21:11 b freshclam[22378]: Fri Mar  6 10:21:11 2020 -> daily.cvd updated (version: 25742, sigs: 2208177, f-level: 63, builder: raynman)
Mar 06 10:21:11 b freshclam[22378]: Fri Mar  6 10:21:11 2020 -> main database available for download (remote version: 59)
Mar 06 10:21:28 b freshclam[22378]: Fri Mar  6 10:21:28 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-ea8e6554afa4b49023af11272e09532f.tmp-main.cvd' ...
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> Database test passed.
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> main.cvd updated (version: 59, sigs: 4564902, f-level: 60, builder: sigmgr)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> bytecode database available for download (remote version: 331)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-7daed3263eb26f753d70cec595669ca0.tmp-bytecode.cvd' ...
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> Database test passed.
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> bytecode.cvd updated (version: 331, sigs: 94, f-level: 63, builder: anvilleg)
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> !NotifyClamd: Can't find or parse configuration file /etc/clamav/clamd.conf

And its full log (could be usefull to attach that to the bug) would look like:
root@b:~# journalctl -u clamav-freshclam.service
-- Logs begin at Tue 2019-12-17 08:53:23 UTC, end at Fri 2020-03-06 10:23:51 UTC. --
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:51 b systemd[1]: Started ClamAV virus database updater.
Mar 06 10:20:51 b freshclam[22378]: Fri Mar  6 10:20:51 2020 -> ClamAV update process started at Fri Mar  6 10:20:51 2020
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:51 b systemd[1]: clamav-freshclam.service: Failed to reset devices.list: Operation not permitted
Mar 06 10:20:53 b freshclam[22378]: Fri Mar  6 10:20:53 2020 -> daily database available for download (remote version: 25742)
Mar 06 10:21:04 b freshclam[22378]: Fri Mar  6 10:21:04 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-d27d67a14d4730fa24f41ecf9e5e83a8.tmp-daily.cvd' ...
Mar 06 10:21:11 b freshclam[22378]: Fri Mar  6 10:21:11 2020 -> Database test passed.
Mar 06 10:21:11 b freshclam[22378]: Fri Mar  6 10:21:11 2020 -> daily.cvd updated (version: 25742, sigs: 2208177, f-level: 63, builder: raynman)
Mar 06 10:21:11 b freshclam[22378]: Fri Mar  6 10:21:11 2020 -> main database available for download (remote version: 59)
Mar 06 10:21:28 b freshclam[22378]: Fri Mar  6 10:21:28 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-ea8e6554afa4b49023af11272e09532f.tmp-main.cvd' ...
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> Database test passed.
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> main.cvd updated (version: 59, sigs: 4564902, f-level: 60, builder: sigmgr)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> bytecode database available for download (remote version: 331)
Mar 06 10:21:35 b freshclam[22378]: Fri Mar  6 10:21:35 2020 -> Testing database: '/var/lib/clamav/tmp.0b342/clamav-7daed3263eb26f753d70cec595669ca0.tmp-bytecode.cvd' ...
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> Database test passed.
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> bytecode.cvd updated (version: 331, sigs: 94, f-level: 63, builder: anvilleg)
Mar 06 10:21:36 b freshclam[22378]: Fri Mar  6 10:21:36 2020 -> !NotifyClamd: Can't find or parse configuration file /etc/clamav/clamd.conf

For tha manual refresh as you show it to work the service needs to stop anyway.
Did you do that and why (probably as part of the debugging)?

I stopped my service as well and removed the databases.

I see it doing the download (fast in my case at first):

root@b:~# freshclam 
Fri Mar  6 10:27:03 2020 -> ClamAV update process started at Fri Mar  6 10:27:03 2020
Fri Mar  6 10:27:03 2020 -> daily database available for download (remote version: 25742)
Time: 7.0s, ETA: 0.0s [=============================>] 56.84MiB/56.84MiB        
Fri Mar  6 10:27:12 2020 -> Testing database: '/var/lib/clamav/tmp.8c5eb/clamav-6c089d19b1ffd905e9881b7cc51b5569.tmp-daily.cvd' ...
Fri Mar  6 10:27:19 2020 -> Database test passed.
Fri Mar  6 10:27:19 2020 -> daily.cvd updated (version: 25742, sigs: 2208177, f-level: 63, builder: raynman)
Fri Mar  6 10:27:19 2020 -> main database available for download (remote version: 59)
Time: 13.8s, ETA: 0.0s [=============================>] 112.40MiB/112.40MiB      
Fri Mar  6 10:27:37 2020 -> Testing database: '/var/lib/clamav/tmp.8c5eb/clamav-01e095cdfa60cbc46c5012a1e658b59b.tmp-main.cvd' ...
Fri Mar  6 10:27:43 2020 -> Database test passed.
Fri Mar  6 10:27:43 2020 -> main.cvd updated (version: 59, sigs: 4564902, f-level: 60, builder: sigmgr)
Fri Mar  6 10:27:43 2020 -> bytecode database available for download (remote version: 331)
Time: 0.2s, ETA: 0.0s [=============================>] 289.44KiB/289.44KiB     
Fri Mar  6 10:27:43 2020 -> Testing database: '/var/lib/clamav/tmp.8c5eb/clamav-1d325f44a96c8eaac1f1d0ae6043e35d.tmp-bytecode.cvd' ...
Fri Mar  6 10:27:45 2020 -> Database test passed.
Fri Mar  6 10:27:45 2020 -> bytecode.cvd updated (version: 331, sigs: 94, f-level: 63, builder: anvilleg)
Fri Mar  6 10:27:45 2020 -> !NotifyClamd: Can't find or parse configuration file /etc/clamav/clamd.conf

You could also try --verbose and --debug if anything special happens before your timeouts (some locking or hang).

Now let me slow it down to recreate your case to be above 30 seconds.

root@b:~# tc qdisc show dev eth0
qdisc noqueue 0: root refcnt 2
root@b:~# tc qdisc add dev eth0 root handle 1: htb default 12
root@b:~# tc class add dev eth0 parent 1:1 classid 1:12 htb rate 14kbps ceil 14kbps
root@b:~# tc qdisc add dev eth0 parent 1:12 netem delay 250ms
root@b:~# tc qdisc show dev eth0
qdisc htb 1: root refcnt 2 r2q 10 default 18 direct_packets_stat 0 direct_qlen 1000
qdisc netem 8001: parent 1:12 limit 1000 delay 250.0ms

Now I was able to reproduce your case:
< 
* Operation timed out after 30000 milliseconds with 19618356 out of 59605116 bytes received
* stopped the pause stream!
* Closing connection 0s [=========>                    ] 18.71MiB/56.84MiB

This is the 30 second timeout that is the default.

Per [1] I was setting the timeout to a higher value in /etc/clamav/freshclam.conf
ConnectTimeout 300
ReceiveTimeout 300

And then it worked again.
Fri Mar  6 10:38:41 2020 -> ClamAV update process started at Fri Mar  6 10:38:41 2020
Fri Mar  6 10:38:41 2020 -> daily database available for download (remote version: 25742)
Time: 89.7s, ETA: 0.0s [=============================>] 56.84MiB/56.84MiB        
Fri Mar  6 10:40:13 2020 -> Testing database: '/var/lib/clamav/tmp.dea37/clamav-c6eff5dffb9adbb813b9a2d9d4646848.tmp-daily.cvd' ...
Fri Mar  6 10:40:21 2020 -> Database test passed.
Fri Mar  6 10:40:21 2020 -> daily.cvd updated (version: 25742, sigs: 2208177, f-level: 63, builder: raynman)
Fri Mar  6 10:40:21 2020 -> main database available for download (remote version: 59)
Time: 178.9s, ETA: 0.0s [=============================>] 112.40MiB/112.40MiB      
Fri Mar  6 10:43:23 2020 -> Testing database: '/var/lib/clamav/tmp.dea37/clamav-e3fe3307371296aac45e347158fa7efb.tmp-main.cvd' ...
Fri Mar  6 10:43:29 2020 -> Database test passed.
Fri Mar  6 10:43:29 2020 -> main.cvd updated (version: 59, sigs: 4564902, f-level: 60, builder: sigmgr)
Fri Mar  6 10:43:29 2020 -> bytecode database available for download (remote version: 331)
Time: 3.3s, ETA: 0.0s [=============================>] 289.44KiB/289.44KiB

This is a local config issue when matched with a very slow internet connection.
The defaults are from upstream, so a discussion about bumping them for higher defaults would have to be there. But I think you are good just adapting your system as needed.

I found that a discussion about that default already happened and the default was set to 0 (no timeout) on the receive [2].
That change is rather new and we will pick it up naturally with the newer version.

But it is good to be aware as we will also have to change
  debian/clamav-freshclam.postinst.in
Which sets the old default of 30 still
  205   [ -z "$ConnectTimeout" ] && ConnectTimeout=30
  ...
  227 ConnectTimeout $ConnectTimeout

For now just change your local config.
But we should try to fix that before 20.04 is released in that new version (can't really wait on a new clamav). But we'd have to check if there are negative interactions first.

Adding it to the list of Ubuntu-server TODOs

[1]: https://linux.die.net/man/5/freshclam.conf
[2]: https://github.com/Cisco-Talos/clamav-devel/commit/2fd28e1d09f6a563564b61923e62338308e44466

Changed in clamav (Ubuntu):
status:	New → Triaged
importance:	Undecided → High
tags:	added: server-next
summary:	- clamav update failed + clamav update failed - default timeout needs a bump (upstream has bumped + already)

Revision history for this message

cwf3wfwfswf (vdvegegeg-deactivatedaccount) wrote on 2020-03-06:

#3

hi christian

yes by default it should be done automatically in the background & it used to but not since the last month now.

for the manual update i do > sudo systemctl stop clamav-freshclam > sudo freshclam

i did this because clamtk reported signatures out of date & clamscan -V did not give me the latest signature version with the date as it used to.

this fix provided here solves the problem, please do have a look :

https://gitlab.com/dave_m/clamtk/issues/90

i have been with bionic ever since it was released & have had the same internet connection but never faced this issue earlier.

the same computer, the same internet connection but with debian buster installed clamav & clamtk have absolutely no issues.

for your reference here is my ubuntu bionic freshclam.conf :

https://postimg.cc/GHtX3nNZ

for your reference here is the debian buster freshclam.conf :

https://postimg.cc/RJ9QrM3p

i will bump the default 30 second timeout to 300 & report back.

Revision history for this message

cwf3wfwfswf (vdvegegeg-deactivatedaccount) wrote on 2020-03-08:

#4

hi!

did a fresh install of ubuntu 18.04.4, updated the software & did a restart.
next i installed clamav & clamtk but clamav would not update the signatures in the background by default as it should so i edited freshclam.conf & bumped the default 30 second ConnectTimeout & ReceiveTimeout to 300 as shown by you & the update was done.

just out of curiosity i did a fresh install again, did a software update, restarted & installed clamav & clamtk.

clamav would not update the signatures in the background by default as it should so i edited freshclam.conf but this time instead of bumping both ConnectTimeout & ReceiveTimeout to 300 i copied from the debian freshclam.conf & only edited the ReceiveTimeout to 0 & restarted.

after a few minutes when i checked with clamscan -V it showed me the latest signature version with date & time as it always did before > ClamAV 0.102.2/25744/Sat Mar 7 19:46:15 2020
clamav had done the update automatically in the background.

for your reference here is =

the default ubuntu bionic 18.04.4 freshclam.conf :

https://postimg.cc/GHtX3nNZ

the default debian buster 10.3 freshclam.conf :

https://postimg.cc/RJ9QrM3p

the edited ubuntu bionic 18.04.4 freshclam.conf :

https://postimg.cc/GBRzC0m6

what i understand is that the problem is only with the 30 second default RecieveTimeout in freshclam.conf but i guess you would know better.

please look into it & do the needful.

information type:

Public → Private Security

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-08

information type:

Private Security → Public Security

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-08

information type:	Public Security → Private Security
information type:	Private Security → Public

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-14

information type:

Public → Private Security

cwf3wfwfswf (vdvegegeg-deactivatedaccount) on 2020-03-14

information type:

Private Security → Public Security

Revision history for this message

Bryce Harrington (bryce) wrote on 2020-03-19:

#5

The version of clamav in focal has the required fix:

clamav-gu$ grep ReceiveTimeout shared/optparser.c
{"ReceiveTimeout", NULL, 0, CLOPT_TYPE_NUMBER, MATCH_NUMBER, 0, NULL, 0, OPT_FRESHCLAM, "Timeout in seconds when reading from database server.", "0"},

Full patch as landed upstream is:
https://github.com/Cisco-Talos/clamav-devel/commit/2fd28e1d09f6a563564b61923e62338308e44466

Changed in clamav (Ubuntu):
status:	Triaged → Fix Released

Revision history for this message

cwf3wfwfswf (vdvegegeg-deactivatedaccount) wrote on 2020-03-21:

#6

thanks bryce.

Ubuntu
clamav package

clamav update failed - default timeout needs a bump (upstream has bumped already)

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntuclamav package

clamav update failed - default timeout needs a bump (upstream has bumped already)

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntu
clamav package