Tips for text searching in several log files
This article describes how you can use the default Windows functions to search for the occurrence of specific string in various log files.
Imagine the scenario there is an issue with the LDAP replication of "user7" - the user was created in the past but now he is missing. Standard analytic tools (PSpad, Notepad ++, Total Commander...) cannot be installed in the environment for security reasons. There are 10 replicator log files with size 10MB for last 7 days and you need to find all records about this particular user to track the history of the changes. By filtering out of all the records related to this particular user you will be able to see, where the things went wrong. Reading all files one by one would take tremendous time.
Example from replicator.log:
2021-08-06 13:35:23,731 DEBUG Thread-20| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,DC=CSS,DC=LOCAL, ldapExtId=null, ldapMemberOfs=[CN=Domain Users,CN=Users,DC=CSS,DC=LOCAL], ldapCards=[], ldapAliases=[User7], additionalAttributes={})Option 1 - command find.exe
Command find is able to show quite nicely the name of the log file it has been looking at and also the string that has been found.
Usage:
find /i "user7" C:\SafeQ6\logs\replicator.* > c:\diagnosticoutput.txtExplanation:
/i - this parameter defines that searching will be case insensitive
"user7" - this is the string we are looking for
C:\SafeQ6\logs\replicator.* - this is the file we will be analysing. By putting the * we say that all files starting "replicator." will be searched through.
> c:\diagnosticoutput.txt - this specifies that output of the query will be written to file c:\diagnosticoutput.txt. Optionally you would replace this part by "| more" so that result will be shown right in the command line. Every time the command line window is full, searching is paused and you must press any key to continue.
Result:
Output can look like this:
---------- C:\SAFEQ6\LOGS\REPLICATOR.LOG
2021-08-06 13:35:23,731 DEBUG Thread-20| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,DC=css,DC=local, ldapExtId=null, ldapMemberOfs=[CN=Domain Users,CN=Users,DC=CSS,DC=LOCAL], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
---------- C:\SAFEQ6\LOGS\REPLICATOR.LOG.1
2021-08-06 02:21:42,194 DEBUG Thread-167| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=null, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
---------- C:\SAFEQ6\LOGS\REPLICATOR.LOG.2
2021-08-05 23:07:09,583 DEBUG Thread-73| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=f8:3a:3a:0d:90:2a:47:47:87:e1:8b:5e:87:e6:14:a2, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
2021-08-05 23:07:09,616 DEBUG Thread-73| DbPersist| adding alias: {call safeq_enh_insupd_usersaliases(?,?,?,?)} [1000000000004374,user7,PIV]
2021-08-05 23:07:09,627 DEBUG Thread-73| LdapReplicator| ADD USER - LdapUser(id=1000000000004374, login=user7, name=account, surname=User7, email=null, home=null, ou=1000000000004210, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=f8:3a:3a:0d:90:2a:47:47:87:e1:8b:5e:87:e6:14:a2, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
---------- C:\SAFEQ6\LOGS\REPLICATOR.LOG.3
---------- C:\SAFEQ6\LOGS\REPLICATOR.LOG.4Thanks to this output we know:
the log files required for the analysis will be REPLICATOR.LOG, REPLICATOR.LOG.1 and REPLICATOR.LOG.2. Other logs contain no record about this user.
first note about this user is from 5th August when he was added to the database.
from the output it is not exactly obvious what is the issue with user7. You can just recognize that for some reason the ldapExtId is different during last replications. You will have to open the the newest log file and search for more details around the row which was found (e.g. around 2021-08-06 13:35)
Option 2 - command findstr.exe
This command works in a very similar way to find.exe. However it provides some additional parameters such as regular expression for searching. A bit unfortunate behavior is that if more than one file is searched, the results will be prefixed with the filename where the text was found. Thus the searching through single files one by one is advised.
Usage:
findstr /R "user7 This\sis ERROR LDAP.filter.is\: Requested.LDAP.attributes\:.\[" C:\SafeQ6\logs\replicator.* > c:\diagnosticoutput.txtExplanation:
All rows containing following strings will be listeduser7This isERRORLDAP filter is:Requested LDAP attributes: [
/R - this parameter says that searched string is provided in form of regular expression.
\ - backslash is an escape character for special characters. If we did not escape these special characters, they would be considered as parameters of RegEx syntax.
. - dot matches any single character except line break characters \r and \n . In our case it replaces empty spaces.
/i - this parameter is not mentioned but it could be used the same way as described above for case insensitive searching. We did not use it on purpose now.
C:\SafeQ6\logs\replicator.* - this is the file we will be analyzing. By putting the * we say that all files starting "replicator." will be searched through.
> c:\diagnosticoutput.txt - this specifies that output of the query will be written to file c:\diagnosticoutput.txt. Optionally you would replace this part by "| more" so that result will be shown right in the command line. Every time the command line window is full, searching is paused and you must press any key to continue.
Result:
C:\SafeQ6\logs\replicator.log:2021-08-06 13:35:21,766 INFO Thread-20| LdapReplicator| This is full replication.
C:\SafeQ6\logs\replicator.log:2021-08-06 13:35:23,544 DEBUG Thread-20| LdapEngine| LDAP filter is: (objectClass=user)
C:\SafeQ6\logs\replicator.log:2021-08-06 13:35:23,544 DEBUG Thread-20| LdapEngine| Requested LDAP attributes: [sAMAccountName, primaryGroupID, givenName, sn, mail, homeDirectory, memberOf, GUID, otherPager, mail, userPrincipalName]
C:\SafeQ6\logs\replicator.log:2021-08-06 13:35:23,731 DEBUG Thread-20| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,DC=css,DC=local, ldapExtId=null, ldapMemberOfs=[CN=Domain Users,CN=Users,DC=CSS,DC=LOCAL], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
C:\SafeQ6\logs\replicator.log:2021-08-06 13:35:23,731 ERROR Thread-20| LdapReplicator| User has undefined ext-id!
C:\SafeQ6\logs\replicator.log.1:2021-08-06 02:21:40,121 INFO Thread-167| LdapReplicator| This is full replication.
C:\SafeQ6\logs\replicator.log.1:2021-08-06 02:21:41,347 DEBUG Thread-167| LdapEngine| LDAP filter is: (objectClass=user)
C:\SafeQ6\logs\replicator.log.1:2021-08-06 02:21:41,452 DEBUG Thread-167| LdapEngine| Requested LDAP attributes: [sAMAccountName, primaryGroupID, givenName, sn, mail, homeDirectory, memberOf, GUID, otherPager, mail, userPrincipalName]
C:\SafeQ6\logs\replicator.log.1:2021-08-06 02:21:42,194 DEBUG Thread-167| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=null, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
C:\SafeQ6\logs\replicator.log.1:2021-08-06 02:21:42,194 ERROR Thread-167| LdapReplicator| User has undefined ext-id!
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:05,227 INFO Thread-73| LdapReplicator| This is full replication.
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:07,446 DEBUG Thread-73| LdapEngine| LDAP filter is: (objectClass=user)
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:07,446 DEBUG Thread-73| LdapEngine| Requested LDAP attributes: [sAMAccountName, primaryGroupID, givenName, sn, mail, homeDirectory, memberOf, objectGUID, otherPager, mail, userPrincipalName]
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:09,583 DEBUG Thread-73| LdapReplicator| Searched user: LdapUser(id=0, login=user7, name=account, surname=User7, email=null, home=null, ou=0, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=f8:3a:3a:0d:90:2a:47:47:87:e1:8b:5e:87:e6:14:a2, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:09,616 DEBUG Thread-73| DbPersist| adding alias: {call safeq_enh_insupd_usersaliases(?,?,?,?)} [1000000000004374,user7,PIV]
C:\SafeQ6\logs\replicator.log.2:2021-08-05 23:07:09,627 DEBUG Thread-73| LdapReplicator| ADD USER - LdapUser(id=1000000000004374, login=user7, name=account, surname=User7, email=null, home=null, ou=1000000000004210, ldapName=CN=User7 account,OU=MCE,dc=css,dc=local, ldapExtId=f8:3a:3a:0d:90:2a:47:47:87:e1:8b:5e:87:e6:14:a2, ldapMemberOfs=[CN=Domain Users,CN=Users,dc=css,dc=local], ldapCards=[], ldapAliases=[User7], additionalAttributes={})Script:
Even better it is to utilize this command in some batch file like this:
logsearch.bat
@echo off
REM At first configure variables. Then launch the batch file.
REM ** PathToSearchIn ** is path to YSoft SafeQ directory. You can also set the path leading to logs directory. If there is a space
REM in the path, do not insert any quotation marks!
REM ** LogToSearchIn ** is the name of log file to search through. The file can located anywhere in PathToSearchIn path.
REM Be sure not to enter the name that can be fitting also to the name of binary files. Wildcard character is supported.
REM ** StringToSearchFor ** is the string of text you wish to look for. It supports regular expressions so you can
REM filter out all rows containing specific words in the order they are stored in the original log file. \ is used
REM as an escape character. . (dot) is is used as a substitude for any character such as space. Space divides separate
REM keywords to look for.
REM ** OutputFile ** is the name of file where output is stored to. The directory must already exist. If there is a space
REM in the path, do not insert any quotation marks!
REM ------------------VARIABLES START--------------------
SET PathToSearchIn=C:\SafeQ6\logs
SET LogToSearchIn=replicator.*
SET StringToSearchFor=user7\, This.is ERROR LDAP.filter.is\: Requested.LDAP.attributes
SET OutputFile=C:\analytic output\output.txt
REM -------------------VARIABLES END---------------------
DEL "%OutputFile%" /Q /F >nul 2>&1
FOR /R "%PathToSearchIn%" %%G IN (%LogToSearchIn%) DO (
echo. >> "%OutputFile%"
echo %%G >> "%OutputFile%"
findstr /R "%StringToSearchFor%" "%%G" >> "%OutputFile%"
)
The output from this batch file would look like:
C:\SafeQ6\logs\replicator.log
2021-08-09 02:00:00,125 INFO Thread-13| LdapReplicator| This is full replication.
C:\SafeQ6\logs\replicator.log.2021-08-06.1
2021-08-06 12:00:10,350 DEBUG Thread-7| LdapEngine| LDAP filter is: (objectClass=group)Thanks to this output we know:
the log files required for the analysis will be REPLICATOR.LOG, REPLICATOR.LOG.1 and REPLICATOR.LOG.2. Other logs contain no record about this user.
first note about this user is from 5.8. when he was added to the database.
from the output it is obvious that the user was at first mapped properly and he was added to YSoft SafeQ (2021-08-05 23:07). Then the mapping attributes have been modified (from objectGUID to GUID). LDAP did not return any value for the newly mapped attribute GUID and this this resulted into error with undefined ext-id - the user could not be mapped properly.
Option 3 - PowerShell
PowerShell is a scripting language providing massive set of functions. It can be used to filter out specific strings from several log files as well as from one log file. The example below describes the way you can use it:
Usage:
Save script as PSscript.ps1 in a parent directory (directory where sub-directory with logs is stored)
Replace $StringFilterRegex value by the text you would like to search for. Use the standard regex syntax.
Replace $FilePath value by the sub-directory name where to search in.
Run the script by right-click and wait for result. Result will be two files, one of them alphabetically sorted.
Script:
PSscript.ps
Clear-Host;
# name of file to search in. Wildchart can be used.
$FilePattern = '*.*';
# this automatically takes the current directory from where the ps1 is launched
$CurrentDir = (Get-Item -Path ".\" -Verbose).FullName;
# define subdirectory here where to search in (final path is defined by combination of this string and current directory)
$FilePath= $CurrentDir+'\Logs\all\';
# name of output file, file will be stored in directory from which the powershell was launched. Second file with extension SORTED will be created as well
$OutputFile= '_parsed.txt';
# string to search for, usage of Regex expression is possible
$StringFilterRegex = '^.*1000000000000006.*$|^.*10\.0\.5\.61.*$|^.*1000000000000054.*$';
# code that will search in the defined path, if path is not found the error is shown.
# if the output file exists, it will be deleted
if (-Not(Test-Path $($FilePath+$FilePattern)))
{
Write-Host 'Parsing has failed as the following path not found:' -foregroundcolor red
Write-Host $($FilePath+$FilePattern)
Write-Host ''
Write-Host 'Press any key to close the window...'
$x = $host.UI.RawUI.ReadKey("NoEcho,IncludeKeyDown") | Out-Null
}
else
{
if (Test-Path $OutputFile) {
Remove-Item $OutputFile -Recurse
Write-Host 'Following output file was deleted: '$OutputFile
}
if (Test-Path $($OutputFile+'SORTED')) {
Remove-Item $($OutputFile+'SORTED') -Recurse
Write-Host 'Following output file was deleted: '$($OutputFile+'SORTED')
}
Write-Host 'Parsing in progress...' -foregroundcolor green
Get-ChildItem $($FilePath+$FilePattern) | ForEach-Object {$InputFile=$FilePath + $_.name;select-string -Path $InputFile -Pattern $StringFilterRegex -AllMatches | % { $_.Matches } | % { $_.Value } | Add-Content $OutputFile}
if (Test-Path $OutputFile) {
Get-Content $OutputFile | Sort-Object | Add-Content $($OutputFile+'SORTED')
Write-Host 'Parsing has finished. Following files were parsed:' -foregroundcolor green
Write-Host ' '$($FilePath+$FilePattern)
}
else {
Write-Host 'Parsing finished, requested text not found. Following files were parsed:' -foregroundcolor Green
Write-Host ' '$($FilePath+$FilePattern)
}
Write-Host ''
Write-Host 'Press any key to close the window...'
$x = $host.UI.RawUI.ReadKey("NoEcho,IncludeKeyDown") | Out-Null
}Example of input:
2014-05-23 10:16:44,576 DEBUG ClientServerThreadPool| ClientServerThreadPool| Waiting for connection
2014-05-23 10:16:53,344 DEBUG TERM-1-2| TerminalListener| <<< NOPCommand[percents=0; pages=0]
2014-05-23 10:16:53,344 DEBUG TERM-1-2| TerminalListener| >>> NOPCommand[percents=0; pages=0]
2014-05-23 10:17:03,421 DEBUG essage-processing-loop| MessagingServer| Sending back a PONG
2014-05-23 10:17:03,764 DEBUG Terminal#1| TerminalListener| Connection from: 10.0.5.61
2014-05-23 10:17:03,780 DEBUG TERM-1-3| TerminalListener| <<< .SQ 5.0.2.3 SQRTW492K300630
2014-05-23 10:17:03,780 DEBUG TERM-1-3| TerminalConnector| Checking config file safeQ.fwupdate.conf
2014-05-23 10:17:03,780 INFO TERM-1-3| SafeQConnector| Found device Device[1000000000000006,10.0.5.61,Device-ST-1215(VENDOR-PROVIDED-ACCOUNTING/none),Default, , status=, snmp: SnmpSettings [readOnlyCommunity=public, readWriteCommunity=private, username=null, context=null, authenticationAlgorithm=MD5, authenticationPassword=*****, privacyAlgorithm=DES, privacyPassword=*****], TerminalEmbedded[installed: true, auth status: INSTALLED, spi status: INSTALLED, acc status: INSTALLED, payment status: INSTALLED, scan status: INSTALLED] for terminal [SQRTW492K300630/10.0.5.61]Example of output:
2014-05-23 10:17:03,764 DEBUG Terminal#1| TerminalListener| Connection from: 10.0.5.61
2014-05-23 10:17:03,780 INFO TERM-1-3| SafeQConnector| Found device Device[1000000000000006,10.0.5.61,Device-ST-1215(VENDOR-PROVIDED-ACCOUNTING/none),Default, , status=, snmp: SnmpSettings [readOnlyCommunity=public, readWriteCommunity=private, username=null, context=null, authenticationAlgorithm=MD5, authenticationPassword=*****, privacyAlgorithm=DES, privacyPassword=*****], TerminalEmbedded[installed: true, auth status: INSTALLED, spi status: INSTALLED, acc status: INSTALLED, payment status: INSTALLED, scan status: INSTALLED] for terminal [SQRTW492K300630/10.0.5.61]