openHAB2, MAX! binding, no effect on hardware

Hi,

I am new to openHAB, but for more than 2 weeks I am trying to get a basic system running. I have a test installation on Mac OS X 10.12 with the newest openHAB2 builds. At home I have a MAX! Cube with some thermostats and shutter contact. The system is running without problems.

I configured the Max!-system in openHAB2 with PaperUI and BasicUI. I can see all the items and can change the temperature, but nothing will happen on the actual MAX! hardware. All things are online and there are no errors in the log.

Here is the log after I changed the temperature for “Buero_Temperatur_soll” from 21.5 to 28.5 °C:

17:01:23.862 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'Buero_Temperatur_soll' received command 28.5
17:01:23.902 [INFO ] [marthome.event.ItemStateChangedEvent] - Buero_Temperatur_soll changed from 21.5 to 28.5
17:01:28.271 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Command 9 (MEQ0346584-set_temp:28.5) sent to MAX! Cube at IP: 192.168.66.42
17:01:28.271 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #80 to MAX! Cube
17:01:28.455 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - S message. Duty Cycle: 0, Free Memory Slots: 0
17:01:38.255 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #81 to MAX! Cube
17:01:38.355 [DEBUG] [b.binding.max.internal.device.Device] - Device 11eb6b (Wallmounted Thermostat): Actual Temperature : 22.5
17:01:38.355 [DEBUG] [b.binding.max.internal.device.Device] - Device 101aa0 (Thermostat): Actual Temperature : 22.5
17:01:38.356 [DEBUG] [b.binding.max.internal.device.Device] - Device 14945a (Shutter Contact): Status: Closed
17:01:38.356 [DEBUG] [b.binding.max.internal.device.Device] - Device 102a96 (Thermostat): Actual Temperature : 21.7
17:01:38.356 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fc0f (Thermostat): Actual Temperature : 22.4
17:01:38.356 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fbe9 (Thermostat): Actual Temperature : 21.5
17:01:38.356 [DEBUG] [x.internal.handler.MaxDevicesHandler] - No changes for Thermostat Heizung BĂĽro (MEQ0346584) id: max:thermostat:KEQ0534301:MEQ0346584
17:02:08.357 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #82 to MAX! Cube
17:02:08.456 [DEBUG] [b.binding.max.internal.device.Device] - Device 11eb6b (Wallmounted Thermostat): Actual Temperature : 22.5
17:02:08.457 [DEBUG] [b.binding.max.internal.device.Device] - Device 101aa0 (Thermostat): Actual Temperature : 22.5
17:02:08.457 [DEBUG] [b.binding.max.internal.device.Device] - Device 14945a (Shutter Contact): Status: Closed
17:02:08.457 [DEBUG] [b.binding.max.internal.device.Device] - Device 102a96 (Thermostat): Actual Temperature : 21.7
17:02:08.457 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fc0f (Thermostat): Actual Temperature : 22.4
17:02:08.457 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fbe9 (Thermostat): Actual Temperature : 21.5
17:02:08.458 [DEBUG] [x.internal.handler.MaxDevicesHandler] - No changes for Thermostat Heizung BĂĽro (MEQ0346584) id: max:thermostat:KEQ0534301:MEQ0346584

It seems that the last line with “x.internal.handler.MaxDevicesHandler” is the problem. The same message appears with shutter contacts.

Does anyone have a clue what to do?

The [DEBUG] [x.internal.handler.MaxDevicesHandler] - No changes for Thermostat Heizung BĂĽro lines are perfectly normal.
It just means that no difference was detected, hence no updates are made.
The odd line in your log is the s message, which indicates no memory positions free. If that is true, the cube will ignore all commands until free places are available.

Can you run once with trace level and attach the full max log. That may give some more clues tho what’s going on.

Hello Marcel,

Thank you for your quick reply.

Here is the trace log:

19:12:06.817 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Command queued id 1 (MEQ0346584-set_temp:30).
19:12:06.818 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'Buero_Temperatur_soll' received command 30
19:12:06.819 [INFO ] [marthome.event.ItemStateChangedEvent] - Buero_Temperatur_soll changed from 20.5 to 30
19:12:08.909 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Command 1 (MEQ0346584-set_temp:30) sent to MAX! Cube at IP: 192.168.66.42
19:12:08.910 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #15 to MAX! Cube
19:12:08.910 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - Write string to Max! Cube 192.168.66.42: s:AARAAAAAEfvpBDw=

19:12:09.102 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - message block: 'S:00,1,00'
19:12:09.102 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - === S_Message === 
19:12:09.102 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 	RAW : 00,1,00
19:12:09.102 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 	DutyCycle         : 0
19:12:09.103 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 	Command Discarded : false
19:12:09.103 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 	FreeMemorySlots   : 0
19:12:09.103 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - S message. Duty Cycle: 0, Free Memory Slots: 0
19:12:09.103 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - Command 1 (MEQ0346584-set_temp:30) completed for MAX! Cube at IP: 192.168.66.42
19:12:33.908 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #16 to MAX! Cube
19:12:33.908 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - Write string to Max! Cube 192.168.66.42: l:

19:12:34.003 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - message block: 'L:DBHrawkCGAQtAAAA4QsQGqAJAhgWLQDhAAYUlFoJAhALECqWCQIYASgA2QALEfwPCQIYJS0A4AALEfvpCQIYGSkA1wA='
19:12:34.003 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - === L_Message === 
19:12:34.003 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 	RAW:DBHrawkCGAQtAAAA4QsQGqAJAhgWLQDhAAYUlFoJAhALECqWCQIYASgA2QALEfwPCQIYJS0A4AALEfvpCQIYGSkA1wA=
19:12:34.003 [TRACE] [b.binding.max.internal.device.Device] - Device 11eb6b (Wallmounted Thermostat): L Message length: 12 content: 11 EB 6B 09 02 18 04 2D 00 00 00 E1
19:12:34.003 [DEBUG] [b.binding.max.internal.device.Device] - Device 11eb6b (Wallmounted Thermostat): Actual Temperature : 22.5
19:12:34.004 [TRACE] [b.binding.max.internal.device.Device] - Device 101aa0 (Thermostat): L Message length: 11 content: 10 1A A0 09 02 18 16 2D 00 E1 00
19:12:34.004 [DEBUG] [b.binding.max.internal.device.Device] - Device 101aa0 (Thermostat): Actual Temperature : 22.5
19:12:34.004 [TRACE] [b.binding.max.internal.device.Device] - Device 14945a (Shutter Contact): L Message length: 6 content: 14 94 5A 09 02 10
19:12:34.004 [DEBUG] [b.binding.max.internal.device.Device] - Device 14945a (Shutter Contact): Status: Closed
19:12:34.004 [TRACE] [b.binding.max.internal.device.Device] - Device 102a96 (Thermostat): L Message length: 11 content: 10 2A 96 09 02 18 01 28 00 D9 00
19:12:34.004 [DEBUG] [b.binding.max.internal.device.Device] - Device 102a96 (Thermostat): Actual Temperature : 21.7
19:12:34.004 [TRACE] [b.binding.max.internal.device.Device] - Device 11fc0f (Thermostat): L Message length: 11 content: 11 FC 0F 09 02 18 25 2D 00 E0 00
19:12:34.005 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fc0f (Thermostat): Actual Temperature : 22.4
19:12:34.005 [TRACE] [b.binding.max.internal.device.Device] - Device 11fbe9 (Thermostat): L Message length: 11 content: 11 FB E9 09 02 18 19 29 00 D7 00
19:12:34.005 [DEBUG] [b.binding.max.internal.device.Device] - Device 11fbe9 (Thermostat): Actual Temperature : 21.5
19:12:34.005 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - 6 devices found.
19:12:34.005 [DEBUG] [x.internal.handler.MaxDevicesHandler] - No changes for Shutter Contact TerrassentĂĽr WZ (MEQ1803219) id: max:shuttercontact:KEQ0534301:MEQ1803219
19:12:34.006 [DEBUG] [x.internal.handler.MaxDevicesHandler] - No changes for Thermostat Heizung BĂĽro (MEQ0346584) id: max:thermostat:KEQ0534301:MEQ0346584

I am afraid that is too much for me. I don’t understand the details.

There is certainly something strange going one. Your cube is receiving / sending too many commands
The free memory slots is 0, hence that normally means that there are 49 commands still waiting in the cube to be send to the thermostats. FreeMemorySlots : 49

Do you have the Binding Settings - Actual Temperature Refresh Rate setting with something different than 0?
If yes, can you put that to 0.

Also, cab you try to do a reboot of the cube (can be done from the menu, or by unplugging & replugging the cube) to see if this is there from boot time onwards

See here an example of my cube after sending a command…

00:16:49.050 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Command 1 (LEQ0015340-set_temp:18) sent to MAX! Cube at IP: 192.168.3.9
00:16:49.057 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - Sending request #57 to MAX! Cube
00:16:49.071 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - Write string to Max! Cube 192.168.3.9: s:AARAAAAADhXMAiQ=

00:16:49.224 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - message block: 'S:01,0,31'
00:16:49.231 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - === S_Message ===
00:16:49.233 [TRACE] [nternal.handler.MaxCubeBridgeHandler] -   RAW : 01,0,31
00:16:49.234 [TRACE] [nternal.handler.MaxCubeBridgeHandler] -   DutyCycle         : 1
00:16:49.236 [TRACE] [nternal.handler.MaxCubeBridgeHandler] -   Command Discarded : false
00:16:49.238 [TRACE] [nternal.handler.MaxCubeBridgeHandler] -   FreeMemorySlots   : 49
00:16:49.250 [DEBUG] [nternal.handler.MaxCubeBridgeHandler] - S message. Duty Cycle: 1, Free Memory Slots: 49
00:16:49.251 [TRACE] [nternal.handler.MaxCubeBridgeHandler] - Command 1 (LEQ0015340-set_temp:18) completed for MAX! Cube at IP: 192.168.3.9
1 Like

You are right: The problem was the free memory slots. After rebooting the cube I had 50 free slots. Now it is working like expected.

Thank you very much for your support.

I’m happy to hear that.
In the mean time I also spotted an issue with the parsing of the Command Discarded element.
I fixed that, so if this happens again you will have a more clear warning in the log.

Hi,

I have similar issue but reboot of cube does not help, and it shows 50 free slots,…

2017-04-06 20:24:52.805 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 4, Free Memory Slots: 50
2017-04-06 20:24:58.002 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 4, Free Memory Slots: 50
2017-04-06 20:25:08.403 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 6, Free Memory Slots: 50
2017-04-06 20:26:53.608 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 6, Free Memory Slots: 50
2017-04-06 20:26:58.812 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 6, Free Memory Slots: 50
2017-04-06 20:27:09.210 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50
2017-04-06 20:34:54.442 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50
2017-04-06 20:34:59.641 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50
2017-04-06 20:35:04.841 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50
2017-04-06 20:35:35.042 [WARN ] [nternal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50

What I may need to check or test here? Using exclusive mode on at this moent and autoupdate actual temperature every 60min and that seems to work, but at some devices not always the slots seems to be always free when I take a look
I see the updates of the setoint temperature but it does seem to be smaller time then configured like 20min instead of 60min and i recieve feedback at all channels except at 2 at those the updates are more time between almost looking sporadicly (all configured the same in paper ui).
What is suspect when looking at the diagrams is that the actual temperature update seems to happen at all of the devices at the same time,… is it not possible to dispatch them that there are send in serial instead of paralell, maybe this is the cause?!

Hi,
if indeed it tries starts the automatic update more frequent than set in the config, it would be a bug.
Would you mind trying to capture the log for a longer time and send it. I’ll try to understand what’s causing it. Pls indicate which one you think it’s problematic.
The auto refresh is still a bit of an experimental feature / but of a hack, so I can imaging that specific conditions are not well handled

I’ll add a random delay for the first update, that will avoid the mass sending of command, though that should not cause this issue.

Just as a note: I added some MAX! devices to my home setup last week. Since then I observed problems like the above mentioned and others with the openHAB 2 connection. In most cases the values of the channels are not displayed correctly in oH2. But the mentioned log message

Last Send Command discarded. Duty Cycle: XXX, Free Memory Slots: YYY

shows up more often than before. I didn’t activate debug logging, yet. I’ll try that and post more details after I have done my research. I have in mind there is a maximum number of commands which the binding / MAX! Cube can process. Is that correct? How does the binding handle that? Does it depend on the number of devices or the number of channels (e.g. did each channel exhaust one command slot)?

Looks like you are sending too many commands to the cube. The cube can only send in total 1% per hour. If the alloted transmission time in an hour is used up, the cube blocks further messages.

To limit the number of commands send, I filter them to check I’m not sending the a command that has already been implemented. For example setting a thermostat to 20 degrees when it is already at 20 degrees.

Hey Mark,

thanks for pointing that out. But I am doing that already - most of the times. I only send commands if a real change has to be done. I do the same checks like you.

I activated debug logging and did some tests and I am thinking I found my problem - which isn’t a real problem. The mentioned log message pops up after restarting the openHAB service or editing the items file containing the MAX! items. Every reload of the items file triggers sending those commands and that is the reason for my occupied command slots. When I leave the system untouched it runs as expected. My Refresh Interval is set to 30 seconds and the requests were send in time. Neither faster nor slower.

Good to hear it works like expected. If you want to check add an item for the channels duty cycles and memory slots on the cube. That way you can see how much space you have left. Btw, be aware that the cube only reports those channels if you send commands.

One of the main driver for sending too many command is the experimental feature of actuals update.
As the actual temperature is only updated when a valve is moving, the binding actually changes the set-temperature twice (once to change it to a temporary temperature, than back to the original)

Esp if you have many thermostats that may be a lot of traffic exceeding the maximum duty-cycle. So the more thermostats you have, the slower that actuals refresh needs to be (or switched off completely).

I am also experiencing the “last send command discarded” warning at one of my thermostats (I have a second one working as expected in my home). Strangely, the working thermostat changes once in a while – I have no idea why.
I already tried restarting the max cube but the issue remains.
I configured all thermostats and window sensors via the paper gui in openhab2 so I cannot really change the update intervals, can I?
Do you have any other idea what might be wrong?

Typically the discard issue comes from to many over the air commands.
The cube reports that the queues is full, hence the binding will no longer send commands to the cube.

This can happen if e.g you have lot of rules changing the temperature of a thermostat.

Best to switch off the experimental actual temperature feature if enabled, as this feature is generating a lot of commands esp if you have many thermostats

Lowering the poll frequency (through paperui using the advanced settings) does not really help, as the cube queues get only filled when you send commands, not when just pulling the state

Hi everyone!

Long time since last posting here.

I had the same error today:
20:17:00.239 [WARN ] [internal.handler.MaxCubeBridgeHandler] - Last Send Command discarded. Duty Cycle: 9, Free Memory Slots: 50

I found a solution for me. In my case there was an uninitialized shutter contact in my living room which causes a discard of any temperature command to this room. Exactly the same issue as described by Chris-Walter: All my other thermostats were working except of these ones. After replacing batteries and the initialization of the shutter contact everything worked!

Maybe this is helpful for someone…

1 Like