[LCN] OH3 fails to receive status messages after some time

Hello,

as there don’t seem to be many LCN users in the german openhabforum.de where I have already asked for help on this topic ([LCN] OH3 empfängt nach einiger Zeit keine Statusmeldungen mehr? - openhabforum.de), I am looking for assistance here now.

OH3 runs on a Raspberry 4B. In addition to the LCN binding I have a deCONZ/conbee to manage some motion sensors, lamps and humidity sensors.
Generally the LCN binding works: modules have been auto discovered, outputs can be set via OH, binary sensor states appear in the OH logs and rules react on those state changes.
But after a certain time (sometimes a few minutes, sometimes hours, sometimes a few days) the following warnings appear in the logs and no status messages of the modules come in any more.

2022-11-15 21:40:26.397 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Module did not respond to command: A1DI000000
2022-11-15 21:46:51.715 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M009: Failed to receive status message: Binary Sensors: Failed finally after 3 tries
2022-11-15 21:47:25.750 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Failed to receive status message: Output 1: Failed finally after 3 tries

In this state it is still possible e. g. to set the outputs of a module, but lacking the status feedback.
On the LCN side, i. e. in the bus log (LCN-Pro and LinHK), the said modules are still sending status messages – only OH has ceased to receive them.
I can remedy this state by disabling/enabling the PCK gateway Thing – until, after some time, the said warnings reappear.
Increasing the ‘connection timeout’ from 3s to 5s or 15s in the PCK gateway Thing doesn’t change the behaviour.
In the original post in the german forum I wondered about one module sending status messages containing a ‘4’ in the module name, which I suspected to be a possible reason for the LCN binding to not correctly interpret the status message.

2022-11-15 22:11:18.128 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M004009Bx008'
2022-11-15 22:11:23.631 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M004009Bx000'

This was due to setting status messages to ‘global’ in the property settings of this very module (LCN-Pro); ‘global’ messages are sent to the special segment ‘4’.
But resetting this setting back to ‘local’ didn’t change the issue.
My LCN modules are older ones with firmware versions 13 and 14.

In the german bus-profi forum I found a discussion (Feb. 2016, OH1 or OH2?) about delayed forwarding of (dimming) commands to the LCN bus.
The LCN binding was suspected (and criticised) to work based on acknowledge messages (Quittungsmeldungen), i. e. every command sent to the bus requesting an acknowledgement.
The problem being that these acknowledge (ack) messages cannot be ascribed to a specific command (as they do not contain any reference to the command that caused the ack message).
Furthermore the loss of such ack messages (e. g. due to bus collisions) or the fact(?) that no ack and status messages are sent, if a command does not cause a change of a module’s state (e. g. output or relay state) – if not adequately handled in the binding – could lead to unnecessary resending of commands or being caught in timeouts (waiting for ack messages).
In the case of missing ack messages the binding repeatedly sends the same commands to the bus, while increasing the timeouts between two commands.
Subsequent commands being queued during these timeouts, the user has the impression of a blocked/irresponsive system. (This could e. g. happen when slowly moving a dimming slider and the binding repeatedly sending identical commands, that are not acknowledged, as no state changes…).
It was suggested to rather rely on status messages (and track intended changes of an output or relay) instead of waiting for unspecific ack messages.

I don’t know if these assumptions of working principles (still) hold true for the current LCN binding, but there might be a relation to the issue of missing status messages described above?

Could it be that a module is ‘switched off’ in a certain way by the binding, after a number of timeouts?
(NB: the module is still sending status messages (cf. LCN bus log); after disable/enable of the gateway Thing the module’s status messages are ‘live’ again.)

Best,
Jo.

If you set the log level for the LCN binding to TRACE, you should see all telegrams you also see in the LCN-PRO bus monitor. Is that true, if the lock-up happens you described?

The binding should also react to status messages sent to segment 4. Seems like a bug as you describe it. But it should have no relation to your actual issue.

Hello Fabian,

thanks for replying.

I have set the log level to ‘TRACE’:
In the locked-up state I see the following in the log:

2022-11-23 11:08:48.197 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M011: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:08:51.200 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:08:51.202 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M007: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:08:51.203 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:08:52.206 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:09:02.216 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M009: Failed to receive status message: Binary Sensors: Failed finally after 3 tries

2022-11-23 11:18:58.706 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M011: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:19:01.710 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:19:01.711 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M007: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:19:01.712 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:19:02.715 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:19:12.725 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M009: Failed to receive status message: Binary Sensors: Failed finally after 3 tries

2022-11-23 11:24:17.870 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping1636

2022-11-23 11:25:17.870 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping1637

2022-11-23 11:27:17.872 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping1639

2022-11-23 11:28:17.873 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping1640

2022-11-23 11:28:54.197 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2

2022-11-23 11:28:57.200 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008.SMA1

2022-11-23 11:28:57.203 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1

2022-11-23 11:28:57.205 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA1

2022-11-23 11:28:58.202 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA2

2022-11-23 11:28:59.203 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2

2022-11-23 11:29:02.206 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008.SMA1

2022-11-23 11:29:02.208 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1

2022-11-23 11:29:02.211 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA1

2022-11-23 11:29:03.207 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA2

2022-11-23 11:29:04.208 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2

2022-11-23 11:29:07.211 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008.SMA1

2022-11-23 11:29:07.213 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1

2022-11-23 11:29:07.216 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA1

2022-11-23 11:29:08.212 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000009.SMB

2022-11-23 11:29:08.214 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA2

2022-11-23 11:29:09.215 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M011: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:29:12.221 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:29:12.223 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M007: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:29:12.224 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 1: Failed finally after 3 tries

2022-11-23 11:29:13.227 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000009.SMB

2022-11-23 11:29:13.227 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M012: Failed to receive status message: Output 2: Failed finally after 3 tries

2022-11-23 11:29:17.874 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping1641

2022-11-23 11:29:18.233 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000009.SMB

2022-11-23 11:29:23.237 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M009: Failed to receive status message: Binary Sensors: Failed finally after 3 tries

Status messages are requested but no replies are received.
The LCN log (LinHK) does show the requested status messages:

|11:29:40.196326|9|>M000009.A1DI000002|
|---|---|---|
|11:29:18.406066|9|:M000009Bx000|
|11:29:18.258825|4|>M000009.SMB|
|11:29:13.405956|9|:M000009Bx000|
|11:29:13.253437|4|>M000009.SMB|
|11:29:08.407503|9|:M000009Bx000|
|11:29:08.237001|4|>M000009.SMB|
|11:29:07.404117|9|&M000009.MST2SC=139581;TS=...|
|11:28:17.271235|9|&M000009.MST122d,16:55:39;...|
|11:27:39.093486|9|&M000009.MW000000119600000|
|11:27:27.187909|9|=M000009.TLAAAAAAAAAAAANNNN|
|11:26:37.209731|9|%M000009.S101165|
|11:25:40.232769|9|>M000009.A1DI000002|
|11:24:06.152660|9|&M000009.MST2SC=139572;TS=...|
|11:23:40.243483|9|>M000009.A1DI000002|
|11:23:15.931493|9|&M000009.MST122d,16:50:37;...|
|11:22:39.170322|9|&M000009.MW000000119600000|
|11:22:26.133891|9|=M000009.TLAAAAAAAAAAAANNNN|
|11:21:40.260233|9|>M000009.A1DI000002|

Best,
Jo

PS: the LCN log was filtered with expression: ‘m000009’

Intresting behavior. I’ll have a look at the weekend.

1 Like

I looked into the code but couldn’t find any particular reason that could cause these lock-ups. As there are several users using openHAB with PCHK, one could come to the conclusion it’s something related to LinHK.

I have had feedback that the binding isn’t working with the DOMIQ gateway, due to some line ending issues. Unfortunately the communication with the user stalled, so I couldn’t investigate it further.

Can you post the logs at TRACE level when the transition from working to the locked-up state happens? Could be that there’s a deadlock in the connection state machine, especially if something unusual happens, which could be caused by LinHK.

I validated that the openHAB binding is processing status messages to segment 4 correctly. This is necessary if the LCN module is configured to send status messages globally to all segments.

Thank you Fabian for searching the code.
Analyzing openhab.log and looking for the moments where the lock-up appears, I found out that every time immediately before the binding fails to receive new status messages, there are lines where the modules report their property commentaries:

2022-12-04 22:13:03.120 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000008.K1R8H, B8H - A'
2022-12-04 22:13:03.173 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000010.K1Roll�den Sue'

Shortly afterwards:

2022-12-04 22:14:08.505 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping20
2022-12-04 22:14:09.524 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:14.528 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:19.533 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:24.537 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M007: Failed to receive status message: Output 1: Failed finally after 3 tries
2022-12-04 22:14:59.989 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:05.572 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:08.505 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping21
2022-12-04 22:15:10.577 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:15.580 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Module did not respond to command: A1DI000000

In this state no more status messages are received by the binding.
I think the reason for the hickup could be the following:
The commentary contains the umlaut ä in Rolläden.
(At this point I remembered a forum post where someone found out that umlauts in module names caused problems…)
Indeed, after replacing the umlauts in the modules’ property commentaries (LCN-Pro) there was no lock-up after the said lines:

2022-12-04 22:16:35.823 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000010.K1Rollaeden Su'
2022-12-04 22:16:35.852 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000014.K1KIND.OG'
2022-12-04 22:16:36.103 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000011.K1SZ.OG'
2022-12-04 22:16:36.132 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000015.K1'
2022-12-04 22:16:36.141 [DEBUG] [onnection.ConnectionStateSegmentScan] - No segment couplers detected
2022-12-04 22:16:36.145 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateSegmentScan -> ConnectionStateConnected
2022-12-04 22:16:36.147 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000009.SMB
2022-12-04 22:16:36.149 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:16:36.152 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008.SMA1
2022-12-04 22:16:36.154 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA1
2022-12-04 22:16:36.156 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2
2022-12-04 22:16:36.254 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000008A1000'
2022-12-04 22:16:36.399 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007A1100'
2022-12-04 22:16:36.402 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000009Bx000'
2022-12-04 22:16:36.452 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000012.K1WZ.EG'

The LinHK-Visualisierung (UI) requests the reporting of those commentaries by periodically emitting the command

>G000003.NMK1

Do you think that umlauts in the commentary of a module could lead to the problem described in the thread?
If so, can the offending comments be intercepted to prevent them from causing a lock-up?

Best, Jo.

I added Rolläden Sued to the description of one of my LCN modules and couldn’t reproduce the error.

Can you post the messages between 2022-12-04 22:13:03.173 and 2022-12-04 22:14:08.505? Everything can help. Please don’t truncate or filter the logs.

Do you have the ability to test with LCN-PCHK?

Does your setup differ in any other point from the normal one, beside LinHK?

Why does it do this?

Hi,
here is the complete log. In the first part with the umlaut in the module’s comment and later (after 2022-12-04 22:15:45.043) without the umlaut (changed module’s comment in LCN-Pro and reinitialized the pck gateway thing in OH).

2022-12-04 22:12:55.788 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000005A1062'
2022-12-04 22:12:57.877 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000005A1056'
2022-12-04 22:13:00.287 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000005A1050'
2022-12-04 22:13:02.377 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000005A1046'
2022-12-04 22:13:03.120 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000008.K1R8H, B8H - A'
2022-12-04 22:13:03.173 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000010.K1Roll�den Sue'
2022-12-04 22:13:08.504 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping19
2022-12-04 22:13:47.943 [INFO ] [org.openhab.rule.f6a06bf3a4         ] - Rule BM Küche | Status BM (BmKueche_Bewegung): OFF
2022-12-04 22:13:47.946 [INFO ] [org.openhab.rule.f6a06bf3a4         ] - Nachlauf LED 50 s | Status LED 90
2022-12-04 22:13:52.542 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Rule BM Kellertreppe | Status BM (BmKellertreppeBewegung_Bewegung): OFF
2022-12-04 22:13:52.543 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Nachlauf LED 15 s | Status LED ON
2022-12-04 22:13:52.545 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_sonoff: 1 | myBmSonoffOn: 0
2022-12-04 22:13:52.546 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_lcn: 0 | myBmLcnOn: 0
2022-12-04 22:13:59.611 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Rule BM Kellertreppe | Status BM (BmKellertreppeBewegung_Bewegung): ON
2022-12-04 22:13:59.613 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Nachlauf LED 15 s | Status LED ON
2022-12-04 22:13:59.616 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_sonoff: 1 | myBmSonoffOn: 1
2022-12-04 22:13:59.617 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_lcn: 0 | myBmLcnOn: 0
2022-12-04 22:14:08.505 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping20
2022-12-04 22:14:09.524 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:14.528 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:19.533 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:14:24.537 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M007: Failed to receive status message: Output 1: Failed finally after 3 tries
2022-12-04 22:14:59.989 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:05.572 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:08.505 [TRACE] [g.lcn.internal.connection.Connection] - Sent: ^ping21
2022-12-04 22:15:10.577 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008!A1DI000000
2022-12-04 22:15:15.580 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M008: Module did not respond to command: A1DI000000
2022-12-04 22:15:29.645 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Rule BM Kellertreppe | Status BM (BmKellertreppeBewegung_Bewegung): OFF
2022-12-04 22:15:29.653 [INFO ] [org.openhab.rule.dbbe52bee3         ] - Nachlauf LED 15 s | Status LED ON
2022-12-04 22:15:29.656 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_sonoff: 1 | myBmSonoffOn: 0
2022-12-04 22:15:29.658 [INFO ] [org.openhab.rule.dbbe52bee3         ] - bm_lcn: 0 | myBmLcnOn: 0
2022-12-04 22:15:45.043 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateConnected -> ConnectionStateShutdown
2022-12-04 22:16:15.992 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateInit -> ConnectionStateConnecting
2022-12-04 22:16:15.995 [DEBUG] [connection.ConnectionStateConnecting] - Connecting to 192.168.178.21:4114 ...
2022-12-04 22:16:16.006 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateConnecting -> ConnectionStateSendUsername
2022-12-04 22:16:16.012 [TRACE] [g.lcn.internal.connection.Connection] - Received: 'LCN-PCK/IP 1.0'
2022-12-04 22:16:16.017 [TRACE] [g.lcn.internal.connection.Connection] - Received: 'Username:'
2022-12-04 22:16:16.080 [TRACE] [g.lcn.internal.connection.Connection] - Sent: pro
2022-12-04 22:16:16.091 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateSendUsername -> ConnectionStateSendPassword
2022-12-04 22:16:16.093 [TRACE] [g.lcn.internal.connection.Connection] - Received: 'Password:'
2022-12-04 22:16:16.104 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateSendPassword -> ConnectionStateWaitForLcnBusConnected
2022-12-04 22:16:16.104 [TRACE] [g.lcn.internal.connection.Connection] - Received: 'OK'
2022-12-04 22:16:16.112 [TRACE] [g.lcn.internal.connection.Connection] - Sent: XXXX
2022-12-04 22:16:21.119 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateWaitForLcnBusConnected -> ConnectionStateSendDimMode
2022-12-04 22:16:21.122 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateSendDimMode -> ConnectionStateSegmentScan
2022-12-04 22:16:21.122 [TRACE] [g.lcn.internal.connection.Connection] - Sent: !OM0P
2022-12-04 22:16:21.127 [TRACE] [g.lcn.internal.connection.Connection] - Received: '(0..50-mode percent)'
2022-12-04 22:16:21.133 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >G003003.SK
2022-12-04 22:16:21.377 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx064'
2022-12-04 22:16:23.127 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx008'
2022-12-04 22:16:23.206 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:23.676 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx072'
2022-12-04 22:16:23.705 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:26.135 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >G003003.SK
2022-12-04 22:16:26.175 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx064'
2022-12-04 22:16:29.673 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx000'
2022-12-04 22:16:30.173 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx008'
2022-12-04 22:16:30.404 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:31.139 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >G003003.SK
2022-12-04 22:16:31.691 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx072'
2022-12-04 22:16:32.622 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx000'
2022-12-04 22:16:35.622 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000009.K1R8H, B8H - A'
2022-12-04 22:16:35.624 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000007.K1GT12.Haustue'
2022-12-04 22:16:35.634 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000006.K1TR.EG, Watch'
2022-12-04 22:16:35.658 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000005.K1Rollaeden No'
2022-12-04 22:16:35.681 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000009.K1BMI, FK-Piep'
2022-12-04 22:16:35.793 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000013.K1WC.OG'
2022-12-04 22:16:35.823 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000010.K1Rollaeden Su'
2022-12-04 22:16:35.852 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000014.K1KIND.OG'
2022-12-04 22:16:36.103 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000011.K1SZ.OG'
2022-12-04 22:16:36.132 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000015.K1'
2022-12-04 22:16:36.141 [DEBUG] [onnection.ConnectionStateSegmentScan] - No segment couplers detected
2022-12-04 22:16:36.145 [DEBUG] [rnal.connection.AbstractStateMachine] - Changing state ConnectionStateSegmentScan -> ConnectionStateConnected
2022-12-04 22:16:36.147 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000009.SMB
2022-12-04 22:16:36.149 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000007.SMA1
2022-12-04 22:16:36.152 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000008.SMA1
2022-12-04 22:16:36.154 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA1
2022-12-04 22:16:36.156 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2
2022-12-04 22:16:36.254 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000008A1000'
2022-12-04 22:16:36.399 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007A1100'
2022-12-04 22:16:36.402 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000009Bx000'
2022-12-04 22:16:36.452 [TRACE] [g.lcn.internal.connection.Connection] - Received: '=M000012.K1WZ.EG'
2022-12-04 22:16:36.466 [INFO ] [org.openhab.rule.709790dd42         ] - Rule BM Treppe EG/OG | Status BM (Module9sh4ug_Binarsensor4): CLOSED
2022-12-04 22:16:36.470 [INFO ] [org.openhab.rule.709790dd42         ] - Zeit h: 22
2022-12-04 22:16:36.472 [INFO ] [org.openhab.rule.709790dd42         ] - threshold dunkler h: 15, dunkler: 1
2022-12-04 22:16:36.474 [INFO ] [org.openhab.rule.709790dd42         ] - threshold heller h: 7, heller: 0
2022-12-04 22:16:36.476 [INFO ] [org.openhab.rule.709790dd42         ] - bm_lux(alt): 0 lx | bm_beleuchtung_state: 0 lx
2022-12-04 22:16:36.478 [INFO ] [org.openhab.rule.709790dd42         ] - Nachlauf LED 45 s | Status LED 50
2022-12-04 22:16:36.480 [INFO ] [org.openhab.rule.709790dd42         ] - bm_lumi: 0 | myBmLumiOn: 0
2022-12-04 22:16:36.482 [INFO ] [org.openhab.rule.709790dd42         ] - bm_lcn: 1 | myBmLcnOn: 0
2022-12-04 22:16:36.485 [INFO ] [org.openhab.rule.709790dd42         ] - bm_lux neu: 0 lx | Status LED neu 50
2022-12-04 22:16:36.487 [INFO ] [org.openhab.rule.709790dd42         ] - dunkel: true | lux threshold: 20 lx
2022-12-04 22:16:36.639 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012A1100'
2022-12-04 22:16:37.158 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000012.SMA2
2022-12-04 22:16:37.210 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012A2000'
2022-12-04 22:16:41.161 [TRACE] [g.lcn.internal.connection.Connection] - Sent: >M000011.SMA2
2022-12-04 22:16:41.268 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000011A2000'
2022-12-04 22:16:43.616 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx008'
2022-12-04 22:16:43.697 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:51.365 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx008'
2022-12-04 22:16:51.614 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx000'
2022-12-04 22:16:54.191 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:54.313 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx008'
2022-12-04 22:16:54.392 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:55.191 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:16:55.682 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx072'
2022-12-04 22:17:00.749 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx064'
2022-12-04 22:17:02.659 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx000'
2022-12-04 22:17:04.159 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx008'
2022-12-04 22:17:04.208 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:17:05.688 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:17:05.778 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx072'
2022-12-04 22:17:06.611 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000012Bx000'
2022-12-04 22:17:14.155 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx008'
2022-12-04 22:17:16.154 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000007Bx072'
2022-12-04 22:17:16.191 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000015Rx128'
2022-12-04 22:17:25.500 [TRACE] [g.lcn.internal.connection.Connection] - Received: ':M000014Bx000'

No, sorry only LinHK for bus coupling and programming here.

There is a tab ‘status’ in the visualization provided by LinHK showing information of all the bus modules. I think all accessible information, including modules’ comments, are gathered for this.

Best, Jo.

Edit:

Could you give an example of a difference?

Edit 2:

Could there be differences as to the encoding scheme (utf-8, etc.) of the umlauts (depending on the computer system used)?
Linux + Wine for LCN-Pro here.

I don’t think it’s an encoding issue, but you could try to enter the umlauts with different encodings in LCN-PRO, just to be sure.

I’m running out of ideas. Is there a chance that I can connect my OH instance to your LinHK?

I don’t know how/where to change the encoding for the Linux/Wine/LCN-Pro combo — have to find that out…

Yesterday I tried to connect with a new PCK Gateway Thing from OH to LinHK from ‘outside’ my local network and it worked. When do you want to do the test? PM me…
I suppose that you want me to enter/delete the Umlaut from the module comment then?

My setup (LCN with LinHK) is quite similar and I am encountering similar issues, in particular warning messages, eg.

S000M202: Failed to receive measurement value: S000M202 VARIABLE 1: Failed finally after 3 tries

For some reason I haven’t seen these warnings for quite a while - they just disappeared even though I hadn’t changed anything deliberately.

Your notion that it might be related to the LinHK-Visualisierung (which I normally don’t use) triggered me to open it - and immediately the warning messages re-appeared. So I stopped and started the PCK gateway and the messages were gone.

I checked my module comments for umlauts and yes, there were some which I then all removed/replaced (incl. an ß which I changed to ss). However, the warnings re-appeared again so this doesn’t seem to be the root cause.

I contacted the LinHK owner and he said you could open a thread in the LinHK support forum. The LinHK developer will have a look, then.

Hello Fabian,

as suggested I have opened

Thomas,
as you

and seem to have access to the restricted LinHK support forum, could you please have a look at the thread Probleme beim Zusammenspiel LinHK — openHAB?
and possibly comment on your specific case there?

I hope to correctly reproduce the following:
Niko, the LinHK developer, supposes that the Windows-1252 encoded modules’ comments could cause the described hickup in the OH LCN binding, if the latter strictly interprets all incoming characters as UTF-8 encoded.
An umlaut ‘ä’ e.g. is Windows-1252 encoded as ‘0xe4’. With the MSB set, the OH binding interprets this character as the beginning of a UTF-8 multi byte character and runs into trouble if the succeeding character does not have the MSB set as well, thus not correctly continuing/terminating the multi byte character.

LinHK does no conversion of the encoding of the modules’ comments when sending them out to the bus, whereas PCHK seems to have changed it’s behaviour some time in the past (after the coding of LinHK) and apparently does a reencoding to UTF-8.

Furthermore it is pointed out that dynamic texts sent to GT displays might be problematic, even when UTF-8 encoded, if a multi byte character appears at the border of the 12 byte maximum string length.

Probably there are other combinations (apart from umlauts and the sharp s) of originally Windows-1252 encoded characters that lead to unexpected behaviour if interpreted as UTF-8?

I see the same error message still with the latest OH 4.0.2 - annoying polluting the error log with a new line approx. every 40s:

2023-08-22 03:48:41.164 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:49:19.232 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:49:57.278 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:50:35.321 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:51:13.371 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:51:51.414 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

2023-08-22 03:52:29.458 [WARN ] [ding.lcn.internal.connection.ModInfo] - S000M034: Failed to receive status message: LEDs and Logic: Failed finally after 3 tries

I validated whether there are no German special characters (Umlaute and ß) in the configuration of this module.

I am using a LCN-PKE to interface.

Would be great if you could have a look.

This doesn’t seem related. Can you open a new thread and paste a log with trace logging enabled?

OK I opened an issue on GitHub and provided trace level logs