client prematurely closed connection

[LarsBel]

Every few days I got processes that took 99.9% CPU and running forever.

Debug logging shows:

Feb 5 02:40:26 host python3[1250337]: 2024-02-05 02:40:26 uvscand: [INFO] ('127.0.0.1', 58160) queued uvscan of /tmp/uvscan_1707097226.0092113_58160, queue size is 1 Feb 5 02:40:26 host uvscand: ('127.0.0.1', 58160) queued uvscan of /tmp/uvscan_1707097226.0092113_58160, queue size is 1 Feb 5 02:40:31 host python3[1250337]: 2024-02-05 02:40:31 uvscand: [WARNING] ('127.0.0.1', 58160) client prematurely closed connection, removing /tmp/uvscan_1707097226.0092113_58160 from scan queue Feb 5 02:40:31 host python3[1250337]: 2024-02-05 02:40:31 uvscand: [INFO] closed connection to ('127.0.0.1', 58160) Feb 5 02:40:31 host uvscand: ('127.0.0.1', 58160) client prematurely closed connection, removing /tmp/uvscan_1707097226.0092113_58160 from scan queue Feb 5 02:40:31 host uvscand: closed connection to ('127.0.0.1', 58160)

The file in tmp gets deleted but the process runs forever.

I tried to change the uvscan parameter from --secure --mime --noboot --panalyse --manalyse to --secure --mime --noboot --panalyse --manalyse --timeout=15 --APPEND --EXIT-ON-ERROR --RPTALL --RPTCOR --RPTERR --VERBOSE --REPORT=/var/log/mcafee.log

but nothing changes nor any info in these logfiles

[spacefreak86]

Which process exactly is running forever? The uvscan process or python?

[LarsBel]

python calls the uvscan and reports: "python3[1250337]: 2024-02-05 02:40:31 uvscand: [WARNING] ('127.0.0.1', 58160) client prematurely closed connection, removing /tmp/uvscan_1707097226.0092113_58160 from scan queue" and delete the file in /tmp to scan.. then the uvscan process takes 99% cpu and runs forever, i think because python removes the file uvscan is currently scanning

this does not depend on the version of uvscan, happens on all three i tested

[spacefreak86]

Sorry for the long delay. I have just improved the daemon, it should now correctly handle premature disconnects. Could you please test it out? I don't use the daemon by myself anymore so feedback would be appreciated.

[LarsBel]

now I get:

python3[3909918]: 2024-07-01 19:59:20 uvscand: [WARNING] ('127.0.0.1', 46608) client prematurely closed connection, but scan is already running uvscand: ('127.0.0.1', 46608) client prematurely closed connection, but scan is already running

The file is now still in /tmp as long as the uvscan process runs.

I checked the file and it is a jpeg. I've run an uvscan manually on the file without problem

uvscan uvscan_1719856750.4279017_34920 --secure --mime --noboot --panalyse --manalyse --VERBOSE --SUMMARY Dat set version: 11120 created Jul 1 2024 Scanning for 596817 viruses, trojans and variants. ` /tmp/uvscan_1719856750.4279017_34920 ... is OK. Summary Report on /tmp/uvscan_1719856750.4279017_34920 File(s) Total files:................... 1 Clean:......................... 1 Not Scanned:................... 0 Possibly Infected:............. 0 Time: 00:00:00`

[spacefreak86]

The log messages are intentional. The first one means that uvscand got a request from RSpamd to scan a file, but RSpamd closed the connection before the scan was completed. uvscand is programmed asynchronously, so usually a scan gets cancelled in this case. But if the scan is already running, it cannot be cancelled anymore which causes the second log message.

The big question is, do you still have forever running scan processes which consume 100% CPU?

[spacefreak86]

BTW: what is your configured timeout for antivirus on the RSpamd side?

[LarsBel]

sorry, for some reason I got no notification. I havent configured a timeout, my config is what I have written in the installation file.

I have now added a timeout of 5 seconds.. lets see what happens.

edit No, even with a 5 sec timeout these 100% CPU processes happens when this is logged: uvscand: [WARNING] ('127.0.0.1', 43350) client prematurely closed connection, but scan is already running