Missing telegrams in IP KNX tunnel about knx-go

[farmio]

Hi 👋!
Just stumbled over this issue. I implemented TCP tunneling for xknx this winter. Main differences to UDP are:

• no TunnellingACK needed
• IP and Port in HPAI shall be set to all 0, protocol to IPv4_TCP
• Sequence counter shall be ignored (for xknx we still count up because I like it in tcpdumps)

Possible test devices are all Secure enabled interfaces (Secure Tunneling is TCP only) and some non-secure Gira devices (X1, I12 Router with firmware update). MDT and Weinzierl non-secure are V1 only afaik.

Other than that you can use the wonderful Calimero project for testing. https://github.com/calimero-project/calimero-server

To get the official specifications application note you would have to file a ticket to KNXA as this in not yet publicly released. (They said they are close to releasing a new version of the specs about 1,5 years ago 🤷).

If you have any questions about TCP or Secure Tunneling feel free ask (eg. on our xknx discord)!

[alexander-zimmermann]

FYI: influxdata/telegraf#11759

[alexander-zimmermann]

A bit busy the next days. Will come back w/ the result from telegraf asap

[mobilarte]

Hi Alexander,

Have you tried to write a small go program that just logs raw messages?

Are you sure you would see the log messages on line 134 (of telegraf) if GA were wrongly configured?

[alexander-zimmermann]

Hey @mobilarte,

no since I'm not a GO ninja, I was a bit lazy and used xknx to dump raw data on the IP wire. But sure, I can use knx-go to dump. Do you have a pointer somewhere I can take look. Otherwise I will start from scratch.

Yes, I'm sure. Either telegraf wrote to log if the GA is configured (if you run it in debug mode) or report unknown GA.

But I scan the screenshot about again, and found a better "proof" of the issue. For example GA 7/2/64 was seen by xknx, but not by telegraf, even it was configure in my config.

...
389   [[inputs.KNXListener.measurement]]
390     name = "Sensorik.EG.Büro.Sensor.Luftfeuchte"
391     dpt = "9.007"
392     addresses = ["7/2/64"]
393 

[alexander-zimmermann]

Not really a proof, but also on the Grafana side I saw that a loose data. For example I configure the KNX sensors to flush the temperature every 60 sec. Running the monitor in ETS and xknx I see the telegrams, but not influxdb2 anymore. Take a look how unfrequent I receive the data in the DB

I'm pretty sure if I clear the whole telegarf config and only dump some temperature values (2, 3 GAs), I don't have any gaps anymore

[vapourismo]

If you're using a KNXnet/IP router, can you ensure that there aren't multiple processes on the receiving machine interfering with the multicast group subscription?

There were a few changes on regarding how multicast sockets are bound. I suspect that there might be an issue there, given misbound sockets usually exhibit this kind of "lossy" behaviour.

[alexander-zimmermann]

I run telegraf with a UDP tunnel:

   1 # Listener capable of handling KNX bus messages provided through a KNX-IP Interface.
   2 [[inputs.KNXListener]]
   3   ## Type of KNX-IP interface.
   4   ## Can be either "tunnel" or "router".
   5   service_type = "tunnel"
   6 
   7   ## Address of the KNX-IP interface.
   8   service_address = "192.168.1.173:3671"

However, it runs in a docker container (the official one from telegraf). If you believe if it make sense I can run a test outside from docker w/ telegraf on the host

[vapourismo]

Ok, given you're using a tunnel my theory is off.

Can you try the example on the README? If you modify it to not send anything and just keep the for loop to print incoming messages, you could see if knx-go actually doesn't receive them.

[alexander-zimmermann]

Sure. Good opportunity to improve my rusty GO knowledge ;-)

[alexander-zimmermann]

Hmm, still strange or even stranger.

Left hand side knx-go example on OS Macbook, right hand side telegraf on docker on linux vm.

knx-go receive now more data (good, so it seems that telegraf has a problem, and not knx-go), but why I receive the GA 7/5/53 w/ telegraf and not with the knx-go example???

In theory I could be the case that we have congestion and packet loss UDP, but I doubt on that. No clue so far.

Let me recompile the example on the linux vm/host. I will then run then knx-go and xknx from the vm/host and telegraf from the container.

[alexander-zimmermann]

On the linux vm, I've now a different problem. I loose the connection. The example code is exactly the same.

alexander@ubuntu:~/development/go/src/knx-test$ ./knx-test 
2022/08/17 21:28:10 *net.UDPConn[0xc000010038]: Started worker
2022/08/17 21:28:10 <-chan cemi.Message[0xc00001c1e0]: Started worker
2022/08/17 21:28:10         *knx.Tunnel[0xc000094080]: Started worker
2022/08/17 21:28:11 {Command:Write Source:1.2.131 Destination:7/3/41 Data:[0 45 51]}: 11571 mA
2022/08/17 21:28:13         *knx.Tunnel[0xc000094080]: Server terminated with error: gateway terminated the connection
2022/08/17 21:28:13         *knx.Tunnel[0xc000094080]: Attempting reconnect
2022/08/17 21:28:13         *knx.Tunnel[0xc000094080]: Reconnect succeeded
2022/08/17 21:28:14 {Command:Write Source:1.2.91 Destination:7/2/97 Data:[0 5 211]}: 1491 mA
2022/08/17 21:28:16         *knx.Tunnel[0xc000094080]: Server terminated with error: gateway terminated the connection
2022/08/17 21:28:16         *knx.Tunnel[0xc000094080]: Attempting reconnect
2022/08/17 21:28:16         *knx.Tunnel[0xc000094080]: Reconnect succeeded
2022/08/17 21:28:16 {Command:Write Source:1.2.151 Destination:7/3/91 Data:[0 13 3]}: 3331 mA
2022/08/17 21:28:18         *knx.Tunnel[0xc000094080]: Server terminated with error: gateway terminated the connection
2022/08/17 21:28:18         *knx.Tunnel[0xc000094080]: Attempting reconnect
2022/08/17 21:28:18         *knx.Tunnel[0xc000094080]: Reconnect succeeded
2022/08/17 21:28:20         *knx.Tunnel[0xc000094080]: Server terminated with error: gateway terminated the connection
2022/08/17 21:28:20         *knx.Tunnel[0xc000094080]: Attempting reconnect
2022/08/17 21:28:20         *knx.Tunnel[0xc000094080]: Reconnect succeeded
^C
alexander@ubuntu:~/development/go/src/knx-test$ 

[vapourismo]

Is the problem specific to the VM? Does it succeed elsewhere? If so, does xknx also have a problem in the VM?

[alexander-zimmermann]

@vapourismo no, it only occurs on the Ubuntu VM. Same code on Mac OSX laptop works. xknx on the Ubuntu VM doesn't have the problem. However, xknx establish a TCP connection, not a UDP one. I will test it on other devices today as well. BTW should I open another issue on connection problems since it's much likely not related to the original discussion

[vapourismo]

I am still not sure what is actually wrong given the lack of comparable data.

Given only the VM causes problem, I would like some evidence that knx-go is actually throwing away packets. If that's not the case, it isn't doing anything wrong.
Can you produce a packet capture on the VM with Wireshark?

We can look into implementing TCP tunnelling separately. No need to create another issue. However, I have nothing to test this with - I would need your help with that.

[alexander-zimmermann]

Sure. Let me run some more test today with different OSes. Will come back with the results. I'm also in touch w/ xknx author. AFAIK we can force xknx to use UDP so that we have more comparable data.

[alexander-zimmermann]

OK, together w/ the guys from xknx I was able to find the issue why we loose the connectivity. Hyper-v is currently broken.

I will revert the KB on the windows server and retest the stuff.

Anyway, if you would like to implement TCP connectivity as well, I willing to help.

[vapourismo]

I think I have some time to look at the TCP tunnelling stuff over the weekend. Will report if I got something then.

[vapourismo]

@alexander-zimmermann I've had a stab at the Tunnelling V2 aka TCP Tunnelling. I didn't find many useful resources on it. However, it looks like it is the same protocol for UDP but via TCP.

Changes are in here: https://github.com/vapourismo/knx-go/tree/feature/tunneling-v2

The TunnelConfig has a UseTCP option now, which if set to true will use the TCP tunnel.

I'd be delighted if you could try this out and report back.

[alexander-zimmermann]

@vapourismo the TCP connection itself works, but I don't see nearly no telegram output on the cmd.
Used test code.

I've the feeling that for loop doesn't work as expected. After one output, we see don't see any further output. However, on the wire (tcpdump), we still see traffic.

[vapourismo]

Thanks! Can you send me that packet dump? Also, could you capture a packet dump for xknx on the same machine?

[alexander-zimmermann]

SRC: 192.168.1.10, Ubuntu on Win hyper-v
DST: 192.168.1.173, MDT KNX Gateway

https://github.com/alexander-zimmermann/tcpdump

[vapourismo]

These are super useful! It looks like it is almost working, there is an issue with sequence numbers and acknowledgements. I hope this is now fixed with the latest changes pushed to the feature/tunneling-v2 branch.

[mobilarte]

No acknowledgements in xknx.cap to Tunnel Req, that is on channel #10. Normally the MDT SCN-IP000.03 should send a disconnect if its packets are not acknowledged. On channel #11 (knx-go) all TunnelReqs are followed by TunnelAcks.

[vapourismo]

I think that is correct, given the transport protocol (TCP) takes care of acknowledgements.

[vapourismo]

Note the sequence numbers within the tunnel requests. It is always 0, which makes sense in the context of TCP where it is an ordered stream of bytes, rather than unordered packets as is the case in UDP.

[mobilarte]

But the MDT seems to be ok with receiving TunnelAcks and I could not find any reference to the expected behavior in the KNX Standard (maybe in the newest, but not out yet!), TCP being optional.

[vapourismo]

Same here, haven't found much useful in the official docs about this.

As for the MDT, I'd imagine it just throws away the Tunnel Response frames entirely. knx-go can save some bandwidth not producing these at all.

[mobilarte]

I don't have a device with TCP capabilities yet, but maybe someone with an ABB/Weinzierl device could test this (or anything that does not have the same codebase as MDT).

[alexander-zimmermann]

Looks better now. Let me recompile telegraf w/ this version. Will comeback...

alexander@ubuntu:~/development/go/src/knx-test$ ./knx-test 
2022/08/20 15:30:07 *net.TCPConn[0xc000010038]: Started worker
2022/08/20 15:30:07 <-chan cemi.Message[0xc00001c1e0]: Started worker
2022/08/20 15:30:07         *knx.Tunnel[0xc000094080]: Started worker
2022/08/20 15:30:07 {Command:Write Source:1.2.131 Destination:7/3/31 Data:[0 12 190]}: 3262 mA
2022/08/20 15:30:07 Unpack fails: given application data has invalid length
2022/08/20 15:30:07 {Command:Write Source:1.2.141 Destination:7/3/71 Data:[0 45 48]}: 11568 mA
2022/08/20 15:30:07 Unpack fails: given application data has invalid length
2022/08/20 15:30:07 {Command:Write Source:1.2.66 Destination:8/2/25 Data:[0 52 121]}: 13433 mA
2022/08/20 15:30:08 Unpack fails: given application data has invalid length
2022/08/20 15:30:08 Unpack fails: given application data has invalid length
2022/08/20 15:30:09 Unpack fails: given application data has invalid length
2022/08/20 15:30:10 Unpack fails: given application data has invalid length
2022/08/20 15:30:10 {Command:Write Source:1.2.26 Destination:8/1/65 Data:[0 22 89]}: 5721 mA
2022/08/20 15:30:11 {Command:Write Source:1.2.42 Destination:9/1/90 Data:[0 21 170]}: 5546 mA
2022/08/20 15:30:11 Unpack fails: given application data has invalid length
2022/08/20 15:30:11 {Command:Write Source:1.2.71 Destination:7/2/41 Data:[0 47 108]}: 12140 mA
2022/08/20 15:30:12 Unpack fails: given application data has invalid length
2022/08/20 15:30:12 Unpack fails: given application data has invalid length
2022/08/20 15:30:12 {Command:Write Source:1.2.131 Destination:7/3/41 Data:[0 45 70]}: 11590 mA
2022/08/20 15:30:14 Unpack fails: given application data has invalid length
2022/08/20 15:30:14 Unpack fails: given application data has invalid length
2022/08/20 15:30:14 {Command:Write Source:1.2.191 Destination:7/3/221 Data:[0 47 223]}: 12255 mA
2022/08/20 15:30:15 Unpack fails: given application data has invalid length
2022/08/20 15:30:15 Unpack fails: given application data has invalid length
2022/08/20 15:30:15 Unpack fails: given application data has invalid length
2022/08/20 15:30:15 Unpack fails: given application data has invalid length

[vapourismo]

I think the "Unpack fails: given application data has invalid length" messages are fine. They appear because all packets are treated as 7.012 in your example.

[alexander-zimmermann]

Hey folks, I recompile telegraf master w/ the knx-go tcp feature branch. I forced telegraf to use the tcp connection. AFAIKS it looks good.

@vapourismo what are your plans for next steps? More testing w/ other KNX GWs or push your code already to master?

[vapourismo]

Great to see it works.

I will give this another pass next weekend to gain more confidence. However, I think it is fine to merge it given it is not enabled by default.

[vapourismo]

Awesome! Thanks @farmio.

[vapourismo]

Merged TCP support in 66b7fc5.

[alexander-zimmermann]

FYI 2: influxdata/telegraf#11783. Feature will be available with upcoming telegraf version 1.25