I’m not sure how far back this goes in my binding usage but I after some item changes I noticed in the logs that the binding was repeatedly showing a state update of disconnected.
The debug says unable to make API connection, also shows a null item is being sent and shows a command with empty strings “” “” “” passed.
I would assume this is not normal behavior
Here is some of what I see in the DEBUG:
2015-09-27 12:36:19.138 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API reconnection failed!
2015-09-27 12:36:24.139 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - DSC Alarm Execute
2015-09-27 12:36:24.140 [DEBUG] [dscalarm.internal.protocol.API] - close(): Disconnecting from API Connection!
2015-09-27 12:36:24.141 [DEBUG] [o.b.d.i.connector.TCPConnector] - close(): Closed TCP Connection!
2015-09-27 12:36:24.141 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.141 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.141 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.141 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.141 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - closeConnection(): TCP Connection Closed!
2015-09-27 12:36:24.141 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - execute(): Not Connected to the DSC Alarm!
2015-09-27 12:36:24.141 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API Reconnection!
2015-09-27 12:36:24.143 [DEBUG] [dscalarm.internal.protocol.API] - sendCommand(): ‘NetworkLogin’ Command Sent - 005user54
2015-09-27 12:36:24.143 [DEBUG] [dscalarm.internal.protocol.API] - open(): Connected = true, Connection Type: TCP
2015-09-27 12:36:24.143 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.143 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.143 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.143 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:24.145 [ERROR] [o.b.d.i.connector.TCPConnector] - read(): IO Exception:
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:196) ~[na:1.7.0_79]
at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) ~[na:1.7.0_79]
at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[na:1.7.0_79]
at java.io.BufferedReader.fill(BufferedReader.java:154) ~[na:1.7.0_79]
at java.io.BufferedReader.readLine(BufferedReader.java:317) ~[na:1.7.0_79]
at java.io.BufferedReader.readLine(BufferedReader.java:382) ~[na:1.7.0_79]
at org.openhab.binding.dscalarm.internal.connector.TCPConnector.read(TCPConnector.java:89) ~[bundlefile:na]
at org.openhab.binding.dscalarm.internal.connector.TCPConnector$TCPListener.run(TCPConnector.java:231) [bundlefile:na]
2015-09-27 12:36:24.146 [DEBUG] [o.b.d.i.connector.TCPConnector] - handleIncomingMessage(): Message recieved: - Code: “”, Name: “”, Description: “”
2015-09-27 12:36:24.146 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_MESSAGE
2015-09-27 12:36:24.146 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_MESSAGE
2015-09-27 12:36:24.146 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - setTimeStampState(): Time Stamp:
2015-09-27 12:36:24.146 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_TIME_STAMP
2015-09-27 12:36:24.147 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - setTimeStampState(): Already Set!
2015-09-27 12:36:24.147 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - dscAlarmEventRecieved(): Event received! Looking for item: null
2015-09-27 12:36:29.144 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - DSC Alarm Execute
2015-09-27 12:36:29.145 [DEBUG] [dscalarm.internal.protocol.API] - close(): Disconnecting from API Connection!
2015-09-27 12:36:29.151 [DEBUG] [o.b.d.i.connector.TCPConnector] - close(): Closed TCP Connection!
2015-09-27 12:36:29.153 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:29.155 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_CONNECTION
2015-09-27 12:36:29.156 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:29.159 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_CONNECTION
2015-09-27 12:36:29.167 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - closeConnection(): TCP Connection Closed!
2015-09-27 12:36:29.168 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - execute(): Not Connected to the DSC Alarm!
2015-09-27 12:36:29.169 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API Reconnection!
2015-09-27 12:36:29.175 [ERROR] [o.b.d.i.connector.TCPConnector] - write(): {}
java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118) ~[na:1.7.0_79]
at java.net.SocketOutputStream.write(SocketOutputStream.java:159) ~[na:1.7.0_79]
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) ~[na:1.7.0_79]
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291) ~[na:1.7.0_79]
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295) ~[na:1.7.0_79]
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141) ~[na:1.7.0_79]
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229) ~[na:1.7.0_79]
at org.openhab.binding.dscalarm.internal.connector.TCPConnector.write(TCPConnector.java:72) ~[bundlefile:na]
at org.openhab.binding.dscalarm.internal.protocol.API.sendCommand(API.java:397) [bundlefile:na]
at org.openhab.binding.dscalarm.internal.protocol.API.open(API.java:204) [bundlefile:na]
at org.openhab.binding.dscalarm.internal.DSCAlarmActiveBinding.openConnection(DSCAlarmActiveBinding.java:531) [bundlefile:na]
at org.openhab.binding.dscalarm.internal.DSCAlarmActiveBinding.reconnect(DSCAlarmActiveBinding.java:545) [bundlefile:na]
at org.openhab.binding.dscalarm.internal.DSCAlarmActiveBinding.execute(DSCAlarmActiveBinding.java:139) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-09-27 12:36:29.177 [ERROR] [o.b.d.i.connector.TCPConnector] - read(): IO Exception:
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:196) ~[na:1.7.0_79]
at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) ~[na:1.7.0_79]
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) ~[na:1.7.0_79]
at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[na:1.7.0_79]
at java.io.BufferedReader.fill(BufferedReader.java:154) ~[na:1.7.0_79]
at java.io.BufferedReader.readLine(BufferedReader.java:317) ~[na:1.7.0_79]
at java.io.BufferedReader.readLine(BufferedReader.java:382) ~[na:1.7.0_79]
at org.openhab.binding.dscalarm.internal.connector.TCPConnector.read(TCPConnector.java:89) ~[bundlefile:na]
at org.openhab.binding.dscalarm.internal.connector.TCPConnector$TCPListener.run(TCPConnector.java:231) [bundlefile:na]
2015-09-27 12:36:29.189 [DEBUG] [dscalarm.internal.protocol.API] - sendCommand(): ‘NetworkLogin’ Command Sent - 005user54
2015-09-27 12:36:29.190 [ERROR] [dscalarm.internal.protocol.API] - open(): Unable to Make API Connection!
2015-09-27 12:36:29.191 [DEBUG] [dscalarm.internal.protocol.API] - open(): Connected = false, Connection Type: TCP
2015-09-27 12:36:29.193 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_MESSAGE
2015-09-27 12:36:29.196 [DEBUG] [o.b.d.i.connector.TCPConnector] - handleIncomingMessage(): Message recieved: - Code: “”, Name: “”, Description: “”
2015-09-27 12:36:29.207 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_MESSAGE
2015-09-27 12:36:29.209 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_MESSAGE
2015-09-27 12:36:29.210 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_MESSAGE
2015-09-27 12:36:29.215 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API reconnection failed!
2015-09-27 12:36:29.216 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: ZONE3_IN_ALARM
I’m also seeing this where there is a network command sent “005user54” I do not know where that came from, but I think it might be possible that I erroneously programmed a section when trying to enable the output on the DSC system through the keypad:
at org.openhab.binding.dscalarm.internal.connector.TCPConnector$TCPListener.run(TCPConnector.java:231) [bundlefile:na]
2015-09-29 15:15:45.138 [DEBUG] [dscalarm.internal.protocol.API] - sendCommand(): ‘NetworkLogin’ Command Sent - 005user54
2015-09-29 15:15:45.141 [DEBUG] [o.b.d.i.connector.TCPConnector] - handleIncomingMessage(): Message recieved: - Code: “”, Name: “”, Description: “”
2015-09-29 15:15:45.142 [ERROR] [dscalarm.internal.protocol.API] - open(): Unable to Make API Connection!
2015-09-29 15:15:45.143 [DEBUG] [dscalarm.internal.protocol.API] - open(): Connected = false, Connection Type: TCP
2015-09-29 15:15:45.152 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_MESSAGE
2015-09-29 15:15:45.152 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_MESSAGE
2015-09-29 15:15:45.153 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_MESSAGE
2015-09-29 15:15:45.154 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_MESSAGE
2015-09-29 15:15:45.154 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API reconnection failed!
2015-09-29 15:15:47.388 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - DSC Alarm Execute
2015-09-29 15:15:50.156 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - DSC Alarm Execute
2015-09-29 15:15:50.156 [DEBUG] [dscalarm.internal.protocol.API] - close(): Disconnecting from API Connection!
2015-09-29 15:15:50.158 [DEBUG] [o.b.d.i.connector.TCPConnector] - close(): Closed TCP Connection!
2015-09-29 15:15:50.159 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceItem(): Item Name: PANEL_CONNECTION
2015-09-29 15:15:50.160 [DEBUG] [.d.internal.DSCAlarmItemUpdate] - updateDeviceProperties(): Item Name: PANEL_CONNECTION
2015-09-29 15:15:50.160 [DEBUG] [.dscalarm.internal.model.Panel] - updateProperties(): Panel Item Name: PANEL_CONNECTION
2015-09-29 15:15:50.161 [DEBUG] [.dscalarm.internal.model.Panel] - refreshItem(): Panel Item Name: PANEL_CONNECTION
2015-09-29 15:15:50.161 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - closeConnection(): TCP Connection Closed!
2015-09-29 15:15:50.162 [ERROR] [.o.b.d.i.DSCAlarmActiveBinding] - execute(): Not Connected to the DSC Alarm!
2015-09-29 15:15:50.162 [DEBUG] [.o.b.d.i.DSCAlarmActiveBinding] - reconnect(): API Reconnection!
2015-09-29 15:15:50.221 [ERROR] [o.b.d.i.connector.TCPConnector] - write(): {}
java.net.SocketException: Connection reset
Any ideas would be appreciated. The strange thing is, the commands still seem to be passed to the DSC system and I get responses and messages back so it must be connecting and disconnecting so quickly that I do not notice through the web interface other than occasional statuses.