How to watch and look through logging

Tags: #<Tag:0x00007fc9102eebf0>

I’ve been seeing a lot of posts lately about people wanting to eliminate certain events from their events.log. This posting is to show that doing so is not only a bad idea but unnecessary.

First, I’ll apologize to the Windows users out there. I don’t know the right commands to do this on Windows without installing MinGW, Cygwin, or Linux Subsystem for Windows. Below I include both Posix (will work for Linux, iOS, BSD, and those addons to Windows listed to the left) and the Windows Powershell equivalents. Note though that the Powershell Get-Content is really slow. You may want to install MinGW or the like anyway.

Anyway, we will be using tail -f to follow the log file as it is being written. Note that this may not work on log files over a SAMBA share.

Finally, these are naive examples. There are ways to construct equivalent command lines that will run more efficiently and require fewer characters to write. I opted for less efficient and longer command lines in order to utilize fewer new commands or concepts.

In the below examples, I will use an environment variable to represent the log file path. You can replace the variable with the actual path to the file or set an environment variable. This is an exercise left to the student.

Posix
$OH_EVENTS  for an apt-get installed OH /var/log/openhab2/events.log
$OH_LOG     for an apt-get installed OH /var/log/openhab2/openhab.log

Windows
$Env:OH_EVENTS c:\openhab2\userdata\logs\events.log
$Env:OH_LOG    c:\openhab2\userdata\logs\openhab.log

Only shows log entries that contain MyItem

Posix
tail -F $OH_EVENTS | grep MyItem

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -match "MyItem" }

Only shows log entries that do not contain MyItem

Posix
tail -F $OH_EVENTS | grep -v MyItem

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -notmatch "MyItem" }

Shows those log entries that contain MyItem1 OR MyItem2

Posix
tail -F $OH_EVENTS | grep -E "MyItem1|MyItem2"`

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -match "MyItem1|MyItem2" }

Shows only log entries that contain MyItem1 and strips off the date time and class fields.

Posix
tail -F $OH_EVENTS | grep MyItem1 | cut -d '-' -f 4

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -match "MyItem" } | ForEach-Object  { $_.split("-")[3] }

Shows only log entries showing where MyItem1 changed state

Posix
tail -F $OH_EVENTS | grep MyItem1 | grep changed

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -match "MyItem" } | where { $_ -match "changed" }

Shows only log entries from logName (e.g. the first argument to a logInfo in your Rules)

Posix
tail -F $OH_LOG | grep logName

Windows
Get-Content $Env:OH_LOG - Wait | where { $_ -match "logName" }

Shows only those log entries where MyItem1 received an ON command

Posix
tail -F $OH_EVENTS | grep MyItem1 | grep "received command ON"

Windows
Get-Content $Env:OH_EVENTS -Wait | where { $_ -match "MyItem1" } | where { $_ -match "received command ON" }

I could go on with more examples but I hope these will be enough for you to manipulate your log file viewing to filter them down to just view what you care about at any given moment.

Edit 1: Removed wrong OR example, changed the tail to use -F so it follows the logs when they happen to become rotated
Edit 2: Added back a working OR example that will work with regular grep.
Edit 3: Added Windows Powershell equivalent commands

13 Likes

Hmm, shouldn’t that be:

tail -f /var/log/openhab2/events.log | egrep ‘MyItem1|MyItem2’

for OR’ing?

1 Like

ORing only works with egrep which isn’t POSIX so not guaranteed to be there. I didn’t want to present any examples that depended on it.

Right, but the example will only pass lines with MyItem1 to the last grep, so in effect only lines with MyItem1 AND MyItem2 will be shown.

Also, using tail -F instead of tail -f will work even after a log file rotates. Handy when DEBUG is enabled and output is massive.

Indeed, that was a dumb mistake.

I’m not too concerned about following a log rotate but that is a good point.

Good tutorial, that’s useful stuff! Thanks!

Very helpful - thumbs up!

Added back a version of the OR case that will work with regular grep. The trick was finding the -E flag.

1 Like

@rlkoshak
I am wondering what linux command I can use if I don’t want to analyze the events.log in realtime using tail -f? What am I up to? Well, let’s say I want to filter for a specific item and its related events during the last 72 hours. How am I supposed to do that?

Just drop the tail -f part and add the name of the file to grep

grep MyItem $OH_EVENTS

:+1:

Follow up question: How can I filter all the events that happened between 22:59h and 23:01 for all devices?

I know of no way to do that.

Depending on how long ago it was, you can use the -n option for tail to start the tail showing some number of previous lines, then scroll to the time you need. This will start the tail and show the previous 3000 lines:

tail -F -n3000 $OH_EVENTS

Is there a limit how many lines will be shown? Even if I use -n100000, I do see the same amounts of lines as with -n3000. It will show me approximately the last six hours.

I don’t know… but if you need to go that far back, just open the file.

Hehe, that’s true :wink:

I thought of another trick that might work for you… use the -A option and filter on the start time. So something like:

grep -E -A100 "2017-11-07 22:59" $OH_EVENTS

or try this:

grep -E "2017-11-07 22:59|2017-11-07 23:0[0-1]" $OH_EVENTS

There is no limit but realize that the log file gets rotated out whenever it gets above a certain size and periodically so unless you are unlikely to ever have a file with 100000 lines in it to begin with.