The debug flag on the freshclam invocation seems only to report on the processing that happens *after* the cvd is successfully downloaded.
So... I went to a more basic level and captured the actual network traffic with pcap and then examined it with wireshark. I found an update attempt that failed because the mirrors were "not synchronized" and then went to the capture files to find the DNS that retrieved the version number, and the HTTP that retrieved the data. (These are in separate pcap files because our DNS uses our old DSL, but HTTP uses the faster cable modem.) Anyway, here is a summary of a typical "not synchronized" failure. Here is an excerpt from the freshclam log from Sunday 01 July 2018 at 09:36:01 EDT (aka 13:36:01 GMT): daily.cvd version from DNS: 24713 Retrieving http://db.us.clamav.net/daily.cvd Ignoring mirror 104.16.189.138 (due to previous errors) Trying host db.us.clamav.net (104.16.185.138)... Using ip '10.11.14.160' for fetching. Trying to download http://db.us.clamav.net/daily.cvd (IP: 104.16.185.138) Downloading daily.cvd [100%] WARNING: Mirror 104.16.185.138 is not synchronized. Indeed, when we look at the captured DNS TXT record and compare it to the captured downloaded data, we see that it in fact is *not* synchronized! First, the wireshark decode of the TXT record, showing that the current version is in fact 24713. No. Time Source Port Destination Port Length Protocol Info 4723 09:36:02.098521 147.75.64.146 53 10.25.26.60 26793 148 DNS Standard query response 0x5469 TXT Frame 4723: 148 bytes on wire (1184 bits), 148 bytes captured (1184 bits) Ethernet II, Src: 6c:72:20:41:d1:32 (6c:72:20:41:d1:32), Dst: fc:aa:14:5a:1b:68 (fc:aa:14:5a:1b:68) Internet Protocol Version 4, Src: 147.75.64.146 (147.75.64.146), Dst: 10.25.26.60 (10.25.26.60) User Datagram Protocol, Src Port: 53 (53), Dst Port: 26793 (26793) Domain Name System (response) [Request In: 4722] [Time: 0.044517000 seconds] Transaction ID: 0x5469 Flags: 0x8400 Standard query response, No error Questions: 1 Answer RRs: 1 Authority RRs: 0 Additional RRs: 1 Queries current.cvd.clamav.net: type TXT, class IN Answers current.cvd.clamav.net: type TXT, class IN Name: current.cvd.clamav.net Type: TXT (Text strings) Class: IN (0x0001) Time to live: 30 minutes Data length: 43 TXT Length: 42 TXT: 0.100.0:58:24713:1530451740:1:63:47569:322 Additional records <Root>: type OPT Name: <Root> Type: OPT (EDNS0 option) UDP payload size: 1680 Higher bits in extended RCODE: 0x0 EDNS0 version: 0 Z: 0x8000 Bit 0 (DO bit): 1 (Accepts DNSSEC security RRs) Bits 1-15: 0x0 (reserved) Data length: 0 Next is the HTTP request and (truncated) response from 104.16.185.138, as provided by wireshark's handy Follow TCP Stream. Note that the response says that the version is only 24712, not 24713! GET /daily.cvd HTTP/1.0 Host: db.us.clamav.net User-Agent: ClamAV/0.99.4 (OS: linux-gnu, ARCH: x86_64, CPU: x86_64) Connection: close HTTP/1.1 200 OK Date: Sun, 01 Jul 2018 13:36:20 GMT Content-Type: application/octet-stream Content-Length: 48149793 Connection: close Set-Cookie: __cfduid=d88ed50c4d496c2c73f2f8c6f2579b9bb1530452180; expires=Mon, 01-Jul-19 13:36:20 GMT; path=/; domain=.clamav.net; HttpOnly Last-Modified: Sun, 01 Jul 2018 04:40:58 GMT ETag: "5b385b5a-2deb521" Expires: Sun, 01 Jul 2018 08:40:58 GMT Cache-Control: max-age=3600 Cache-Control: public CF-Cache-Status: HIT Accept-Ranges: bytes Server: cloudflare CF-RAY: 433942cde659ae1a-BOS ClamAV-VDB:01 Jul 2018 00-40 -0400:24712:2000714:63:6b67a9289bf468a7bc9caead0b485bfd:8PaJxsXEfye3s7v74s7ahRQ1IaryM7UxzfE8Cnb8g2l+wLIMC6wCwIvh3wvbLJzDtSMkeerx8s1O1K/TYiCf445F+79Srhgc/Rl1Qokm2IsUNOL4J2VbzRM/Akq0eTQhHk999P7Irz0MyLJWzNeXaKDWN0LmUmcpZrBTjhJYzQg:neo:1530420019 My conclusion is that the cause of this is a typical race condition: the DNS TXT record is updated before Cloudflare has propagated the new cvd file to all the mirrors. I have attached the full freshclam log for this failing update attempt to this email, The pcap file is far too big for email, but can be retrieved via the following full URL (directory listing is blocked): http://iment.com/paste-bin/ClamAV-104-16-185-138.pcap On Sun, 1 Jul 2018 00:37:35 +0000 "Joel Esler (jesler)" <jes...@cisco.com> wrote: > Ping.clamav.net is an identification lookup. Helps us see what > versions people are running out there and what version of ClamAV > people are using. It’s failure shouldn’t stop the update process. > Please give us a debug. > > Sent from my iPhone > > > On Jun 30, 2018, at 19:28, Paul Kosinski <clamav-us...@iment.com> > > wrote: > > > > We are *still* failing to get ClamAV cvd files updates reliably -- > > even after deleting mirrors.dat before each attempt! > > > > [... and much, much more ...]
------------------------------ Sunday 01 July 2018 at 09:36:01 ------------------------------ Current working dir is /opt/clamav.d/clamav.0.99.4/share/clamav Max retries == 4 ClamAV update process started at Sun Jul 1 09:36:02 2018 Using IPv6 aware code Querying current.cvd.clamav.net TTL: 1800 Software version from DNS: 0.100.0 WARNING: Your ClamAV installation is OUTDATED! WARNING: Local version: 0.99.4 Recommended version: 0.100.0 DON'T PANIC! Read http://www.clamav.net/documents/upgrading-clamav main.cvd version from DNS: 58 main.cvd is up to date (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr) daily.cvd version from DNS: 24713 Retrieving http://db.us.clamav.net/daily.cvd Using ip '10.11.14.160' for fetching. Trying to download http://db.us.clamav.net/daily.cvd (IP: 104.16.188.138) Downloading daily.cvd [100%] WARNING: Mirror 104.16.188.138 is not synchronized. Querying daily.0.85.0.0.6810BC8A.ping.clamav.net Can't query daily.0.85.0.0.6810BC8A.ping.clamav.net Trying again in 5 secs... ClamAV update process started at Sun Jul 1 09:36:11 2018 Using IPv6 aware code Querying current.cvd.clamav.net TTL: 1791 Software version from DNS: 0.100.0 WARNING: Your ClamAV installation is OUTDATED! WARNING: Local version: 0.99.4 Recommended version: 0.100.0 DON'T PANIC! Read http://www.clamav.net/documents/upgrading-clamav main.cvd version from DNS: 58 main.cvd is up to date (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr) daily.cvd version from DNS: 24713 Retrieving http://db.us.clamav.net/daily.cvd Using ip '10.11.14.160' for fetching. Trying to download http://db.us.clamav.net/daily.cvd (IP: 104.16.189.138) Downloading daily.cvd [100%] WARNING: Mirror 104.16.189.138 is not synchronized. Querying daily.0.85.0.0.6810BD8A.ping.clamav.net Can't query daily.0.85.0.0.6810BD8A.ping.clamav.net Trying again in 5 secs... ClamAV update process started at Sun Jul 1 09:36:20 2018 Using IPv6 aware code Querying current.cvd.clamav.net TTL: 1782 Software version from DNS: 0.100.0 WARNING: Your ClamAV installation is OUTDATED! WARNING: Local version: 0.99.4 Recommended version: 0.100.0 DON'T PANIC! Read http://www.clamav.net/documents/upgrading-clamav main.cvd version from DNS: 58 main.cvd is up to date (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr) daily.cvd version from DNS: 24713 Retrieving http://db.us.clamav.net/daily.cvd Ignoring mirror 104.16.189.138 (due to previous errors) Trying host db.us.clamav.net (104.16.185.138)... Using ip '10.11.14.160' for fetching. Trying to download http://db.us.clamav.net/daily.cvd (IP: 104.16.185.138) Downloading daily.cvd [100%] WARNING: Mirror 104.16.185.138 is not synchronized. Querying daily.0.85.0.0.6810B98A.ping.clamav.net Trying again in 5 secs... ClamAV update process started at Sun Jul 1 09:36:28 2018 Using IPv6 aware code Querying current.cvd.clamav.net TTL: 1774 Software version from DNS: 0.100.0 WARNING: Your ClamAV installation is OUTDATED! WARNING: Local version: 0.99.4 Recommended version: 0.100.0 DON'T PANIC! Read http://www.clamav.net/documents/upgrading-clamav main.cvd version from DNS: 58 main.cvd is up to date (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr) daily.cvd version from DNS: 24713 Retrieving http://db.us.clamav.net/daily.cvd Ignoring mirror 104.16.185.138 (due to previous errors) Ignoring mirror 104.16.189.138 (due to previous errors) Trying host db.us.clamav.net (104.16.186.138)... Using ip '10.11.14.160' for fetching. Trying to download http://db.us.clamav.net/daily.cvd (IP: 104.16.186.138) Downloading daily.cvd [100%] WARNING: Mirror 104.16.186.138 is not synchronized. Querying daily.0.85.0.0.6810BA8A.ping.clamav.net Can't query daily.0.85.0.0.6810BA8A.ping.clamav.net Giving up on db.us.clamav.net... ClamAV update process started at Sun Jul 1 09:36:32 2018 Using IPv6 aware code Querying current.cvd.clamav.net TTL: 1770 Software version from DNS: 0.100.0 WARNING: Your ClamAV installation is OUTDATED! WARNING: Local version: 0.99.4 Recommended version: 0.100.0 DON'T PANIC! Read http://www.clamav.net/documents/upgrading-clamav main.cvd version from DNS: 58 main.cvd is up to date (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr) daily.cvd version from DNS: 24713 Retrieving http://database.clamav.net/daily.cvd Ignoring mirror 104.16.189.138 (due to previous errors) Trying host database.clamav.net (104.16.187.138)... Using ip '10.11.14.160' for fetching. Trying to download http://database.clamav.net/daily.cvd (IP: 104.16.187.138) Downloading daily.cvd [100%] Loading signatures from daily.cvd Properly loaded 2001002 signatures from new daily.cvd daily.cvd updated (version: 24713, sigs: 2001002, f-level: 63, builder: neo) Querying daily.24713.85.1.0.6810BB8A.ping.clamav.net Can't query daily.24713.85.1.0.6810BB8A.ping.clamav.net bytecode.cvd version from DNS: 322 bytecode.cvd is up to date (version: 322, sigs: 90, f-level: 63, builder: neo) Database updated (6567341 signatures) from database.clamav.net (IP: 104.16.187.138) OnUpdateExecute: EXIT_1 ------------------------------ Sunday 01 July 2018 at 09:36:46 ------------------------------
_______________________________________________ clamav-users mailing list clamav-users@lists.clamav.net http://lists.clamav.net/cgi-bin/mailman/listinfo/clamav-users Help us build a comprehensive ClamAV guide: https://github.com/vrtadmin/clamav-faq http://www.clamav.net/contact.html#ml
