openHAB - Filtering event logs

My point is to be challenging: I strongly believe OH is by far the most robust and versatile home automation framework. Otherwise, I would have given up :slight_smile:
For sure, these are valuable technical improvements from a conceptual standpoint. I am just pointing out that, as a developer focused on the automation logic, I miss efficiency and usability of rules environment. Sometimes it takes me hours to write one single line of code just because (1) the package DSL + XTend + Java is touchy about the syntax, (2) because the VSCode IDE is sometimes not reporting errors properly and (3) because it take very long before a modified .rules file is loaded and ready for testing in OH. This is irritating but does not depreciates core strengths of OH (if I list them all, my post will be far longer).

I want to write code with an efficient debugging/IDE. My previous home automation what built on Python. I rewrote it all in DSL-style when migrating to OH… My current DSL config is around 4600 lines of code! And Python came in to OH afterwards :frowning: :slight_smile:
The syntaxic “mix” between Java / XTend was so painful that I fear to experience the same if migrating back to Python again…

Yes, grep is fine for few items but becomes unhandy when many items are involved. I am also using a 3rd party log viewer but filtering “on the fly” is more convenient to me. My intend is not replace the standard logger that is alreay configurable using org.ops4j.pax.logging. But it provides a configurable “on the fly” filtering method that can be useful and shoudl remain temporary while debugging (at least that is useful to me).

I initially used a filter, but for some reason, this raised errors time to time which remains a mystery to me, so that “ugly” multilined code.

The bitWiseAnd determines which event (change, update, command) should be logged based on the value of the “Filter items” in the sitemap belows.: I run similar rules to log commands and updates.
The hashmap was a workaround to catch a strange behaviour where the logging rule was triggered repeateadly, especially for updates(don’t ask me why: I gave up searching). But I agree that this hashmap should be useless.

So use Scripted Automation which which addresses almost all of these errors. That’s why in OH 3 Scripted Automation is likely to become the default instead of Rules DSL. All the things you complain about Rules DSL is simply not going to ever get any better.

Python has been an option, though admittedly a somewhat fringe option until about OH 2.3, since at least OH 1.7.

Hmmm, depending on the error it might be because the members are changing state while the filter is taking place. Though the same problem usually kills a forEach so without seeing the error itself I can only speculate.

How old is this Rule? Was it written before Member of triggers? That behavior would make sense if that were the case. If you’ve seen this error with the Member of triggers, have you filed an issue?

The next-gen scripting engine is promising for basic automation through programming bricks.
It would be great if these bricks could be mixed with lower-level programming language such as Python or Java so anyone has the choice to combine ready-to-use the “high level bricks” and to design “low level programming routine”

Eventghost and Tasker are nice examples of scripting tools

Both tools combine high level bricks using events/triggers logic + level coding (with Java scripting for Tasker or Python scripting in Eventghost)
Let’s not misunderstand : I am not trying to compare Eventghost or Tasker with OH. Tasker is limited to Windows platform, has no UI capability, little interoperability and very limited device support. Tasker is limited to Android with a singular lack of logic in implementation and terrific designer IDE.

Without low-coding capability, I will have to merge to Python (it will be hard work but I love structuraton of Python language )

Back to my rule, I rolled back to my misleading rule and this is the error I could not fix. For the hashmap, the intend was to return the previous state / command to build the logInfo() line

rule "Log item change filter"

when
    Member of SYS_Settings changed
    or Member of AX received update
    or Member of USR received update
    or Member of ECL received update
    or...
then
    SYS_LogGroup.members.filter[ GenericItem curLogGroup | 
        if(curLogGroup.state==NULL)false} else{Integer.parseInt(curLogGroup.state.toString).bitwiseAnd(1) != 0}
    ].forEach[ GenericItem curLogGroup | 
            val String logGroupName = curLogGroup.name.replace("SYS_LogGroup_", "")
            if(triggeringItem.getGroupNames.contains(logGroupName)){
                logInfo("rules.log.ItemChange", "" + logGroupName + "] " + triggeringItem.name + " changed from " + itemChanges.get(triggeringItem.name) + " to " + triggeringItem.state.toString)
                itemChanges.put(triggeringItem.name,triggeringItem.state.toString)
            }
    ]
end

And this is enigmatic error which occured (no stack to trace anything). And because I am not a Java/XTend specialist, I gave up and returned to my ugly-but-working code.

2020-05-07 22:50:50.336 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'log.rules'
2020-05-07 22:52:01.943 [INFO ] [me.model.script.rules.log.ItemChange] - [ECL] ECL_mRDC_Salon_lampe changed from null to ON
2020-05-07 22:52:01.965 [INFO ] [me.model.script.rules.log.ItemChange] - [ECL_Proxy] PROXY_ECL_mRDC_Salon_lampe changed from null to ON
2020-05-07 22:52:16.203 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Log item change filter': null
2020-05-07 22:52:16.208 [INFO ] [me.model.script.rules.log.ItemChange] - [ECL] ECL_mRDC_Salon_lampe changed from ON to OFF

By programming bricks, do you mean like libraries where, for example, there are PRs for a number of the design pattern concepts, other integrations, and all sorts of community developed libraries to use?

Or do you mean more like importing and configuring a ready made Rule from a template so you don’t have to look at the code at all?

And of course, in either case you have access to create your own Scripts using the supported language of choice.

As for the error…
Is the same Item a member of more than one of the Groups that triggers the Rule? Is it likely that this Rule will be triggered multiple times at the same time?

Yes: this is exactly what I expect: embed my own script written with a language that gives access to more programming features such as hashmap, lists, loops, global variables, and functions.
So anyone can choose or mix any of the 3 levels : (1) use the ready-to-use rules templates, (2) build the rules from the logical bricks and things/items exposed to the rule engine, (3) design his own bricks with a standard language (Python or Java, anything but standard) and get native interoperability between the 3 levels of design. I suspect that this is what is coming and I can’t wait but in the meanwhile, I try to maintain my modular layers in the DSL-style

No, the rule should only be triggered once per item because each one belongs to one single functional category (group ECL=lighting device and group PROXY_ECL=lighting command layer). They belong to other groups mRDC_Salon (living-room=location group) and ECL_Salon (living-room lighting group to allow driving groups of lights = scenes ). They are not monitored by this rule.

Switch  ECL_mRDC_Salon_lampe            "Lampe du salon"       <light> (mRDC_Salon, ECL_Salon, ECL)                    { channel="zwave:device:142f34cb:node36:switch_binary" }
Switch  PROXY_ECL_mRDC_Salon_lampe      "Lampe du salon"       <light> (mRDC_Salon, ECL_Proxy)                     {autoupdate="false"}

Ultimately, I think the root cause is the fact that Rules DSL Rules are not thread safe (a problem that doesn’t exist in Scripted Automation) so my recommendation for the fix would be to rewrite the Rule in Scripted Automation, probably Python at this point.

When/if you do, you might consider using Item Metadata instead of Groups which might give you a bit more control over how the Rule triggers which in turn will simplify the code itself. See JSR223 Jython Replacement for Expire Binding for an example of doing just that to replace the Expire binding using Rules.

I am not a thread or coding specialist but I suspected there was something about this.
I already delt with several “processes” that would have required a real-threaded approach (IR queue, notification queue) that I addressed with a dirty queue.lock()/unlock. But I understand that thread-safe implementation my requires more resources which would prevent OH to run on lightweighted systems.

For sure, I will have to migrate again one day. Already looked to JSR few years ago but the install seemed so complicated on a Windows platform that I gave up. Switching to another OS is much time to spend when you are not used to it and I still have one critical sub-system (wired door/gate opener) fully coded in Python/Eventghost, bound using MQTT to OH, which forces me to maintain a MS Windows machine.
It is always frustrating to rework existing code when you are not a profesional/fast coder and when you have so many “new” features coming everyday in your home automation todo list !

There is an open report on openHAB core

So far as I can see, there is some issue in the bowels of openHAB (probably about multi threading, yes) where iterating the members of a Group in a DSL rule while the Group is also being updated by “someone else” sometimes returns null.

That’s good fit for your rule - it triggers from member update and chunters along, iterating a Group. Meantime that update will also be causing Group(s) to update/review their own status in parallel, because of member update.

I have doubts this would be circumvented by NGRE unless it is using some completely different mechanism to examine Groups? Certainly throw different symptoms, sure.

1 Like

See Design Pattern: Gate Keeper which shows a better way to handle that.

Even on Windows now it’s just an add-on. See [beta testers wanted!] Jython addon w/ helper libraries (requires OH 2.5.x). It’s not merged so you have to install it manually (i.e. drop 1 jar file into the addons folder) and that’s it. It’s pretty simple now to get started.

The gate keeper thread was already in my bookmarks :wink: and my todo list

Hey guys, recent posts look to be moving somewhat off topic from the original topic around filtering/excluding events from the logs. Any chance the discussion can continue in a separate thread?

Thx.

Do I need to restart or reboot anything after the change? Any Service or the Server itself?

Filters take effect as soon as you save the changes. No restarts needed

1 Like

I only have one filter expression for now, but until I tried doing it this way I couldn’t get it to work. :+1:

Specifically:

log4j2.appender.out.filter.stuff.type = Filters

log4j2.appender.out.filter.stuff.Modbus1stConnectionRefused.type = RegexFilter
log4j2.appender.out.filter.stuff.Modbus1stConnectionRefused.regex = .*connect try 1/3 error.*
log4j2.appender.out.filter.stuff.Modbus1stConnectionRefused.onMatch = DENY
log4j2.appender.out.filter.stuff.Modbus1stConnectionRefused.onMismatch = NEUTRAL

I just wanted to add to this thread a little discovery that might save a headache to those that want to play with the RegEx filters.

OH2 is using the properties file format to configure log4j2 that, while certainly more readable than XML, it is prone to some errors.

Specifically, while the parser seems to be pretty lenient regarding white-space before the regular expression, it is absolutely inflexible with anything following it.

You can use something like:
log4j2.appender.event.filter.1.regex = .*(Motion|Meter).*
with a space after the equal sign (=).

But you absolutely can’t use:
log4j2.appender.event.filter.1.regex = .*(Motion|Meter).* <-- there’s a space here
with a space at the end of the regular expression.

For some reason the properties parser strips whitespace before but not after. I’m running OH2 2.5.4 on Ubuntu.

This would have been more apparent with the XML format that forces the regex in quotes.

When I looked into this fairly deeply awhile back, this was a decision made by the upstream Karaf project. There have been several who have tried to move to XML and, even better, allow for imports so we can have something like a logging.d folder where we can have our own customizations to the logging config without needing to modify the original. But we just haven’t figured out how to do it. One challenge is when you change the logging through the Karaf console it actually modifies the exiksting logging config file.

I see. I’m not a big fan of editing xml files by hand. Sometimes the properties are so much more clear. Having a logging.d folder would have been very cool :slight_smile:

Rich, on the topic of logging, is there a way to log from rules using the first parameter of logInfo, logWarn and so on as a marker and then intercept that parameter in the log4j2 configuration?

I’m thinking something like:
logInfo(“my_logger”,“this is a message”)

Matched by some definition in the log4j2 config file so that anything going to my_logger is redirected to a specific logger?

In other words, is the first parameter actually used to create a real logger behind the scenes that we can use in the log4j2 definitions.

Sure. E.g. you can create extra files for some of your rule. Each loggername set in logInfo() and so on is an extra logger which is catched by the generic logger, as it’s part of the tree org.openhab.model.script.

1 Like