iAnish / openhab

Automatically exported from code.google.com/p/openhab
GNU General Public License v3.0
0 stars 0 forks source link

TCP Binding "there is no active channel" #146

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
I have a Java TCP Socket server running on my local pc.

I've added the example code from the OpenHAB wiki 
Switch Light_OnOff "Alarmbeleuchtung"   (Garden)    { 
tcp=">[ON:127.0.0.1:3000:cmd_on], >[OFF:127.0.0.1:3000:cmd_off]" }

I get the error message
14:08:18.679 ERROR o.o.b.t.AbstractChannelEventSubscriberBinding[:1047] - there 
is no active channel for [itemName=Light_OnOff, command=ON]
When the switch is enabled/disabled

Socketserver recognizes the client connection but doesn't get a message

I've tried it with:
OpenHab runtime 1.0.0
TCP Binding 1.1.0
and also with
OpenHab runtime 1.1.0
TCP Binding 1.1.0

(There's no tcp binding in my addon-1.0.0 download file)

@WinXP 32Bit

Original issue reported on code.google.com by quellt...@gmail.com on 15 Nov 2012 at 1:18

GoogleCodeExporter commented 9 years ago

Original comment by kai.openhab on 15 Nov 2012 at 1:20

GoogleCodeExporter commented 9 years ago
Sorry for the late answer - I do not actively read the mailbox 
karel.goderis@gmail.com

I have tried to replicate the problem. I have the following configuration 
set-up ( based on latest repo):

demo.items:
Switch Light_OnOff "Alarmbeleuchtung"   (Garden)    { 
tcp=">[ON:127.0.0.1:3000:cmd_on], >[OFF:127.0.0.1:3000:cmd_off]" }

demo.rules:
rule "Crontest"
    when 
        Time cron "0/5 * * * * ?"
    then
        sendCommand(Light_OnOff, OFF)
end

In a terminal window I execute the following command, to listen to TCP port 
3000:
nc -l 3000

Then I do a debug run and this is what I get in the OH logs: (I removed the 
non-relevant lines)
osgi> 00:20:23.552 DEBUG o.o.b.t.internal.TCPActivator[:51] - TCP/UDP binding 
has been started.
00:20:24.649 DEBUG o.o.b.t.AbstractChannelEventSubscriberBinding[:509] - 
TCPBinding Selector Thread has been started
00:20:24.651 DEBUG o.o.b.t.AbstractChannelEventSubscriberBinding[:265] - 
TCPBinding Parser Thread has been started
00:20:24.654 DEBUG o.o.b.t.AbstractChannelEventSubscriberBinding[:190] - 
TCPBinding Reconnect Thread has been started
00:20:24.662 DEBUG o.o.b.t.AbstractChannelEventSubscriberBinding[:265] - 
UDPBinding Parser Thread has been started
00:20:24.663 DEBUG o.o.b.t.AbstractChannelEventSubscriberBinding[:509] - 
UDPBinding Selector Thread has been started
00:20:40.004 DEBUG o.o.m.r.i.e.ExecuteRuleJob[:73] - Executing scheduled rule 
'Crontest'
00:20:40.011 INFO  runtime.busevents[:42] - Light_OnOff received command OFF
00:20:40.013 INFO  runtime.busevents[:46] - Light_OnOff state updated to OFF
00:20:45.004 DEBUG o.o.m.r.i.e.ExecuteRuleJob[:73] - Executing scheduled rule 
'Crontest'
00:20:45.010 INFO  runtime.busevents[:42] - Light_OnOff received command OFF
00:20:45.011 INFO  runtime.busevents[:46] - Light_OnOff state updated to OFF

In the terminal window, where I have the "server" running, I have the following 
output:
Karel-Goderis-MacBook-Air:~ kgoderis$ nc -l 3000
cmd_off
cmd_off

At first sight I can not replicate your problem. Can you try the same as me and 
tell if you have a different output?

Karel

Original comment by karel.go...@pharco.be on 5 Dec 2012 at 12:00

GoogleCodeExporter commented 9 years ago
Please reopen the issue in case the problem still exists.

Original comment by kai.openhab on 5 Jan 2013 at 10:13

GoogleCodeExporter commented 9 years ago
I have managed to reproduce this on Win 8 x64. It's a string parsing issue, in 
the binding if you have "ON:" you get the error with "on:" it works. I haven't 
fully tested yet but the error does not appear in the log.

Ian

Original comment by ianlinda...@gmail.com on 13 Feb 2013 at 9:15

GoogleCodeExporter commented 9 years ago
Hi Ian

I need to verify this, and also, verify if this problem exists with other 
bindings. From my distant recollection, I think I have never implemented code 
to format the incoming strings and so on to UPPER or lower case. Keep me posted 
with diagnosis...

Original comment by karel.go...@pharco.be on 13 Feb 2013 at 9:43

GoogleCodeExporter commented 9 years ago
I'm having problems with the error as I can get it to mostly not work in either 
case. It seems to be related specifically to the TCP binding... However, the 
good news I build a snapshot from a couple of weeks ago and it seems to work 
there... so whatever has changed seems to have fixed the bug. 

I was wondering if it was something to do with the order in which bindings are 
initialized? As very rarely the Plugwise binding seems to die at startup 
because some other components aren't running. If I still have the logs I'll 
post them as a separate issue. 

Original comment by ianlinda...@gmail.com on 13 Feb 2013 at 8:54

GoogleCodeExporter commented 9 years ago
Hi

A month or two ago I refactored the whole tcp binding to use Quartz
threads amongst other things.

You could try in increase the logging level a bit (debug mode) so that
we can investigate ?

The TCP device you are connecting to is behaving "correctly"? Is not
dropping connections rapidly, or it responds fast to connection
attempts.

"No active channel" is most likely due to openhab sending a value to
the remote end (you switch ON), but the underlying TCP connection is
not connected (yet)/(anymore)

K

Original comment by karel.go...@pharco.be on 14 Feb 2013 at 7:10