Remove \r from TCP response with transform

mattias_mansson · August 28, 2017, 6:39pm

Hi!

Trying to get the TCP binding to work as I want it with my new Marantz AVR (SR5012) and I’m almost there. I’m using the TCP binding (from version 1) and I have created a very simple item:

String MarantzIp				""					{ tcp=">[192.168.0.13:23:REGEX((.*))]" }

It seems to work fine, the commands are sent, responses come back. The problem is that if a command has no effect, for instance sending on when it’s already on, there is no response at all. My rules doesn’t like that so much. So I’m trying to keep the state by parson the value in my item (which should get updated with the responses), but it’s hard because the answers end with carriage return which craps up the logging. I’ve tried using regex to remove \r, but no effect whatever I do. I’m not sure if the regex affects only incoming data with the TCP binding or outgoing as well? I have also tried matching the data WITH \r, but never matches:

rule "Marantz State"
when
	Item marantzIp changed
then
	if (MarantzIp.state.toString == "SIMPLAY\r") {
		logInfo("Marantz", "HTPC")
	}
	else if (MarantzIp.state.toString == "SICD\r") {
		logInfo("Marantz", "BLUE")
	}
end

Please help, I’m low on hair to pull…

rlkoshak · August 28, 2017, 8:31pm

In your rule try using state.toString.startsWith("SIMPLAY")

In your REGEX try using REGEX((.*)\r)

mattias_mansson · August 29, 2017, 6:59am

Ah ofc, so simple! Will try that tonight! Thanks!

mattias_mansson · August 30, 2017, 3:32pm

That regex doesn’t really work, I get an exception:

17:30:22.935 [ERROR] [el.item.internal.GenericItemProvider] - Binding configuration of type 'tcp' of item 'MarantzIp' could not be parsed correctly.
)]' doesn't contain a valid binding configurationseException: bindingConfig '>[192.168.0.13:23:REGEX((.*)
	at org.openhab.core.binding.internal.BindingConfigReaderDelegate.processBindingConfiguration(BindingConfigReaderDelegate.java:50)[190:org.openhab.core.compat1x:2.1.0.201703310852]
	at org.eclipse.smarthome.model.item.internal.GenericItemProvider.internalDispatchBindings(GenericItemProvider.java:312)[124:org.eclipse.smarthome.model.item:0.9.0.201703201701]
	at org.eclipse.smarthome.model.item.internal.GenericItemProvider.internalDispatchBindings(GenericItemProvider.java:284)[124:org.eclipse.smarthome.model.item:0.9.0.201703201701]
	at org.eclipse.smarthome.model.item.internal.GenericItemProvider.processBindingConfigsFromModel(GenericItemProvider.java:167)[124:org.eclipse.smarthome.model.item:0.9.0.201703201701]
	at org.eclipse.smarthome.model.item.internal.GenericItemProvider.modelChanged(GenericItemProvider.java:346)[124:org.eclipse.smarthome.model.item:0.9.0.201703201701]
	at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:281)[123:org.eclipse.smarthome.model.core:0.9.0.201703201701]
	at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:136)[123:org.eclipse.smarthome.model.core:0.9.0.201703201701]
	at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:240)[123:org.eclipse.smarthome.model.core:0.9.0.201703201701]
	at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.processWatchEvent(FolderObserver.java:308)[123:org.eclipse.smarthome.model.core:0.9.0.201703201701]
	at org.eclipse.smarthome.core.service.WatchQueueReader.run(WatchQueueReader.java:209)[99:org.eclipse.smarthome.core:0.9.0.201703201701]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]

Do I have to escape it differently? My item looks like this:

String MarantzIp				""					{ tcp=">[192.168.0.13:23:REGEX((.*)\r)]" }

rlkoshak · August 30, 2017, 6:07pm

I didn’t think so but it sure looks like it. Escape the \ by adding another one. I.e. \r

mattias_mansson · August 30, 2017, 6:35pm

Tested that, at least it got rid of the expection, but the log is still messed up as it prints the \r with the item values. I maybe doesn’t know how it works with transforms, but I would expect the transform applies BEFORE the value is set to the item? So if my regex works there should be no messed up logs?

Can’t get a match in my rules either whatever I do, I tried your startsWith suggestion also but I never see my log prints from that rule:

rule "Marantz State"
when
	Item marantzIp changed
then
	if (MarantzIp.state.toString.startsWith("SIMPLAY")) {
		logInfo("Marantz", "HTPC")
	}
	else if (MarantzIp.state.toString.startsWith("SICD")) {
		logInfo("Marantz", "BLUE")
	}
end

I tested again also to make sure I haven’t misunderstood the protocol, but it seems correct:

]$ echo -e -n 'PW?\r' | netcat -x 192.168.0.13 23
Sent 4 bytes to the socket
00000000  50 57 3F 0D                                         PW?.            
Received 5 bytes from the socket
00000000  50 57 4F 4E  0D                                     PWON.           
Received 5 bytes from the socket
00000000  5A 32 4F 4E  0D                                     Z2ON.

rlkoshak · August 30, 2017, 6:49pm

That is correct.

As long as you are seeing that error about the binding config for all intents and purposes your Item doesn’t exist. You need to get the binding config right first. Replace the REGEX with “default” (I think that works with mqtt) or use REGEX((.*)), which will pass the full message received to the String Item.

Add a logInfo to the Rule that gets printed no matter what the message is so you know whether the rule is firing.

I do not see anything that would match to “SIMPLAY” or “SICD” in that example of the protocol.

mattias_mansson · August 30, 2017, 6:51pm

Sorry, copied the wrong part:

$ echo -e -n 'SI?\r' | netcat -x 192.168.0.13 23
Sent 4 bytes to the socket
00000000  53 49 3F 0D                                         SI?.            
Received 8 bytes from the socket
00000000  53 49 4D 50  4C 41 59 0D                            SIMPLAY.        
Received 6 bytes from the socket
00000000  53 56 4F 46  46 0D                                  SVOFF.

mattias_mansson · August 30, 2017, 7:13pm

That regex seems to affect outgoing messages as well, the AVR doesn’t seem affected at all if I change it to REGEX((.*)\r). Starting to give up soon and script the network parts myself and use MQTT instead… Not sure I can solve this.

rlkoshak · August 30, 2017, 7:38pm

In that case, use a default regex:

REGEX((.*))

and all the parsing and processing needs to take place in the Rule.

Step back and start with a rule that simply logs out the message.

Then add back in the startsWith if statements.

That should give you enough information to figure out what might be going wrong and it can be fixed.

mattias_mansson · August 30, 2017, 8:08pm

OK, I’m trying a really simple example now. I have an item called MarantzTest, whenever it is changed (from a button), this rule sends a command (to get the current input device of my AVR):

rule "Marantz Test"
when
	Item MarantzTest received update
then
	logInfo("Marantz", "TEST")
	sendCommand(MarantzIp, "SI?\r")
end

Then I have the rule for when MarantzIp is changed (which is my TCP item):

rule "Marantz State"
when
	Item marantzIp changed
then
	if (MarantzIp.state.toString.startsWith("SIMPLAY")) {
		logInfo("Marantz", "<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<HTPC")
	}
	else if (MarantzIp.state.toString.startsWith("SICD")) {
		logInfo("Marantz", "<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<BLUE")
	}
	else {
		logInfo("Marantz", "<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<NO MATCH");
	}
end

I made the prints very long as the \r fucks up my logging and moves the cursor while printing and this is what I get:

22:04:31.082 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'MarantzTest' received command GET
22:04:31.084 [INFO ] [lipse.smarthome.model.script.Marantz] - TEST
22:04:31.085 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'MarantzIp' received command SI?
SVOFF to SI? [INFO ] [marthome.event.ItemStateChangedEvent] - MarantzIp changed from SIMPLAY
SVOFFIMPLAY0 [INFO ] [marthome.event.ItemStateChangedEvent] - MarantzIp changed from SI?
SVOFFIMPLAY1 [INFO ] [marthome.event.ItemStateChangedEvent] - MarantzIp changed from SIMPLAY

Doesn’t seem as the rule match on MarantzIp at all…

My items are these for this test:

String MarantzIp				""					{ tcp=">[192.168.0.13:23:REGEX((.*))]" }
String MarantzTest				""

mattias_mansson · August 30, 2017, 8:11pm

Haha, found the error… In the rule I use marantzIp, in the items MarantzIp. Weird it doesn’t complain though as it doesn’t exist…

Thanks for all your help though, really nice of you!

rlkoshak · August 30, 2017, 8:32pm

Glad you got it working.

I highly recommend using ESH Designer which would have caught that error.

mattias_mansson · August 31, 2017, 6:51am

That’s the funny part, I am using it. Doesn’t complain at all…

mattias_mansson · August 31, 2017, 4:31pm

I still have some problems though, it seems to work sometimes and sometimes not. I’m starting to suspect there is some problem with either the TCP binding separating the responses by \r or the regex/openhab or whatever. I’m suspecting that startsWith doesn’t really work then… Any idea how I can force it to split on \r? TCP binding config?

I.e. what kind of separator does the TCP binding use and can it be changed? Can’t find any information…

rlkoshak · August 31, 2017, 5:01pm

I know nothing about the TCP binding. You would have to look in the logs.

The startsWith doesn’t really care if the String has a \r or not. But if messages are coming in truncated or starting with \r or other whitespace it could cause problems.

To fix your logging issues caused by the \r, it just occurred to me you can do the following:

    val message = MarantzIP.state.toString.replace('\r', ' ') // replace \r with space
    logInfo("Marantz", "Received message: " + message)

Then, to eliminate the possibility that there is white space or something before the start of the command string use contains instead of startsWith. I’ll show that below with a switch statement which IMHO is easier to read.

    switch message {
        case message.contains("SIMPLAY") : logInfo("Marantz", "HTPC")
        case message.contains("SICD"): logInfo("Marantz", "BLUE")
        default: logInfo("Marantz", "NO MATCH")
    }

And for encouragement, realize that the TCP binding is perhaps the hardest of all OH bindings to get working the way you need it. TCP/UDP is so low level, and there are so many edge cases and weird behavior with networking at this level that few manage to make it work as they need. You have already come much farther than most.

mattias_mansson · August 31, 2017, 5:05pm

I undestand, I’m greatful you try to help me! I’m actually thinking of going that way with MQTT to my own script instead or maybe use node-red for the network part (had good experience with that before). Think that even if I can get it to work, it is starting to be too much work.

Your solution above sounds good, but I guess if there is a quick switch back and forth and it doesn’t split as I think, it could be both responses in the same message. But I will try that too…

rlkoshak · August 31, 2017, 9:37pm

That is why I log out the contents of the message first thing no matter the message. You should be able to see when the switch statement fails to match and look at the actual message to determine why.