Interpreting SSH Server Log Files using Microsoft Log Parser

Bitvise SSH Server's textual log files are recorded in a machine processable XML format. It is straightforward to process XML files using any .NET language, but another way to extract information from Bitvise SSH Server log files is using Microsoft Log Parser.

When using MS Log Parser, it is important to use the following parameters:

-fNames:XPath -fMode:Tree

With the -fNames:XPath parameter, field names will appear unambiguously, using the full XPath of the attribute to which they refer. The default setting, "compact", can assign unpredictable field names to attributes used in different types of log entries.

If the SSH Server is running...

If the SSH Server is currently running, then it keeps the most recent log file open for writing. The Log Parser will then refuse to process that log file.

To work around this, you can either stop the SSH Server, or copy the log files to another directory before processing. You can copy the most recent log file as well, even while it is open for writing.

Examples with I_LOGON_AUTH_COMPLETED

A basic command to find out who and when logged onto the server:

LogParser -q -i:XML -fNames:XPath -fMode:Tree "SELECT /log/event/@time, /log/event/conn/@windowsAccount, /log/event/conn/@virtualAccount FROM *.log WHERE /log/event/@name = 'I_LOGON_AUTH_COMPLETED'"

We can shorten the paths using the -rootXPath parameter:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time, /event/conn/@windowsAccount, /event/conn/@virtualAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED'"

We can use aliases to clarify output headers:

Show only logons to Windows accounts:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@windowsAccount AS WinAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND /event/conn/@virtualAccount IS NULL"

Show only logons to virtual accounts - we can use the VirtAccount alias in the WHERE clause to shorten the command:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@virtualAccount AS VirtAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND VirtAccount IS NOT NULL"

Show all Windows and virtual logons on a specific date (local time):

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@windowsAccount AS WinAccount, /event/conn/@virtualAccount AS VirtAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND Time BETWEEN '2022-08-07' AND '2022-08-08'"

Find the first login time for the virtual user "Michele":

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT MIN(/event/@time) FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND /event/conn/@virtualAccount LIKE 'Michele'"

Measure the effectiveness of Windows session sharing. Count how many connections created a new Windows logon session, vs. how many connections reused an existing Windows logon session:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/conn/@winSes AS winSes, COUNT(/event/conn/@winSes) FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' GROUP BY /event/conn/@winSes"

Example with I_SERVICE_CONFIG_DESCRIPTION

Find when the SSH Server first logged settings containing a virtual account named "Michele":

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT MIN(/event/@time) FROM *.log WHERE /event/@name = 'I_SERVICE_CONFIG_DESCRIPTION' AND (/event/settings/powerShell#CDATA LIKE '%.new.virtAccount = \"Michele\"%' OR /event/settings/powerShellDiff#CDATA LIKE '%.new.virtAccount = \"Michele\"%')"

If the SSH Server was stopped when the account was created, this will find the first time the SSH Server was started with settings that contained this account.

It is necessary to search both /event/settings/powerShell#CDATA, which is logged when the SSH Server is started, and /event/settings/powerShellDiff#CDATA, which is logged subsequently if settings are changed.

Examples with I_SFS_TRANSFER_FILE

Find out who and when transferred which files:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@windowsAccount AS WinAccount, /event/conn/@virtualAccount AS VirtAccount, /event/sfs/parameters/@path AS Path, /event/sfs/parameters/@bytesWritten AS BytesWritten, /event/sfs/parameters/@bytesRead AS BytesRead FROM *.log WHERE /event/@name = 'I_SFS_TRANSFER_FILE'"

Limit the above query to files that have only been written:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@windowsAccount AS WinAccount, /event/conn/@virtualAccount AS VirtAccount, /event/sfs/parameters/@path AS Path, /event/sfs/parameters/@bytesWritten AS BytesWritten, /event/sfs/parameters/@bytesRead AS BytesRead FROM *.log WHERE /event/@name = 'I_SFS_TRANSFER_FILE' AND BytesWritten <> 0"

Find out who removed which '*.docx' or '*.doc' files (case-insensitive) on August 7, 2022, between 2 pm and 7:30 pm (local time):

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/conn/@windowsAccount AS WinAccount, /event/conn/@virtualAccount AS VirtAccount, /event/sfs/parameters/@path AS Path FROM *.log WHERE /event/@name = 'I_SFS_REMOVE_FILE' AND /event/@time BETWEEN '2022-08-07 14:00' AND '2022-08-07 19:30' AND (Path LIKE '%.docx' OR Path LIKE '%.doc')"

Events and IP addresses

Enumerate all distinct IP addresses from which authenticated users have connected:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT DISTINCT EXTRACT_PREFIX(/event/conn/@remoteAddress, 0, ':') AS RemoteAddress, /event/conn/@windowsAccount AS WinAccount, /event/conn/@virtualAccount AS VirtAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED'"

List the times, connection IDs and names of events from a set of remote IP addresses:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@id as Id, EXTRACT_PREFIX(/event/conn/@remoteAddress, 0, ':') AS RemoteAddress, /event/@name as Event from '*.log' where EXTRACT_PREFIX(/event/conn/@remoteAddress, 0, ':') in ('10.1.1.7'; '192.168.1.3'; '127.0.0.1')"

Enumerate the times and IP addresses of logons for a virtual user named "Michele". Use LIKE to match the username without case sensitivity:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@remoteAddress AS RemoteAddress FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND /event/conn/@virtualAccount LIKE 'Michele'"

Enumerate distinct IP addresses from which the virtual user "Michele" has connected:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT DISTINCT EXTRACT_PREFIX(/event/conn/@remoteAddress, 0, ':') AS RemoteIP FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND /event/conn/@virtualAccount LIKE 'Michele'"

Enumerate the times and IP addresses of all logons for virtual users whose name starts with "M" or "m":

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time AS Time, /event/conn/@remoteAddress AS RemoteAddress, /event/conn/@virtualAccount AS VirtAccount FROM *.log WHERE /event/@name = 'I_LOGON_AUTH_COMPLETED' AND VirtAccount LIKE 'M%'"

Events sorted by connection ID

Show events and IP addresses ordered by connection ID first, and then timestamp:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/conn/@id AS Id, SUBSTR(/event/@time, 11, 11) AS Time, EXTRACT_PREFIX(/event/conn/@remoteAddress, 0, ':') AS RemoteAddress, /event/@name AS Event FROM '*.log' ORDER BY Id, Time"

Events for a specific account

List the times, connection IDs and names of events associated with a specific Windows account. This will not include events about the start of a connection, since the user is not yet authenticated at that time:

Extracting negotiated algorithms

If your settings still enable SSH algorithms which are no longer recommended for use, you can check if any clients are using those algorithms before you disable them. The following example extracts information about SSH algorithms negotiated by any client in available log files:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time as Time, /event/conn/@id as Id, /event/conn/@remoteAddress as RemoteAddr, /event/parameters/@kexAlg as KexAlg, /event/parameters/@hostKeyAlg as HostKeyAlg, /event/parameters/@cipherAlgIn as CipherAlgIn, /event/parameters/@cipherAlgOut as CipherAlgOut, /event/parameters/@macAlgIn as MacAlgIn, /event/parameters/@macAlgOut as MacAlgOut FROM *.log WHERE /event/@name='I_SSH_KEY_EXCHANGE_ALGORITHMS'"

For several algorithms, Bitvise software logs friendly names because some of the technical names are unintuitive or verbose. The algorithm "ssh-rsa" is recorded as either "RSA" or "RSA/sha1", depending on whether it's used as a public key format or a signature algorithm. The algorithms "rsa-sha2-256" and "rsa-sha2-512" are recorded as "RSA/sha2-256" and "RSA/sha2-512".

If you are processing log files generated by older SSH Server versions, the query requires some adaptations. For log files generated by versions 8.xx, replace /event/conn with /event/session, and I_SSH_KEY_EXCHANGE_ALGORITHMS with I_SESSION_KEY_EXCHANGE_ALGORITHMS:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time as Time, /event/session/@id as Id, /event/session/@remoteAddress as RemoteAddr, /event/parameters/@kexAlg as KexAlg, /event/parameters/@hostKeyAlg as HostKeyAlg, /event/parameters/@cipherAlgIn as CipherAlgIn, /event/parameters/@cipherAlgOut as CipherAlgOut, /event/parameters/@macAlgIn as MacAlgIn, /event/parameters/@macAlgOut as MacAlgOut FROM *.log WHERE /event/@name='I_SESSION_KEY_EXCHANGE_ALGORITHMS'"

If you enabled support for FTPS, the following example extracts information about the TLS protocol and cipher suite negotiated by FTPS clients:

LogParser -q -i:XML -fNames:XPath -fMode:Tree -rootXPath:/log/event "SELECT /event/@time as Time, /event/conn/@id as Id, /event/conn/@remoteAddress as RemoteAddr, /event/parameters/@protocol as Protocol, /event/parameters/@cipherSuite as CipherSuite FROM *.log WHERE /event/@name='I_FTP_CONTROL_TLS_NEGOTIATED'"

Processing statistics files

In addition to log files, the SSH Server maintains usage statistics in XML format. These are stored in the Stats subdirectory of the SSH Server installation directory. Statistics files can also be processed using MS Log parser. For example:

LogParser -q -i:XML -fNames:XPath -q -fMode:Tree "SELECT DISTINCT /stats/@type, /stats/@account, /stats/info/@lastLogin FROM *.xml"

This will display the last login time for each virtual and Windows account recorded in SSH Server statistics.

More Information

For more information on the Log Parser's SQL SELECT statement, execute:

LogParser -h GRAMMAR

We also suggest checking out the -o:DATAGRID output format.