Castaglia / proftpd-mod_clamav

Customised version of proftpd mod_clamav
3 stars 1 forks source link

logging #3

Open dfosborne2 opened 11 years ago

dfosborne2 commented 11 years ago

Hi. Looking around on the forums and on the castaglia page I see that you do a lot of work with proftpd. Thank you. As python and shell script are about as good as it gets with programming for me, Im curious if there is a way to get mod_clamav to log up into the ExtendedLog I have configured for my sftp service. Running proftpd in debug level 10, I can see the logging where the scanning of the file takes place. Is there anything configuration-wise that I can do to bring the logging up into the Extended log? I was messing around with the pr_log_debug(DEBUG4....) entries in mod_clamav via changing it to pr_log_pri(PR_LOG_ERR......) but still could only see mod_clamav logging when running in debug mode.

Also when sending a file with the EICAR signature via sftp on cmd line this is what my client spits back when the virus is detected:

sftp> put /tmp/eicarcom2.zip Uploading /tmp/eicarcom2.zip to /eicarcom2.zip /tmp/eicarcom2.zip 100% 308 0.3KB/s 00:00
Couldn't close file: Permission denied sftp>

I know it was mentioned in the previous issue that this might be out the server's control, but want to make sure I if I understood you correctly.

Here are some vitals:

ProFTPD Version: 1.3.4 (stable) Scoreboard Version: 01040003 Built: Wed Apr 24 2013 17:59:53 GMT

Loaded modules: mod_cap/1.1 mod_clamav/0.10b mod_ldap/2.9.0 mod_sftp/0.9.8 mod_radius/0.9.2 mod_ident/1.0 mod_dso/0.5 mod_facts/0.3 mod_delay/0.7 mod_site.c mod_log.c mod_ls.c mod_auth.c mod_auth_file/0.9 mod_auth_unix.c mod_xfer.c mod_core.c

And here are snippets of my proftpd.conf:

<Global>
    <IfModule mod_clamav.c>
         ClamAV on
         ClamServer 127.0.0.1
         ClamPort 3310
    </IfModule>

</Global>

<VirtualHost 0.0.0.0>

  SFTPEngine on
  Port 2206
  RadiusNASIdentifier stage6

  SFTPHostKey         /usr/local/etc/certs/stage6_ssh_host_dsa_key
  SFTPHostKey         /usr/local/etc/certs/stage6_ssh_host_rsa_key
  SFTPAuthorizedUserKeys      file:~/.ssh/authorized_keys
  SFTPClientMatch     WinSCP|ClientSftp sftpProtocolVersion 2-3
  SFTPDisplayBanner   /usr/local/etc/proftp_banner

  TransferLog         /var/log/proftpd/xferlog_stage6.log ALL
  ExtendedLog         /var/log/proftpd/sftp_stage6.log AUTH,DIRS,READ,WRITE,MISC 

  SFTPOptions IgnoreSFTPSetPerms IgnoreSFTPUploadPerms IgnoreSCPUploadPerms 
  SFTPLog /var/log/mod_sftp.log

    <IfModule mod_ldap.c>
           LDAPServer "ldapvip.XXXX"
           LDAPUsers ou=Client,dc=users,dc=XXXX,dc=base (uid=%u)
    </IfModule>
</VirtualHost>
Castaglia commented 11 years ago

Just to clarify my understand: what specific mod_clamav information are you hoping to see in a log file? It may be that using ExtendedLog is not the best log file for the information you want (or it might be) -- I'd like to get a better idea of what you'd like to achieve.

Castaglia commented 11 years ago

Doh...hit the wrong button, sorry.

As for the SFTP "Permission denied" issue, please file a separate issue for that, so that progress/discussion on that can be tracked separately from mod_clamav logging issues.

dfosborne2 commented 11 years ago

Hi. Thanks for taking the time to look at this. When I run proftpd in debug level 10 mode I can see the debug log messages that mod_clamav writes. A message does show in clamd.log when a virus is found. Would setting the pri_log_debug to pri_log_info (or warn or crit) be sufficient? Basically, Id like to be aware of every file that gets scanned, regardless of outcome, and the associated account that made the upload.

So for my extended log I have this data:

vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:29 +0000] "USERAUTH_REQUEST automation@xxxxx.net password" - -
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:29 +0000] "PASS" - -
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:29 +0000] "CHANNEL_OPEN session" - -
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:29 +0000] "CHANNEL_REQUEST subsystem"    
 - -
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:29 +0000] "INIT 3" - -
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:39 +0000] "OPEN /eicarcom2.zip" - 0
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:39 +0000] "WRITE 0yrwIw" 0 308
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:39 +0000] "STOR /eicarcom2.zip" - 308
vftp63.dulis1 UNKNOWN automation@xxxxx.net [30/Apr/2013:14:48:39 +0000] "CLOSE 0yrwIw" 3 -

Would be great that during that session that the logs info writing to pri_log_debug in mod_clamav could write as info and warn based off the success of the scan.

Debug output below. (I will open up another issue with proftpd on the permission denied. Will do a bit more homework to get as much detail into that...)

vftp63.dulis1 proftpd[10576] 0.0.0.0 (10.160.25.102[10.160.25.102]): SSH2 session closed.
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching PRE_CMD command 'STOR  
/eicarcom2.zip' to mod_core
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching PRE_CMD command 'STOR' 
/eicarcom2.zip' to mod_core
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching PRE_CMD command 'STOR 
/eicarcom2.zip' to mod_xfer
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): in dir_check_full(): path = '/eicarcom2.zip', 
fullpath = '/nfs/p6/ftp/49b36da8-13b9a4e3177-16b4f05e31352eae8b3a7020ce930c8b/eicarcom2.zip'.
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): in dir_check_full(): setting umask to 0002 (was
0002)
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching LOG_CMD command 'OPEN   
/eicarcom2.zip' to mod_log
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): in dir_check_full(): path = '/eicarcom2.zip',
fullpath = '/nfs/p6/ftp/49b36da8-13b9a4e3177-16b4f05e31352eae8b3a7020ce930c8b/eicarcom2.zip'.
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): in dir_check_full(): setting umask to 0002 (was 
0002)
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching LOG_CMD command 'WRITE 
0yrwIw' to mod_log
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): mod_clamav/0.10b: absolute path is 
'/nfs/p6/ftp/49b36da8-13b9a4e3177-16b4f05e31352eae8b3a7020ce930c8b/eicarcom2.zip', relative path is  
'/eicarcom2.zip'
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): mod_clamav/0.10b: Going to virus scan  
absolute filename = '/nfs/p6/ftp/49b36da8-13b9a4e3177-16b4f05e31352eae8b3a7020ce930c8b/eicarcom2.zip' with      
relative filename = '/eicarcom2.zip'.
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): mod_clamav/0.10b: Connecting to remote
Clamd host '127.0.0.1' on port 3310
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): ROOT PRIVS at mod_clamav.c:269
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): ROOT PRIVS: ID switching disabled
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): RELINQUISH PRIVS at mod_clamav.c:327
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): RELINQUISH PRIVS: ID switching disabled
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): mod_clamav/0.10b: Successfully reconnected
to Clamd
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): mod_clamav/0.10b: Virus 'Eicar-Test-Signature 
FOUND
' found in '/nfs/p6/ftp/49b36da8-13b9a4e3177-16b4f05e31352eae8b3a7020ce930c8b/eicarcom2.zip'
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching LOG_CMD_ERR command 'STOR 
/eicarcom2.zip' to mod_log
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching LOG_CMD_ERR command 'STOR 
/eicarcom2.zip' to mod_xfer
vftp63.dulis1 proftpd[10569] 0.0.0.0 (vftp63.dulis1[10.160.11.66]): dispatching LOG_CMD_ERR command 'CLOSE 
0yrwIw' to mod_log
vftp63.dulis1 proftpd[10578] vftp63.dulis1: ROOT PRIVS at main.c:1261
vftp63.dulis1 proftpd[10578] vftp63.dulis1: RELINQUISH PRIVS at main.c:1265