Bug 14589 - vfs_virusfilter does not work with Sophos
Summary: vfs_virusfilter does not work with Sophos
Status: NEW
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: VFS Modules (show other bugs)
Version: 4.13.2
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Samba QA Contact
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-12-03 18:46 UTC by Bjoern Voigt
Modified: 2021-02-01 09:51 UTC (History)
1 user (show)

See Also:


Attachments
Fix incorrect error handling in virusfilter_io_readl (969 bytes, patch)
2020-12-03 18:47 UTC, Bjoern Voigt
no flags Details
More debug messages and fix incorrect error handling in virusfilter_io_readl (2.57 KB, patch)
2020-12-08 13:06 UTC, Bjoern Voigt
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Bjoern Voigt 2020-12-03 18:46:10 UTC
Samba does not work with Sophos SAV Dynamic Interface (SAVDI) 2.6.0 (current version).

This is a minimal smb.conf for testing:

[global]
	workgroup = WORKGROUP
	passdb backend = tdbsam
	log level = 2 vfs:10 virusfilter:10
[share1]
	path = /home/myusername
	read only = No
	# Samba Sophos configuration
	vfs objects = virusfilter
	virusfilter:scanner = sophos
	virusfilter:infected file action = rename
	virusfilter:rename suffix = .infected
	virusfilter:socket path = /run/savdi/sssp.sock

The Sophos SAVDI configuration /usr/local/savdi/savdid.conf is

threadcount: 30
maxqueuedsessions: 2
virusdatadir: /opt/sophos-av/lib/sav
idedir: /opt/sophos-av/lib/sav
onexception: REQUEST
onrequest: REQUEST
log {
    type: FILE
    logdir: /var/tmp/savdi/log/
    loglevel: 2 
}
channel {
    logrequests: YES
    commprotocol {
        type: IP
        address: 0.0.0.0
        port: 4020
        sendtimeout: 2
        recvtimeout: 10
    }
    service {
        name: sophos
        type: avscan
        scanprotocol {
            type: ICAP
            version: 1.02
            keepalive: YES
        }
        scanner {
            type: SAVI
            inprocess: YES
            savists: enableautostop 1
            savigrp: grpsuper 1
        }
    }
}
channel {
    commprotocol {
        type: UNIX
        socket: /var/run/savdi/sssp.sock
        requesttimeout: 120
        sendtimeout: 2
        recvtimeout: 5
    }
    scanprotocol {
        type: SSSP
        allowscanfile: DIR
        allowscandata: YES
        maxscandata: 500000
        maxmemorysize: 250000
        tmpfilestub: /tmp/savid_tmp
    }
    scanner {
        type: SAVI
        inprocess: YES
        maxscantime: 3
        maxrequesttime: 10
        deny: /dev
	deny: /proc
	deny: /sys
        savigrp: GrpArchiveUnpack 1
        savigrp: GrpInternet 1
        savists: Xml 1
    }
}

A short test shows, that Sophos SAVDI is working correctly:

# netcat -U /run/savdi/sssp.sockOK SSSP/1.0
SSSP/1.0 SCANFILE /home/myusername/.profile
ACC 5FC92A0F/1
DONE OK 0000 The function call succeeded

SSSP/1.0 SCANFILE /tmp/eicar.com
ACC 5FC92A0F/2
VIRUS EICAR-AV-Test /tmp/eicar.com
OK 0203 /tmp/eicar.com
DONE OK 0203 Virus found during virus scan

But Samba hangs during file download and crashes after the timeout:

# smbclient //localhost/share1
Enter WORKGROUP\myusername's password: 
Try "help" to get a list of possible commands.
smb: \> mget .profile
Get file .profile? y
NT_STATUS_IO_TIMEOUT opening remote file \.profile
smb: \> SMBecho failed (NT_STATUS_CONNECTION_RESET). The connection is disconnected now

# /tmp/samba-4.13.2-orig/sbin/smbd --foreground --no-process-group --interactive --configfile=/tmp/smb.conf
smbd version 4.13.2 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
debug_lookup_classname(virusfilter): Unknown class
[...]
Processing section "[share1]"
Initialising default vfs hooks
[...]
Initialising custom vfs hooks from [virusfilter]
vfs_find_backend_entry called for virusfilter
vfs module [virusfilter] not loaded - trying to load...
vfs_find_backend_entry called for virusfilter
Successfully added vfs backend 'virusfilter'
samba_init_module: Debug class number: 38
samba_init_module: registered
vfs_find_backend_entry called for virusfilter
Successfully loaded vfs module [virusfilter] with the new modules system
[...]
check_reduced_name realpath [.profile] -> [/home/myusername/.profile]
check_reduced_name: .profile reduced to /home/myusername/.profile
virusfilter_scan: Searching cache entry: fname: .profile
virusfilter_scan: Cache entry not found
virusfilter_sophos_scan_init: SSSP: Connecting to socket: /run/savdi/sssp.sock
virusfilter_io_readl: Error Connection timed out
===============================================================
INTERNAL ERROR: Signal 11: Segmentation fault in pid 7524 (4.13.2)
If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
===============================================================
PANIC (pid 7524): Signal 11: Segmentation fault in 4.13.2
BACKTRACE:
 #0 log_stack_trace + 0x28 [ip=0x7f11ac3c676a] [sp=0x7ffc6f342c80]
 #1 smb_panic_log + 0x1b1 [ip=0x7f11ac3c66f5] [sp=0x7ffc6f343580]
 #2 smb_panic + 0x18 [ip=0x7f11ac3c6710] [sp=0x7ffc6f3435a0]
 #3 fault_report + 0x78 [ip=0x7f11ac3c62d8] [sp=0x7ffc6f3435c0]
 #4 sig_fault + 0x15 [ip=0x7f11ac3c62ed] [sp=0x7ffc6f343660]
 #5 funlockfile + 0x60 [ip=0x7f11abb421d0] [sp=0x7ffc6f343680]
 #6 __strncmp_sse42 + 0x97 [ip=0x7f11ab98c457] [sp=0x7ffc6f343ad8]
 #7 virusfilter_sophos_scan_init + 0x40a [ip=0x7f11a8579880] [sp=0x7ffc6f343ae0]
 #8 virusfilter_scan + 0x269 [ip=0x7f11a857710f] [sp=0x7ffc6f343b20]
 #9 virusfilter_vfs_openat + 0x956 [ip=0x7f11a85780c4] [sp=0x7ffc6f343b90]
 #10 smb_vfs_call_openat + 0x73 [ip=0x7f11ac1e53cd] [sp=0x7ffc6f343c50]
 #11 non_widelink_open + 0x255 [ip=0x7f11ac1cd321] [sp=0x7ffc6f343c90]
 #12 fd_open + 0xa4 [ip=0x7f11ac1cd54f] [sp=0x7ffc6f343d10]
 #13 fd_openat + 0x52 [ip=0x7f11ac1cd7d6] [sp=0x7ffc6f343d70]
 #14 fd_open_atomic + 0x54 [ip=0x7f11ac1ce3d8] [sp=0x7ffc6f343dc0]
 #15 open_file + 0x4f7 [ip=0x7f11ac1ceab1] [sp=0x7ffc6f343e10]
 #16 open_file_ntcreate + 0xf13 [ip=0x7f11ac1d4589] [sp=0x7ffc6f343ed0]
 #17 create_file_unixpath + 0xa2d [ip=0x7f11ac1d9123] [sp=0x7ffc6f3440d0]
 #18 create_file_default + 0x4ef [ip=0x7f11ac1d9dc0] [sp=0x7ffc6f3441e0]
 #19 vfswrap_create_file + 0x74 [ip=0x7f11ac14e29e] [sp=0x7ffc6f344370]
 #20 smb_vfs_call_create_file + 0x9e [ip=0x7f11ac1e546d] [sp=0x7ffc6f344420]
 #21 smbd_smb2_create_send + 0x112e [ip=0x7f11ac22e2fe] [sp=0x7ffc6f3444d0]
 #22 smbd_smb2_request_process_create + 0x708 [ip=0x7f11ac22c089] [sp=0x7ffc6f344830]
 #23 smbd_smb2_request_dispatch + 0x1345 [ip=0x7f11ac21e1b4] [sp=0x7ffc6f344940]
 #24 smbd_smb2_io_handler + 0x819 [ip=0x7f11ac222ee6] [sp=0x7ffc6f344a20]
 #25 smbd_smb2_connection_handler + 0x4a [ip=0x7f11ac222fef] [sp=0x7ffc6f344b10]
 #26 tevent_common_invoke_fd_handler + 0x7d [ip=0x7f11abb5ba3d] [sp=0x7ffc6f344b50]
 #27 tevent_common_loop_timer_delay + 0xa97 [ip=0x7f11abb5f4d7] [sp=0x7ffc6f344b80]
 #28 tevent_common_fd_set_close_fn + 0x767 [ip=0x7f11abb57f47] [sp=0x7ffc6f344be0]
 #29 _tevent_loop_once + 0x94 [ip=0x7f11abb5b404] [sp=0x7ffc6f344c00]
 #30 tevent_common_loop_wait + 0x1b [ip=0x7f11abb5b4fb] [sp=0x7ffc6f344c30]
 #31 tevent_common_fd_set_close_fn + 0x7d7 [ip=0x7f11abb57fb7] [sp=0x7ffc6f344c50]
 #32 smbd_process + 0xc9a [ip=0x7f11ac20306d] [sp=0x7ffc6f344c70]
 #33 smbd_accept_connection + 0x17b [ip=0x563f7b910619] [sp=0x7ffc6f344d40]
 #34 tevent_common_invoke_fd_handler + 0x7d [ip=0x7f11abb5ba3d] [sp=0x7ffc6f344e20]
 #35 tevent_common_loop_timer_delay + 0xa97 [ip=0x7f11abb5f4d7] [sp=0x7ffc6f344e50]
 #36 tevent_common_fd_set_close_fn + 0x767 [ip=0x7f11abb57f47] [sp=0x7ffc6f344eb0]
 #37 _tevent_loop_once + 0x94 [ip=0x7f11abb5b404] [sp=0x7ffc6f344ed0]
 #38 tevent_common_loop_wait + 0x1b [ip=0x7f11abb5b4fb] [sp=0x7ffc6f344f00]
 #39 tevent_common_fd_set_close_fn + 0x7d7 [ip=0x7f11abb57fb7] [sp=0x7ffc6f344f20]
 #40 smbd_parent_loop + 0x96 [ip=0x563f7b9114b7] [sp=0x7ffc6f344f40]
 #41 main + 0x18b4 [ip=0x563f7b91363f] [sp=0x7ffc6f344f70]
 #42 __libc_start_main + 0xf2 [ip=0x7f11ab859152] [sp=0x7ffc6f345330]
 #43 _start + 0x2e [ip=0x563f7b90908e] [sp=0x7ffc6f345400]
coredump is handled by helper binary specified at /proc/sys/kernel/core_pattern
Aborted (core dumped)
Comment 1 Bjoern Voigt 2020-12-03 18:47:44 UTC
Created attachment 16356 [details]
Fix incorrect error handling in virusfilter_io_readl

Debugging shows, that virusfilter_sophos_scan_init in source3/modules/vfs_virusfilter_sophos.c fails in virusfilter_io_readl(talloc_tos(), io_h, &reply) with a timeout. Unfortunately "ok" is still true, but "reply" is NULL. The attached patch fixes this problem. But the patch only repairs the crash, not the timeout problem itself.
Comment 2 Jeremy Allison 2020-12-03 19:08:52 UTC
Unfortunately we don't have a Sophos setup in our regression test suite in order to maintain this code.

Would you be willing to help us with the maintanence by testing releases and giving us feedback/patches as needed to keep this module operational ?
Comment 3 Bjoern Voigt 2020-12-03 19:26:33 UTC
ClamAV is unaffected from this bug. E.g. this configuration works without problems.

[global]
	workgroup = WORKGROUP
	passdb backend = tdbsam
	log level = 2 vfs:10 virusfilter:10
[share1]
	path = /home/bv
	read only = No
	# Samba ClamAV configuration
	vfs objects = virusfilter
	virusfilter:infected file action = rename
	virusfilter:rename suffix = .infected
	virusfilter:scanner = clamav
	virusfilter:socket path = /var/run/clamav/clamd-socket
Comment 4 Bjoern Voigt 2020-12-03 19:28:25 UTC
(In reply to Jeremy Allison from comment #2)

Yes, of course I will try to help you with testing.
Comment 5 Jeremy Allison 2020-12-08 01:13:21 UTC
Can you add some DBG_ERR(... returned text...); lines to virusfilter_io_readl() so we can see what Samba is getting back when talking to Sophos (after your patch has been applied first of course) ?
Comment 6 Bjoern Voigt 2020-12-08 13:06:11 UTC
Created attachment 16361 [details]
More debug messages and fix incorrect error handling in virusfilter_io_readl

This patch adds more debug messages for virusfilter_io_readl and fixes error handling.

The logging messages for a file download are:
virusfilter_sophos_scan_init: SSSP: Connecting to socket: /run/savdi/sssp.sock
virusfilter_io_readl: virusfilter_io_readl loop with index i=0.
virusfilter_io_readl: tstream_pending_bytes pending=0.
virusfilter_io_readl: virusfilter_io_readl read_size=12416.
virusfilter_io_readl: Enter tevent_req_poll
virusfilter_io_readl: Leave tevent_req_poll ok=1
virusfilter_io_readl: Error Connection timed out
virusfilter_io_readl: virusfilter_io_readl ok=0
virusfilter_sophos_scan_init: SSSP: Reading greeting message failed: Connection timed out
virusfilter_sophos_scan_end: SSSP: Disconnecting
Comment 7 Bjoern Voigt 2020-12-08 13:13:40 UTC
(In reply to Jeremy Allison from comment #5)
I have done this. The virusfilter module fails to read the greeting message from Sophos SAVDI with a timeout. The Sophos SAVDI module logs that the connection of the virusfilter client terminated too early:

201208:140853 00034411 Processing finishing gracefully
    PID: 8161
201208:140854 00034408 Process exiting
    PID: 8161
201208:140904 00034407 Process starting
    PID: 18203
201208:140914 [5FCF7AF1] 00038400 New connection
    To: /var/run/savdi/sssp.sock From User (0, 0), process 18215
201208:140914 [5FCF7AF1] 00038402 New session
201208:141014 [5FCF7AF1] C000460B Client terminated connection early
201208:141014 [5FCF7AF1] 00038403 Session ended
201208:141014 [5FCF7AF1] 00038401 Connection ended
    To: /var/run/savdi/sssp.sock From User (0, 0), process 18215
Comment 8 Bjoern Voigt 2020-12-08 14:45:57 UTC
If I insert usleep(500000) between virusfilter_io_connect_path() and virusfilter_io_readl() in virusfilter_sophos_scan_init, I get the following logging.

pending is 13 characters, but still tevent_req_poll gets a timeout.

virusfilter_sophos_scan_init: SSSP: Connecting to socket: /run/savdi/sssp.sock
virusfilter_io_readl: virusfilter_io_readl loop with index i=0.
virusfilter_io_readl: tstream_pending_bytes pending=13.
virusfilter_io_readl: virusfilter_io_readl read_size=12416.
virusfilter_io_readl: Enter tevent_req_poll
virusfilter_io_readl: Leave tevent_req_poll ok=1
virusfilter_io_readl: Error Connection timed out
virusfilter_io_readl: virusfilter_io_readl ok=0
virusfilter_sophos_scan_init: SSSP: Reading greeting message failed: Connection timed out
virusfilter_sophos_scan_end: SSSP: Disconnecting
Comment 9 Bjoern Voigt 2020-12-08 15:22:00 UTC
For testing without a real Sophos SAVDI daemon the "netcat" utility can be used. To simulate the Sophos SAVDI greeting message use 

echo -e "OK SSSP/1.0\r" | netcat -l -U /tmp/sssp.sock

together with "virusfilter:socket path = /tmp/sssp.sock" in smb.conf.
Comment 10 Matthias Leopold 2021-02-01 09:51:25 UTC
I just want to add that I'm also affected by this bug and want to see it resolved. Our institution (education) would like to use Samba with Sophos. I can contribute testing and debugging if needed.