search

tcatm / l3roamd

12 stars 4 forks source link

obtaining IP-addresss when igmp_snooping=1 may take up to 5 minutes #30

Open christf opened 7 years ago

christf commented 7 years ago

I was able to capture this log. A new client (00:18:de:24:c6:7c) appears but it does not receive an IP address. In the same configuration in another connection attempt everything works.

What needs fixing?

Sun Nov 27 18:54:38 2016 daemon.info l3roamd[871]: client0: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:54:38 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (865.217705780) Sun Nov 27 18:54:38 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:54:38 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:54:38 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: event 19 Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: client0: new station 00:18:de:24:c6:7c Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: new client 00:18:de:24:c6:7c on br-client Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: client0: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:54:39 2016 daemon.info hostapd: client0: STA 00:18:de:24:c6:7c IEEE 802.11: authenticated Sun Nov 27 18:54:39 2016 daemon.info hostapd: client0: STA 00:18:de:24:c6:7c IEEE 802.11: associated (aid 1) Sun Nov 27 18:54:39 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:54:39 2016 kern.warn kernel: [ 871.040000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:54:41 2016 daemon.info fastd[1597]: resolving host gw02.babel.ffm.freifunk.net' for peer <mesh_vpn_backbone_peer_fastd2>... Sun Nov 27 18:54:41 2016 daemon.info fastd[1597]: resolving hostgw02.babel.ffm.freifunk.net' failed: Name or service not known Sun Nov 27 18:54:42 2016 kern.warn kernel: [ 873.550000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:54:43 2016 daemon.info l3roamd[871]: client0: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:54:43 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (870.218194250) Sun Nov 27 18:54:43 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:54:43 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:54:43 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:54:44 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:54:48 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:54:48 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (875.218978220) Sun Nov 27 18:54:48 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:54:48 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:54:48 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:54:48 2016 kern.warn kernel: [ 880.240000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:54:49 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:54:53 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:54:53 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (880.219782270) Sun Nov 27 18:54:53 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:54:53 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:54:53 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:54:54 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:54:58 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:54:58 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (885.220328500) Sun Nov 27 18:54:58 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:54:58 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:54:58 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:54:59 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:55:00 2016 kern.warn kernel: [ 891.740000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:55:02 2016 daemon.info fastd[1597]: resolving host gw02.babel.ffm.freifunk.net' for peer <mesh_vpn_backbone_peer_fastd2>... Sun Nov 27 18:55:02 2016 daemon.info fastd[1597]: resolving hostgw02.babel.ffm.freifunk.net' failed: Name or service not known Sun Nov 27 18:55:03 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7)

as opposed to a different connection try, when everything seems to work in the same configuration, just a while later. Nov 27 18:56:33 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:33 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:56:34 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:38 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:56:38 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (985.257362680) Sun Nov 27 18:56:38 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:56:38 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:38 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:56:39 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:42 2016 daemon.info fastd[1597]: resolving host gw02.babel.ffm.freifunk.net' for peer <mesh_vpn_backbone_peer_fastd2>... Sun Nov 27 18:56:42 2016 daemon.info fastd[1597]: resolving hostgw02.babel.ffm.freifunk.net' failed: Name or service not known Sun Nov 27 18:56:43 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:56:43 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (990.256023740) Sun Nov 27 18:56:43 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:56:43 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:43 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:56:44 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:44 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: client0: event 19 Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: client0: new station 00:18:de:24:c6:7c Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: new client 00:18:de:24:c6:7c on br-client Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: client0: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:47 2016 daemon.info hostapd: client0: STA 00:18:de:24:c6:7c IEEE 802.11: authenticated Sun Nov 27 18:56:47 2016 daemon.info hostapd: client0: STA 00:18:de:24:c6:7c IEEE 802.11: associated (aid 1) Sun Nov 27 18:56:47 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:56:47 2016 kern.warn kernel: [ 999.320000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:56:48 2016 daemon.info l3roamd[871]: client0: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:56:48 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (995.255729510) Sun Nov 27 18:56:48 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:56:48 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:48 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:56:50 2016 kern.warn kernel: [ 1001.860000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:56:51 2016 daemon.info l3roamd[871]: Add Address: fe80::218:deff:fe24:c67c Sun Nov 27 18:56:52 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:53 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:56:53 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (1000.256491255) Sun Nov 27 18:56:53 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:56:53 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:53 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:56:56 2016 kern.warn kernel: [ 1008.210000] REJECT(src client)IN=br-client OUT= MAC=ff:ff:ff:ff:ff:ff:00:18:de:24:c6:7c:08:00 SRC=0.0.0.0 DST=255.255.255.255 LEN=328 TOS=0x10 PREC=0x00 TTL=128 ID=0 PROTO=UDP SPT=68 DPT=67 LEN=308 Sun Nov 27 18:56:57 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:56:58 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:56:58 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (1005.257325825) Sun Nov 27 18:56:58 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:56:58 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:56:58 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:57:00 2016 daemon.info fastd[1597]: resolving host gw02.babel.ffm.freifunk.net' for peer <mesh_vpn_backbone_peer_fastd2>... Sun Nov 27 18:57:00 2016 daemon.info fastd[1597]: resolving hostgw02.babel.ffm.freifunk.net' failed: Name or service not known Sun Nov 27 18:57:02 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: event 60 Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: client0: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (1010.258089745) Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:57:03 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: Got packet to 2a06:8187:fbab:2:218:deff:fe24:c67c Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: Looking for 2a06:8187:fbab:2:218:deff:fe24:c67c Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff24:c67c Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: Got packet to 2a06:8187:fbab:2:218:deff:fe24:c67c Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:218:deff:fe24:c67c Sun Nov 27 18:57:04 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:218:deff:fe24:c67c changes from INACTIVE to ACTIVE Sun Nov 27 18:57:07 2016 daemon.info l3roamd[871]: Checking Client 00:18:de:24:c6:7c (active, br-client/7) Sun Nov 27 18:57:07 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:218:deff:fe24:c67c (1015.826378795) Sun Nov 27 18:57:07 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff24:c67c Sun Nov 27 18:57:07 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:218:deff:fe24:c67c Sun Nov 27 18:57:07 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:218:deff:fe24:c67c changes from ACTIVE to ACTIVE Sun Nov 27 18:57:08 2016 daemon.info l3roamd[871]: Checking Client 9c:eb:e8:20:92:a2 (active, br-client/7) Sun Nov 27 18:57:08 2016 daemon.info l3roamd[871]: ACTIVE 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 (1015.258922520) Sun Nov 27 18:57:08 2016 daemon.info l3roamd[871]: Send NS to ff02::1:ff20:92a2 Sun Nov 27 18:57:08 2016 daemon.info l3roamd[871]: Add Address: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 Sun Nov 27 18:57:08 2016 daemon.info l3roamd[871]: 2a06:8187:fbab:2:9eeb:e8ff:fe20:92a2 changes from ACTIVE to ACTIVE

christf commented 7 years ago

in my tests I saw that handing out IP addresses and roaming worked great as long as igmp-snooping is turned off on br-client.