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)
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.
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 ?
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
(In reply to Jeremy Allison from comment #2) Yes, of course I will try to help you with testing.
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) ?
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
(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
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
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.
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.