LogReader binding

regarding the discussion on INFO items and stuff:
I’m strongly opposed on this one. Why? simply because it would a) kill OH2 on one-chip-Hardware like Raspberry PIs or PINE64s and the like. and b) that’s not the purpose of a logfile at all.

A logfile just brings some kind of overview on the state of an application. If you need for some reason INFO on how a certain piece in your application is acting => get that piece of application do that for you. The only thing a logfile can do more than an application, is if that application isn’t working properly - hence the need for ERROR or some softer WARNING notifications.

So, for the above examples: If the LG Smart TV binding INFOs, that the TV was removed: this should be implemented as a channel in the binding itself - then we can do something in a rule on this action, not via the very costly detour of analyzing a logfile.
Second: If you really want to have items based on a file like a logfile, you need to adress them properly. how would you do that in a cycle of say 60sec? You could have dozens of INFOs while the analyzing waits. If you needed some realtime action - you need cycles of mere msecs -> that yould even bring some bigger Hardware on the brink of failing.

That being said: Please stick to ERRORs and WARNINGs - If there are any, you need to have a closer look into the logfiles/application anyways. For INFOs - goto the binding itself.

3 Likes

You have very good points here and i totally agree. Leaving INFO out helps keeping this not so “resourcehungry”

That being said: Please stick to ERRORs and WARNINGs - If there are any, you need to have a closer look into the logfiles/application anyways. For INFOs - goto the binding itself.

+1 To this. This binding is going handle only errors and warnings.

I agree with @binderth in that INFO Topic.

For this usecase a binding can provide trigger channels, which will then get fired when an event (like the disconnect) takes place.

Okay, I got your point. I didn’t think it would impact system resources that much, but I’m probably underestimating this. I withdraw my request. :wink:

2 Likes

hehe - yes, just imagine with 80.000+ lines, you’ll propably get as much INFO-items…

As an example here’s my log “stats”. Don’t wonder those huge warning and error line counts because I’m testing the new modbus binding at the same time. Modbus openHAB2 binding available for alpha testing

13:20:01.997 [DEBUG] [ng.logreader.handler.LogReaderHandler] - Log rotated: 2017-11-12 20:09:49.028  
13:20:03.334 [DEBUG] [ng.logreader.handler.LogReaderHandler] - Last line: 2017-11-24 13:20:02.226
13:20:03.335 [DEBUG] [ng.logreader.handler.LogReaderHandler] - Total log lines: 83929. New lines since last read: 83929
13:20:03.336 [DEBUG] [ng.logreader.handler.LogReaderHandler] - New warning lines: 25843
13:20:03.365 [DEBUG] [ng.logreader.handler.LogReaderHandler] - New error lines: 890

I uploaded a slightly updated binding few minutes ago. You can find the download link in post #1. Also check out the fix I made to logreader.rules file

Now the first read, when binding is initialized, is done with LineNumberReader and it only counts the lines and doesn’t parse anything. After this BufferedReader does the reading as usual and channels start to update. There’s also 2 different “timers” added to measure execution times. You can see these result in the log by switching log level to trace in karaf.

log:set TRACE org.openhab.binding.logreader

Have to keep in mind that there might me other factors that affect these times but I think it points the way. I would really much like too see what times you get with RPis version 2 and 3. For comparison, here’s some times I got from my OH2 server (Amd AthlonX2 5000+ / 8gb ram / old hdd):

14:54:38.470 [TRACE] [ng.logreader.handler.LogReaderHandler] - Log lines at first read: 84618
14:54:38.472 [TRACE] [ng.logreader.handler.LogReaderHandler] - First log read took 155 milliseconds
...
14:55:38.610 [DEBUG] [ng.logreader.handler.LogReaderHandler] - Total log lines: 84621. New lines since last read: 3
14:55:38.620 [TRACE] [ng.logreader.handler.LogReaderHandler] - Parsing through log took 146 milliseconds
...
14:56:38.764 [DEBUG] [ng.logreader.handler.LogReaderHandler] - Total log lines: 84627. New lines since last read: 6
14:56:38.774 [TRACE] [ng.logreader.handler.LogReaderHandler] - Parsing through log took 144 milliseconds

Before someone starts to wonder I have to say that I’m quite beginner in java and learning on the way and there might be better and faster methods to achieve this.

Hey @Benjy, can you give me some tips how to use this ${OPENHAB_LOGDIR} in my binding?

I can see that you really have done your homework. And i want to do mine also. I’d like to hear those rough estimates of yours!

I’m running my system in home enviroment but as you said it is not a toy. Of course not as critical as your systems but has to work 24/7 and even when you’re away you have know if something happens.

Really looking forward to this.
/Miika

I’m afraid I don’t know how you’d access it in Java. But I’d guess the first place you could try is the openhab.logdir property.

Thanks anyway. Didn’t even think it could be listed in system properties. I’ll check it. Do you know anyone who could answear this question?

Today I had the time to test again, using Bundle-Version: 2.2.0.201711241250.

Basically it works, I get notifications about warn and error messages.
But the refresh interval does not work: after changing the interval the status gets updated once, then it stops, regardless of what I put in there (I tried 60 seconds, 300 seconds, 5 seconds).

Can you give me TRACE logs?

Sure, but not before Friday evening, I am traveling.

Ok. It might somehow be related to log rotation. But as soon as you get home you can test updated version. I’ve fixed a few bugs here and there and hopefully I’ll get it finished today.

1 Like

The jar in post #1 seems to be from 24th Nov. Did you made an update the last 3 days?

Just few seconds ago I uploaded new version from today. I’ll post a changelog soon.

Ok, I was to fast. Now I got the new one. :slight_smile:

ps. Thank you for that binding. I tried a few days earlier to get this done with exec binding. But I failed. :wink:

1 Like

Updated binding available

You can find the download link in post #1

Changes and new features:

  • Removed configuration option File location. Log file path is now automatically picked up using system properties.
  • Detection and handling of log rotation changed.
  • 3 New channels.
    • lastLine - DateTime of last log line
    • lastWarningLine - Last Warning as String
    • lastErrorLine - Last Error as String

Attention: Check your items. Channel names converted to camelCase.

Hey @binderth, there’s now channels for you to write up a rule to check if logging has stopped.

1 Like

You’re welcome and good to hear that this binding is useful.

One request though. Can you provide some info (platform and OH version) and TRACE logs?

/Miika

I wonder if adding support for journalctl is out of the scope of this addon? I’m using just that instead of files.

Background for this: I have read-only filesystem setup and journalctl serves as volatile log handler.

Best,
Sami