Track origin of warnings from "openhab.core.internal.events.EventHandler"

Setup, Configuration and Use Scripts & Rules
1

Dear Community,

I am receiving the following error in openhab.log files. It seems that I have some kind of issue were I go out of bound of a string array in my rules. The question is how do I pinpoint the originating rule of this error? Is there an easy way to figure that out?

21-08-10 13:00:00.919 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching/filtering event for subscriber 'org.openhab.core.events.EventSubscriber' failed: begin 14, end 13, length 32
java.lang.StringIndexOutOfBoundsException: begin 14, end 13, length 32
        at java.lang.String.checkBoundsBeginEnd(String.java:3319) ~[?:?]
        at java.lang.String.substring(String.java:1874) ~[?:?]
        at org.openhab.core.io.monitor.internal.metrics.RuleMetric.receive(RuleMetric.java:117) ~[?:?]
        at org.openhab.core.internal.events.EventHandler.lambda$0(EventHandler.java:151) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]

Thank you,
Alex

2

One of the things that a lot of people donā€™t understand is that those big long stack traces that get printed to the logs actually provide useful information. I cringe every time I see someone trying to disable them.

Anyway, the error itself is not really coming directly from code you wrote necessarily. I donā€™t see any of the classes involved with running actual rules in this stack trace (this is the full stack trace, right?).

The root error is there is something trying to extract a part of a String that is 32 characters long. Itā€™s trying to extract the characters starting at character 14 through character 13. That should throw up alarms because the end is before the beginning. So thatā€™s whatā€™s going wrong.

The first class that is actually a part of openHAB itself is RuleMetric and the error is taking place on line 117 of that class. Looking on GitHub I see the line is:

            String ruleId = topic.substring(RULES_TOPIC_PREFIX.length(), topic.indexOf(RULES_TOPIC_SUFFIX));

So far that tracks since the original error is a call to substring. That line of code is trying to extract the rule ID from the eventā€™s topic. Based on the available information Iā€™d guess that the event is coming from a rule that doesnā€™t have an ID at all.

Thatā€™s about as far as I can take you. Review all your rules. The best way would be to query for them in the REST API docs and see if you can find one or more that doesnā€™t have a rule ID defined or the ID is an empty string.

Theoretically this state should be impossible. Every entity in openHAB has a unique ID and it shouldnā€™t be possible for a rule to exist without an ID. So once you figure out which rule it is, review how you created it in the first place and/or things you may have done to it in the past to determine if an issue needs to be filed to prevent this from occurring.

1 Like
3

Hey Rich,

thank you very much for the comprehensive reply. I would not try to disable stack traces, they provided a good starting point for analyzing issues in the pastā€¦and if something happens its usually too late to reactivate them.

All my rules are text file based and I havenā€™t actually created any in the through MainUi, Iā€™m old-school like that. I started checking for rules without IDā€™s via Rest, but all results actually had an ID set which basically looked like light_automation-1, etc. That matches what I see in the UI.

Iā€™m now trying to reference the occurence of the error with events that might happen around that time and see if I can identify patterm. Will update the thread once I find the culprit.

Again, Thanks a lot for looking into this.

Alex

4

Hi Rich and Alex,

Thanks to this post Iā€™ve managed to get rid of those warnings in my code! The key was the line pointed by Rich:

String ruleId = topic.substring(RULES_TOPIC_PREFIX.length(), topic.indexOf(RULES_TOPIC_SUFFIX));

which uses two constant string to find the begining and the end of the ruleId. This constants are

public static final String RULES_TOPIC_PREFIX = "openhab/rules/";
public static final String RULES_TOPIC_SUFFIX = "/state";

My rules are all DSL text files, so the uid of every rule is created from filename appending a number. The problem was that I had a file called stateMachines.rules, so all its internal rules had uids like:
stateMachines-1
stateMachines-2
ā€¦

So when the code in RuleMetric executes against the topic ā€œopenhab/rules/stateMachines-1/stateā€ this warning shows up. My solution has been simple, just rename the file avoiding it to start with ā€œstateā€.

Thank your very much for your time and hints. I hope this can help @HoLiuS also.

XĆ nfia

1 Like
5

You might consider filing an issue to make the code that processes the rule ID a little more flexible than that. There are other approaches that wouldnā€™t have this same limitation including splitting the ID on ā€œ/ā€ and only looking at the 3rd element. That should avoid the problem and you can have a .rules file that starts with state.

6

Hi Rich,

Filled my first github issue, I hope thereā€™s enough information for someone to solve this.

2 Likes
7

Hi Xanfia,

welcome to the community.

I in fact have a rule file called stateofday.rules, renaming this rule actually seemed to have fixed the issue.

Thank you very much for your analysis and input.

Alex

8

I think it should be fixed by this PR. :slight_smile:

2 Likes