How to monitor SFTP logs on windows server using Splunk Stream?

[muradgh]

Hi All,

I'm trying to get the SFTP network data protocol logs from an SFTP server (windows server) that has a universal forwarder on it, I have found the Splunk App for Stream:
https://splunkbase.splunk.com/app/1809/

I have configured everything in its place, but the issue here is that this app can monitor several network data protocols but not SFTP, the most relative protocol is FTP as shown below:

I have enabled the FTP as shown above but I can't see any traffic from it, even though I have enabled some other protocols and I saw traffic as shown below:

What can I do about this to get the SFTP logs?

Thanks.

[diogofgm]

Yes, the encryption does limit the amount of information you can get from those stream events.

Does the sftp server log something (i.e log file, wineventlog, etc )? maybe going that route to gather details on the activity instead of stream? 

[muradgh]

The server has Bitvise on it, which is an SSH software for Windows, it's something like PuTTY or MobaXterm.

I have the application's log path, I can monitor this path using the universal forwarder but I prefer not to go through the hassle of manually parsing the logs because I'm not aware that Bitvise has an addon for parsing its logs.

That's why I was hoping that the Splunk Stream will handle the parsing and the dashboards.

[diogofgm]

I could help with the TA part for that data but from a quick check it seems that bitwise saves the logs in xml. can you confirm that?

[muradgh]

Hi @diogofgm 
Sorry for the late reply,
the logs are saved in .log format, but the content is XML 

I have attached a sample of the logs:

I have blurred the sensitive data:

<?xml version="1.0" encoding="UTF-8" ?>
<log>
  <start time="2022-03-22 09:31:07.134007 -0700" appName="BvSshServer" appVersion="9.14" thisFile="C:\Program Files\Bitvise SSH Server\Logs\BvSshServer20220322-093107131-M0700.log"/>

  <event seq="1" time="2022-03-22 09:31:07.128304 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_CONFIG_DESCRIPTION" desc="Configuration description.">
    <parameters configPart="ServerSettings"/>
    <change time="2022-03-20 18:22:53.266247 -0700" action="Settings edited via local Easy Settings interface by 'xxxxxxx'." process="BssCtrl.exe"/>
    <change time="2022-03-03 11:03:35.845336 -0700" action="Settings edited via local Easy Settings interface by 'xxxxxxx'." process="BssCtrl.exe"/>
    <change time="2022-02-23 09:46:56.994154 -0700" action="Settings edited via local Easy Settings interface by 'xxxxxxx'." process="BssCtrl.exe"/>
    <change time="2022-02-16 14:25:43.341806 -0700" action="Settings edited via local Easy Settings interface by 'xxxxxxx'." process="BssCtrl.exe"/>
    <change time="2022-02-16 14:00:42.100136 -0700" action="Settings edited via local Easy Settings interface by 'xxxxxxx'." process="BssCtrl.exe"/>
    <settings fullSettingsLogReason="Startup">
      <powerShell><![CDATA[
        $cfg = new-object -com "Bitvise.BssCfg.912"
        
        $cfg.settings.SetDefaults()
        $cfg.settings.bindings.SetDefaults()
        $cfg.settings.bindings.ipv6.Clear()
        $cfg.settings.algs.SetDefaults()
        $cfg.settings.algs.kex.SetDefaults()
        $cfg.settings.algs.kex.gssG15Sha512Krb5 = $false
        $cfg.settings.algs.kex.gssG14Sha256Krb5 = $false
        $cfg.settings.access.SetDefaults()
        $cfg.settings.access.kerberos5Auth = 1 # $cfg.enums.GlobalGssApiAuth.disabled
        $cfg.settings.access.ntlmAuth = 1 # $cfg.enums.GlobalGssApiAuth.disabled
        $cfg.settings.access.virtAccounts.Clear()
        $cfg.settings.access.virtAccounts.new.SetDefaults()
        $cfg.settings.access.virtAccounts.new.virtAccount = "xxxxxxx"
        $cfg.settings.access.virtAccounts.new.virtPassword.crypt = "xxxxxxx"
        $cfg.settings.access.virtAccounts.new.group = "Virtual Users"
        $cfg.settings.access.virtAccounts.new.loginAllowed = 1 # $cfg.enums.DefaultGroupYesNo.yes
        $cfg.settings.access.virtAccounts.new.term.SetDefaults()
        $cfg.settings.access.virtAccounts.new.term.shellAccessType = 10 # $cfg.enums.ShellAccess.bvshell
        $cfg.settings.access.virtAccounts.new.xfer.SetDefaults()
        $cfg.settings.access.virtAccounts.new.xfer.permitScp = 1 # $cfg.enums.DefaultGroupYesNo.yes
        $cfg.settings.access.virtAccounts.new.xfer.permitSftp = 1 # $cfg.enums.DefaultGroupYesNo.yes
        $cfg.settings.access.virtAccounts.new.xfer.permitFtps = 1 # $cfg.enums.DefaultGroupYesNo.yes
        $cfg.settings.access.virtAccounts.new.xfer.inheritMountPoints = $false
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.Clear()
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.SetDefaults()
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.sfsMountPath = "/INBOUND"
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.realRootPath = "\\xxxxxxx\INBOUND"
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.NewCommit()
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.SetDefaults()
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.sfsMountPath = "/OUTBOUND"
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.new.realRootPath = "\\xxxxxxx\OUTBOUND"
        $cfg.settings.access.virtAccounts.new.xfer.mountPoints.NewCommit()
        $cfg.settings.access.virtAccounts.new.xfer.useDefaultSfsHomeDir = $false
        $cfg.settings.access.virtAccounts.new.fwding.SetDefaults()
        $cfg.settings.access.virtAccounts.new.fwding.permitC2S = 2 # $cfg.enums.DefaultGroupYesNo.no
        $cfg.settings.access.virtAccounts.new.fwding.permitS2C = 2 # $cfg.enums.DefaultGroupYesNo.no
        $cfg.settings.access.virtAccounts.new.creationTime = "2022-02-16 09:26:43 -0800"
        $cfg.settings.access.virtAccounts.NewCommit()
        
        $cfg.settings.Save()
      ]]></powerShell>
    </settings>
  </event>

  <event seq="2" time="2022-03-22 09:31:07.135165 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_CONFIG_DESCRIPTION" desc="Configuration description.">
    <parameters configPart="HostKeys" keypairCount="2"/>
    <keypair algorithm="RSA" keyBits="3072" md5="xxxxxxx" babble="xutat-luvyh-rebud-hisyd-pylin-bagor-votah-mazum-socym-rafun-laxux" sha256="xxxxxxx"/>
    <keypair algorithm="ECDSA/nistp384" keyBits="384" md5="xxxxxxx" babble="xosab-vokun-madas-kaben-fenim-ginyd-tityr-dumog-gosab-kycym-laxax" sha256="xxxxxxx"/>
  </event>

  <event seq="3" time="2022-03-22 09:31:07.135260 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_CONFIG_DESCRIPTION" desc="Configuration description.">
    <parameters configPart="Certificates" certificateCount="1"/>
    <certificate issuedTo="Bitvise SSH Server" issuedBy="Bitvise SSH Server" serial="xxxxxxx"/>
  </event>

  <event seq="4" time="2022-03-22 09:31:08.044899 -0700" app="BvSshServer 9.14" type="Info" name="I_AUTO_ACCOUNT_ENABLED" desc="Enabled the automatically managed local account for virtual users.">
    <parameters account="BvSsh_VirtualUsers"/>
  </event>

  <event seq="5" time="2022-03-22 09:31:08.080023 -0700" app="BvSshServer 9.14" type="Info" name="I_UPDATE_MANAGER_VERSION_STATUS" desc="SSH Server version status.">
    <parameters versionStatus="Unknown"/>
    <help message="The status of the currently installed version is unknown because there has not been a recent, successful check for updates."/>
  </event>

  <event seq="6" time="2022-03-22 09:31:08.188458 -0700" app="BvSshServer 9.14" type="Info" name="I_LOGON_WINDOWS_ACCOUNT_INFO_NOT_RETRIEVED" desc="Windows account information could not be retrieved.">
    <taskProfile taskProfile="Run as SSH Server service account" windowsAccount="xxxxxxx" tokenType="xxxxxxx"/>
    <parameters windowsAccount="xxxxxxx"/>
    <result type="xxxxxxx" operation="NetUserGetInfo()" code="xxxxxxx" message="The user name could not be found."/>
  </event>

  <event seq="7" time="2022-03-22 09:31:08.256719 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_SOCKET_BOUND" desc="Listening socket bound.">
    <parameters listenAddress="xxxxxxx" service="SSH" proxyProtocol="xxxxxxx"/>
  </event>

  <event seq="8" time="2022-03-22 09:31:08.258048 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_CONF_SYNC_SETTINGS_DESCRIPTION" desc="Description of synchronization settings.">
    <settings>
      <powerShell><![CDATA[
        $cfg = new-object -com "Bitvise.BssCfg.912"
        
        $cfg.instanceSettings.SetDefaults()
        $cfg.instanceSettings.update.SetDefaults()
        $cfg.instanceSettings.update.updateType = 0 # $cfg.enums.AutomaticUpdatesType.doNotCheck
        
        $cfg.instanceSettings.Save()
      ]]></powerShell>
    </settings>
  </event>

  <event seq="9" time="2022-03-22 09:31:08.259129 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_CONF_SYNC_SETTINGS_APPLIED" desc="Synchronization settings successfully applied."/>

  <event seq="10" time="2022-03-22 09:31:08.494823 -0700" app="BvSshServer 9.14" type="Info" name="I_SERVICE_STARTED" desc="Service started.">
    <parameters serviceAccount="xxxxxxx" sessionId="xxxxxxx" processId="xxxxxxx" exePath="C:\Program Files\Bitvise SSH Server\BvSshServer.exe" cryptoProvider="Windows CNG (x64) with additions" bootTime="2022-03-22 09:31:03 -0700" computerName="xxxxxxx" computerSid="xxxxxxx" computerDomainName="xxxxxxx" computerDnsDomainName="xxxxxxx.com" windowsVersion="10.0.17763 (64-bit)" servicePack="0" isDomainController="false" lsaProtection="0" lsaAuthPackages="msv1_0; BvLsaEx" bvLsaFileSize="xxxxxxx" bvLsaLastInitTime="2022-03-22 09:31:02 -0700" bvLsaVersion="20.5.0.4" bvAllocHook="true" bvAllocHeapCount="4"/>
  </event>

  <event seq="11" time="2022-03-22 21:28:51.088160 -0700" app="BvSshServer 9.14" type="Info" name="I_CONNECT_ACCEPTED" desc="Connection accepted.">
    <conn id="1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA"/>
    <location continent="xxxxxxx" country="xxxxxxx"/>
    <parameters addressRule="AnyIP" listenAddress="xxxxxxx"/>
    <conns ssh="xxxxxxx" sshAuth="0" ftp="0" ftpAuth="0" nrWinSes="3"/>
  </event>

  <event seq="12" time="2022-03-22 21:28:51.291613 -0700" app="BvSshServer 9.14" type="Info" name="I_CONNECT_VERSION_RECEIVED" desc="Client version string received.">
    <conn id="1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA"/>
    <parameters clientVersion="SSH-2.0-xxxxxxx-SSHD-2.6.0"/>
  </event>

  <event seq="13" time="2022-03-22 21:28:51.720621 -0700" app="BvSshServer 9.14" type="Info" name="I_SSH_KEY_EXCHANGE_ALGORITHMS" desc="Key exchange algorithms.">
    <conn id="1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA"/>
    <parameters kexAlg="diffie-hellman-group14-sha256" dhGroup="group 14" dhBits="2048" hostKeyAlg="RSA/sha1" cipherAlgIn="aes128-ctr" cipherAlgOut="aes128-ctr" macAlgIn="hmac-sha2-256" macAlgOut="hmac-sha2-256" comprAlgIn="none" comprAlgOut="none"/>
  </event>

  <event seq="14" time="2022-03-22 21:28:51.947523 -0700" app="BvSshServer 9.14" type="Info" name="I_LOGON_AUTH_COMPLETED" desc="User authentication completed successfully.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <authentication attemptNr="1" serialize="completion" userName="xxxxxxx" method="password"/>
    <parameters accountSettings="xxxxxxx" groupSettings="Virtual Users" tokenType="LogonUserPwd" tokenLogonType="Network" tokenElevation="Restricted" winSesUsesActive="1" winSesUsesCumul="1"/>
  </event>

  <event seq="15" time="2022-03-22 21:28:52.136976 -0700" app="BvSshServer 9.14" type="Info" name="I_CHANNEL_SESSION_OPENED" desc="Session channel opened.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <channel type="session" id="1"/>
  </event>

  <event seq="16" time="2022-03-22 21:28:52.898140 -0700" app="BvSshServer 9.14" type="Info" name="I_SFTP_SERVER_VERSION_NEGOTIATED" desc="SFTP protocol version negotiated.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <channel type="session" id="1"/>
    <parameters versionRequested="6" versionSelected="6"/>
  </event>

  <event seq="17" time="2022-03-22 21:28:54.038969 -0700" app="BvSshServer 9.14" type="Info" name="I_SFS_TRANSFER_FILE" desc="Virtual filesystem: transfer file.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <channel type="session" id="1"/>
    <sfs moduleName="FlowSfsWin" mountPath="/INBOUND" code="90000" desc="File transfer ended.">
      <parameters path="\\10.1.17.200\INBOUND\xxxxxxxorp EOD 20220322.csv" timeMs="390" bytesRead="0" bytesWritten="1560" readRangeOffset="0" readRangeLength="0" writeRangeOffset="0" writeRangeLength="1560" createdNewFile="true" resizedFile="false" startSize="0" finalSize="1560" endedBy="Client" download="none" upload="full"/>
      <help message="File transfer ended by client."/>
    </sfs>
  </event>

  <event seq="18" time="2022-03-22 21:28:54.637137 -0700" app="BvSshServer 9.14" type="Info" name="I_CHANNEL_SESSION_CLOSED" desc="Session channel closed.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <channel type="session" id="1"/>
    <parameters bytesReceived="1684" bytesSent="556"/>
  </event>

  <event seq="19" time="2022-03-22 21:28:54.638506 -0700" app="BvSshServer 9.14" type="Info" name="I_CONNECT_DISCONNECTED_NORMALLY" desc="Connection disconnected normally.">
    <conn id="1001" winSesId="C1001" service="SSH" remoteAddress="xxxxxxx" loc="US/NA" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers" winSes="new" cacheUse="late"/>
    <parameters reason="EofReceived" socketBytesReceived="3331" socketBytesSent="4068" payloadBytesReceived="2545" payloadBytesSent="2640" channelBytesReceived="1684" channelBytesSent="556"/>
    <conns ssh="0" sshAuth="0" ftp="0" ftpAuth="0" nrWinSes="4" winSesUsesActive="0"/>
    <help message="The client has disconnected the connection by sending EOF."/>
  </event>

  <event seq="20" time="2022-03-22 21:38:55.148379 -0700" app="BvSshServer 9.14" type="Info" name="I_WIN_SESSION_DISMISSED" desc="Windows session dismissed.">
    <winSession winSesId="C1001" winSesService="SSH" virtualAccount="xxxxxxx" windowsAccount="xxxxxxx-xxxxxxx\BvSsh_VirtualUsers"/>
    <conns ssh="0" sshAuth="0" ftp="0" ftpAuth="0" nrWinSes="3"/>
  </event>

Thanks.

[PickleRick]

SFTP is a file transfer mechanism using ssh as the network transport layer (a bit oversimplified but will suffice for us here). So everything is happening within a single encrypted ssh connection. Since ssh is encrypted you won't get anything more than just ssh connection parameters.

Log files is the way to go.

[diogofgm]

Haven't tried this myself but I would try to use the TCP stream with a filter for port 22

[muradgh]

Hi @diogofgm 

I have enabled the TCP protocol and found the SSH traffic, but I think because the SFTP is encrypted that's what I'm unable to see for example the filename which is the name of the transferred file in the SSH logs. so there are not many useful details for me.

Here is a sample SSH event log:

index=main sourcetype="stream:tcp" source="stream:tcp" app=ssh