OH 2.3 / KNX2-Binding über knxd an Rpi3 Pigator ROT

[fido]

Hallo,
beim Aufsetzen meiner OpenHAB-Installation mit Anbindung an KNX stoße ich auf ein bisher nicht lösbares Problem:

Hardware: Rpi3 mit Pigator mit KNX-/OneWire-Modul (ROT) -> KNX-Anbindung über serielles Interface/TPUART
Software: Rasbian 9.4, knxd 0.14, OpenHAB 2.3, KNX-Binding 2

Problem: Der KNX-Bus kann mithilfe von knxd über die Kommandozeile des Rpi3 angesprochen werden (knxtools groupswrite), es lässt sich aber keine Kommunikation von KNX-Binding zum KNX-Bus etablieren, weder über KNX Serial Bridge noch über KNX IP Bridge und knxd.
Hier die knxd.conf:

KNXD_OPTS="-e 1.1.182 -E 1.1.183:3 -D -T -R -S -u /tmp/eib -c -b tpuarts:/dev/ttyKNX1"

und die .things-Datei

Bridge knx:ip:bridge [
    ipAddress="224.0.23.12",
    portNumber=3671,
    localIp="192.168.44.182",
    type="ROUTER",
    ignorelocalevents=true,
    readingPause=50,
    responseTimeout=10,
    readRetriesLimit=3,
    autoReconnectPeriod=10,
    localSourceAddr="0.0.0"
    ] {
      Thing knx:device:bridge:generic {
        Type switch:    demoSwitch    "Light"        [ ga="2/1/2" ]
      }

}

Das folgende event.log interpretiere ich so, dass die KNX-IP-Bridge zwar online ist (was bisher nur mit der angegebenen Konfiguration, d.h. nur mit Broadcast-IP-Adresse und nur mit Type "Router" gelang) und der demoSwitch betätigt wurde, aber dennoch die Gruppenadresse nicht auf den KNX-Bus gelangte: es wurde jedenfalls kein Schaltvorgang ausgelöst.

2018-12-12 18:06:41.047 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNKNOWN to OFFLINE
2018-12-12 18:06:41.054 [me.event.ThingUpdatedEvent] - Thing 'knx:ip:bridge' has been updated.
2018-12-12 18:06:41.147 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNKNOWN to ONLINE
2018-12-12 18:06:41.153 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2018-12-12 18:06:59.575 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from ONLINE to UNINITIALIZED
2018-12-12 18:06:59.602 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-12 18:06:59.623 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from ONLINE to UNINITIALIZED
2018-12-12 18:06:59.639 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNINITIALIZED to OFFLINE
2018-12-12 18:06:59.646 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from OFFLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-12 18:07:00.071 [temChannelLinkRemovedEvent] - Link 'demoSwitch => knx:device:bridge:generic:demoSwitch' has been removed.
2018-12-12 18:07:45.394 [.ItemChannelLinkAddedEvent] - Link 'demoSwitch-knx:device:bridge:generic:demoSwitch' has been added.
2018-12-12 18:07:47.682 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNINITIALIZED to INITIALIZING
2018-12-12 18:07:47.726 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from INITIALIZING to UNKNOWN
2018-12-12 18:07:47.838 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from UNINITIALIZED to INITIALIZING
2018-12-12 18:07:47.875 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)
2018-12-12 18:07:48.057 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNKNOWN to ONLINE
2018-12-12 18:07:48.066 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2018-12-12 18:09:37.726 [ome.event.ItemCommandEvent] - Item 'demoSwitch' received command ON
2018-12-12 18:09:37.771 [vent.ItemStateChangedEvent] - demoSwitch changed from NULL to ON
2018-12-12 18:09:39.905 [ome.event.ItemCommandEvent] - Item 'demoSwitch' received command OFF
2018-12-12 18:09:39.919 [vent.ItemStateChangedEvent] - demoSwitch changed from ON to OFF

Interessant ist allerdings, dass, wenn ich anschließend den Schaltvorgang über die Kommandozeile des Rpi3 (knxtools groupswrite) tatsächlich auslöse, sich dies im event.log abbildet:

2018-12-12 18:10:36.284 [vent.ItemStateChangedEvent] - demoSwitch changed from OFF to ON
2018-12-12 18:10:48.054 [vent.ItemStateChangedEvent] - demoSwitch changed from ON to OFF

Dies bedeutet offenbar, dass die Kommunikation in Gegenrichtung, also von knxd zum KNX-Binding funktioniert.
Kann jemand weiterhelfen, wie knxd.conf und .things-Datei angelegt sein müssen, damit auch OpenHAB auf den KNX-Bus zugreifen kann? Geht das im vorliegenden Fall evtl. doch über die KNX-Serial-Bridge oder mit einer anderen Konfiguration der KNX-IP-Bridge mit Type "Tunnel"?

[udo1toni]

Der Thing-Teil ist falsch, es müsste eigentlich so aussehen:

 {
      Thing device generic []
      {
        Type switch:    demoSwitch    "Light"        [ ga="2/1/2" ]
      }
}

[fido]

Hallo udi1toni,

danke für den Hinweis, ich habe es gleich umgesetzt und bekomme im event.log jetzt keinen Handler_Missing_Error mehr:

2018-12-15 18:36:34.383 [.ItemChannelLinkAddedEvent] - Link 'demoSwitch-knx:device:bridge:generic:demoSwitch' has been added.
2018-12-15 18:36:37.933 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNINITIALIZED to INITIALIZING
2018-12-15 18:36:38.038 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from INITIALIZING to UNKNOWN
2018-12-15 18:36:38.211 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from UNINITIALIZED to INITIALIZING
2018-12-15 18:36:38.274 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)
2018-12-15 18:36:38.717 [hingStatusInfoChangedEvent] - 'knx:ip:bridge' changed from UNKNOWN to ONLINE
2018-12-15 18:36:38.750 [hingStatusInfoChangedEvent] - 'knx:device:bridge:generic' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2018-12-15 18:38:27.352 [ome.event.ItemCommandEvent] - Item 'demoSwitch' received command ON
2018-12-15 18:38:27.385 [vent.ItemStateChangedEvent] - demoSwitch changed from NULL to ON
2018-12-15 18:38:30.432 [ome.event.ItemCommandEvent] - Item 'demoSwitch' received command OFF
2018-12-15 18:38:30.444 [vent.ItemStateChangedEvent] - demoSwitch changed from ON to OFF

aber über OpenHAB lässt sich dennoch kein KNX-Schaltvorgang auslösen, obwohl dieser im Log erscheint.

[udo1toni]

Was passiert denn, wenn Du den Aktor auf knx-Seite schaltest?
Du kannst das Logging für knx erweitern, um mehr zu sehen zu bekommen, dazu loggst Du Dich auf dem Raspberry ein und führst dort

openhab-cli console

aus. Wahlweise kannst Du auch

ssh openhab@localhost -p8101

eingeben, wobei das default Paswort habopen ist.
Nun befindest Du Dich auf der Karaf Konsole. Dort kannst Du den Log Level für jedes Bundle getrennt setzen:

log:set DEBUG org.openhab.binding.knx

log:list

Der zweite Befehl zeigt Dir die Liste aller speziell gesetzten log Level.
Da Du Dich schon auf den Konsosle befindest, kannst Du nun einfach mit

bundle:restart org.openhab.binding.knx

das knx Binding neu starten und anschließend mit

log:tail

schauen, was knx da so ausspuckt. Das Log kannst Du aber natürlich auch ganz ohne karaf Konsole entweder über frontail oder auch direkt in der entsprechenden Datei unter /var/log/openhab2/openhab.log anschauen.
Die Karaf Konsole kannst du bequem mit

logout

wieder verlassen. Den normalen log Level für knx bekommst Du auf gleichem Weg mit

log:set DEFAULT org.openhab.binding.knx

zurück. Ein Neustart des Bindings ist übrigens nicht nötig, das ist nur sinnvoll, um gleich das gesamte Startverhalten in der datei zu haben, ohne erst umständlich openHAB neu zu starten. Einmal gesetzte Log Level bleiben solange erhalten, bis man sie wieder anders setzt oder die entsprechende Datei z.B. durch ein Update verändert wird, sie überleben also auch einen Neustart des Systems.

[fido]

Hallo udi1toni,

nach Aktivierung des Debugging für das KNX-Binding findet sich im openhab.log und Restart des Bindings

2018-12-16 00:09:19.548 [DEBUG] [org.openhab.binding.knx             ] - BundleEvent STARTED - org.openhab.binding.knx
2018-12-16 00:09:19.647 [DEBUG] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge is disconnecting from the KNX bus
2018-12-16 00:09:19.650 [DEBUG] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge is connecting to the KNX bus
2018-12-16 00:09:19.651 [DEBUG] [binding.knx.internal.client.IPClient] - Establishing connection to KNX bus on 224.0.23.12:3671 in mode ROUTER.

und nach erfolgreichen Schalten des Aktors (Ein und Aus) über den dafür programmierten Tastsensor

2018-12-16 00:11:14.456 [DEBUG] [.internal.handler.DeviceThingHandler] - Thing 'knx:device:bridge:generic' received a Group Write telegram from '1.1.100' for destination '2/1/2'
2018-12-16 00:11:21.497 [DEBUG] [.internal.handler.DeviceThingHandler] - Thing 'knx:device:bridge:generic' received a Group Write telegram from '1.1.100' for destination '2/1/2'

bzw. nach erfolgreichem Schalten des Aktors (Ein und Aus) über die Raspberry-Kommandozeile (knxtool groupswrite ...)

2018-12-16 00:12:46.419 [DEBUG] [.internal.handler.DeviceThingHandler] - Thing 'knx:device:bridge:generic' received a Group Write telegram from '1.1.183' for destination '2/1/2'
2018-12-16 00:12:57.899 [DEBUG] [.internal.handler.DeviceThingHandler] - Thing 'knx:device:bridge:generic' received a Group Write telegram from '1.1.184' for destination '2/1/2'

und nach Betätigung des entsprechenden OpenHAB-Switchs (ohne Effekt auf den Aktor)

2018-12-16 00:14:45.017 [DEBUG] [nx.internal.client.AbstractKNXClient] - Wrote value 'ON' to datapoint 'command DP 2/1/2 'knx:ip:bridge', DPT id 1.001, low priority' (0. attempt).
2018-12-16 00:14:53.118 [DEBUG] [nx.internal.client.AbstractKNXClient] - Wrote value 'OFF' to datapoint 'command DP 2/1/2 'knx:ip:bridge', DPT id 1.001, low priority' (0. attempt).

Offenbar kann OpenHAB also vom KNX-Bus über knxd lesen, aber nicht auf diesen schreiben.

[fido]

Problem gelöst, es war offensichtlich die falsch gesetzte localSourceAddr im Tunnel-Modus (.things-Datei), diese muss bei 0.0.0 bleiben!