MQTT regex_filter not working in OH 2.3 Release

I’ve already files an issue but thought I should open up a thread to see if I’m the only one seeing this problem or not.

I noticed today that since the update to 2.3 Release I did a couple of days ago that a couple of my Items were not updating as expected. They are MQTT Items and they use the regex filter to sort through the messages published to the same topic.

After some trouble shooting I discovered the following:

  • the messages are being published just like always
  • if I remove the regex filter the Item gets updated for those messages that it’s REGEX transform match and generates a log error for those it doesn’t
  • if I use ANY regex filter, including “.” or “.*” no messages get passed to the Item.

The Issue is located here:

It’s difficult to see what might be causing this. The binding hasn’t changed in two years, and as far as I can see at a glance, that’s the only place that contains the regex matching…

I agree but I’ve experimentally shown the behavior to be consistent, at least on my setup. The fact that nothing changed in the binding is largely why I started this thread here.

But I can stop my Item from updating by adding .* as the filter and get it back to update by removing the regex filter.

I’ve verified the messages are being published and are unchanged from when it used to work (the message considered of an IP address, a space and ON or OFF).

Had there been a change to the regex library it the like that could be causing problems perhaps?

I created a new unit test using your REGEX.

It fails with this error:

   expected:<...EX(123.45.6.78 (.*))[:123.45.6.78 .*]>
    but was:<...EX(123.45.6.78 (.*))[]>

This shows that the binding is using a different REGEX than the one you’ve specified.

If I change the colon in the REGEX to a period, then the test passes:

REGEX(123.45.6.78 (.*)).123.45.6.78 .*

It also passes when prefixing the colon with a backslash (\\:)

All of this, of course, is using the base binding code, which means we should see the same behaviour from all versions of OH2. I still can’t see a reason why there’d be any change from 2.2 to 2.3.

OK, then I’m confused by a few things:

  1. This has worked unchanged since before OH 2.2 release
  2. The example in the docs clearly uses a colon

Number humidity “humidity [%.1f%%]” {mqtt="<[broker:weatherstation/readings:state:JS(convertPercent.js):humidity=.*]"}

When I replace the colon with a dot on my config I get the following error:

2018-06-01 07:51:40.625 [ERROR] [.mqtt.internal.MqttMessageSubscriber] - Error processing MQTT message.
java.util.regex.PatternSyntaxException: Unmatched closing ')' near index 16
^10.10.1.208 (.*)).10.10.1.208 .$

Config:

mqtt="<[mosquitto:scripts/presence/iphone/results:command:REGEX(10.10.1.200 (.*)).10.10.1.200 .*]"

And this error when I escape the colon:

2018-06-01 07:54:10.632 [ERROR] [.mqtt.internal.MqttMessageSubscriber] - Error processing MQTT message.
java.util.regex.PatternSyntaxException: Unmatched closing ')' near index 16
^10.10.1.200 (.*)):10.10.1.200 .$
                ^

Config:

mqtt="<[mosquitto:scripts/presence/iphone/results:command:REGEX(10.10.1.200 (.*))\\:10.10.1.200 .*]"

I get nothing at all when I use the documented format:

mqtt="<[mosquitto:scripts/presence/iphone/results:command:REGEX(10.10.1.200 (.*)):10.10.1.200 .*]"

And I get errors on the messages that don’t match the REGEX transformation when I remove the regex filter entirely:

2018-06-01 07:57:39.435 [WARN ] [b.core.events.EventPublisherDelegate] - given command is NULL, couldn't post command for 'vJennPhone_Manticore_Net'
2018-06-01 07:57:39.438 [INFO ] [ipse.smarthome.model.script.presence] - vRichPhone_Manticore_Net updated to OFF
2018-06-01 07:57:43.064 [WARN ] [b.core.events.EventPublisherDelegate] - given command is NULL, couldn't post command for 'vRichPhone_Manticore_Net'
2018-06-01 07:57:43.067 [INFO ] [ipse.smarthome.model.script.presence] - vJennPhone_Manticore_Net updated to ON

Config

mqtt="<[mosquitto:scripts/presence/iphone/results:command:REGEX(10.10.1.200 (.*))]"

I notice that all of the error messages you’ve quoted are missing the final character from your configured regex:

error:

^10.10.1.208 (.*)).10.10.1.208 .$

configured regex:

10.10.1.200 (.*)).10.10.1.200 .*

I now see I configured the unit test I spoke about above incorrectly.
I brainlessly hardcoded the expected value for the transform to the entire string REGEX(123.45.6.78 (.*))[:123.45.6.78 .*].

After this is corrected to REGEX(123.45.6.78 (.*)), the test fails with this error:

expected:<...GEX(123.45.6.78 (.*))[]>
 but was:<...GEX(123.45.6.78 (.*))[:123.45.6.78 .*]>

Still looking for the code that’s slurping up the whole line like this…

[Edit:]
After more digging and thought, I now find that the original unescaped config string appears to be parsed correctly:

Splitting config string 'mosquitto:scripts/presence/iphone/results:command:REGEX(123.45.6.78 (.*)):123.45.6.78 .*'
First pass pieces:
  ==> 'mosquitto'
  ==> 'scripts/presence/iphone/results'
  ==> 'command'
  ==> 'REGEX(123.45.6.78 (.*))'
  ==> '123.45.6.78 .*'
Part 0: 'mosquitto'
Part 1: 'scripts/presence/iphone/results'
Part 2: 'command'
Part 3: 'REGEX(123.45.6.78 (.*))'
Part 4: '123.45.6.78 .*'
Established transformation rule: 'REGEX(123.45.6.78 (.*))'
Established message filter: '123.45.6.78 .*'

So now to figure out why incoming messages aren’t being processed correctly…

1 Like

Ok, so after all of that… I can’t reproduce the original problem :frowning:
I tested in both OH 2.1 and OH2.3 RC 1.

Using your original unescaped config string (modified slightly for my feed, of course):

String regexDebug "Regex debug text [%s]" { mqtt="<[ruby:feeds/messages:command:REGEX(123.45.6.78 (.*)):123.45.6.78 .*]" }

I get the command as expected:

23:01:39.802 [TRACE] [g.mqtt.internal.MqttMessageSubscriber] - Processing new message for topic 'feeds/messages'
23:01:39.802 [TRACE] [g.mqtt.internal.MqttMessageSubscriber] - raw bytes: [49, 50, 51, 46, 52, 53, 46, 54, 46, 55, 56, 32, 77, 101, 114, 114, 121, 32, 67, 104, 114, 105, 115, 116, 109, 97, 115, 33]
23:01:39.804 [INFO ] [smarthome.event.ItemStateChangedEvent] - lastMessage changed from June comes before July to 123.45.6.78 Merry Christmas!
23:01:39.807 [TRACE] [g.mqtt.internal.MqttMessageSubscriber] - Transformation service param = '123.45.6.78 (.*)'
23:01:39.808 [TRACE] [g.mqtt.internal.MqttMessageSubscriber] - First pass transform: 'Merry Christmas!'
23:01:39.808 [TRACE] [g.mqtt.internal.MqttMessageSubscriber] - Final transform: 'Merry Christmas!'
23:01:39.810 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'regexDebug' received command Merry Christmas!
23:01:39.812 [INFO ] [smarthome.event.ItemStateChangedEvent] - regexDebug changed from NULL to Merry Christmas!

Well that is frustrating. I guess I’ll have to live with the errors. They happen every 30 seconds so they render my opehab.log almost useless.

Thanks for trying.

If you want to dig further, this test jar might show where the exception is being thrown.

Thanks. I’ll give it a try when I have some time this week and report back if I learn anything.

OK, I figured out both what changed and the problem. Not sure if this is an actual problem to be solved or not.

The messages are coming with newline characters which is why the regex_filter is not matching. Ideally I should strip the trailing newline off of the message but I wanted to see if I can handle the newline. I’ve not figured out how.

First of all, I’m certain yet whether it is a \r\n or just a \n. It’s all Linux all the way so I’m assuming just \n.

So I tried "10.10.1.200 (ON|OFF).", and even just . to no avail. As long as that newline character is in the message the regex_filter will not match the message. Is there a trick I don’t know about (maybe I need to a \g?) or does the regex filter not support multi-line messages, or is this a legitimate bug?

I have no idea how long this service has been returning a newline as part of the message but I’m pretty sure it is before the upgrade. It may have done so since the beginning. But I didn’t notice the error until after the upgrade, though it could have been an error before that.

Any ideas? Sorry to send you on a wild goose chase.

I never was able to figure out exactly what changed. The code posting the message hasn’t changed in well over a year but there has been some updates around it (i.e. Python libraries I’ve used) so perhaps that is something that happend. Anyway I have been able to get this to work using:

mqtt="<[mosquitto:scripts/presence/iphone/results:command:REGEX(10.10.1.200 (.*)):10.10.1.200 .*(\r\n|\r|\n)+.*]"

Sorry for the wild goose chase.