Dhcpv6 client doesn't complete negotiation, no delegated prefix

This is probably related to DHCPv6 release/renew.

Good, you can try to debug the network init script to find out what exactly triggers the restart action that makes it work again.

1 Like

I tried with a bare minimum:

network.wan6=interface
network.wan6.proto='dhcpv6'
network.wan6.ifname='@wan'
network.wan6.metric='20'

After sending 7 solicits and getting 7 advertisements, eventually it sent a request, got the reply and concluded the negotiation.
What troubles me are the logs:

Wed Dec 23 14:55:54 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: (re)starting transaction on pppoe-wan
Wed Dec 23 14:55:55 2020 daemon.notice odhcp6c[8621]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 14:55:55 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
...
Wed Dec 23 14:56:32 2020 daemon.notice odhcp6c[8621]: Got a valid ADVERTISE after 36608ms
Wed Dec 23 14:56:32 2020 daemon.info odhcp6c[8621]: IAID 0001 T1 450 T2 720
Wed Dec 23 14:56:32 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Got a valid ADVERTISE after 36608ms

It only detected the seventh advertisement.
The same occurs now with renew.

Wed Dec 23 15:04:04 2020 daemon.notice odhcp6c[8621]: Starting RENEW transaction (timeout 270s, max rc 0)
Wed Dec 23 15:04:04 2020 daemon.notice odhcp6c[8621]: Send RENEW message (elapsed 0ms, rc 0)
Wed Dec 23 15:04:04 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Starting RENEW transaction (timeout 270s, max rc 0)
Wed Dec 23 15:04:04 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Send RENEW message (elapsed 0ms, rc 0)
Wed Dec 23 15:04:15 2020 daemon.notice odhcp6c[8621]: Send RENEW message (elapsed 10496ms, rc 1)
Wed Dec 23 15:04:15 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Send RENEW message (elapsed 10496ms, rc 1)
Wed Dec 23 15:04:37 2020 daemon.notice odhcp6c[8621]: Send RENEW message (elapsed 32768ms, rc 2)
Wed Dec 23 15:04:37 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Send RENEW message (elapsed 32768ms, rc 2)
Wed Dec 23 15:05:22 2020 daemon.notice odhcp6c[8621]: Send RENEW message (elapsed 77824ms, rc 3)
Wed Dec 23 15:05:22 2020 daemon.notice netifd: wan6 (8621): odhcp6c[8621]: Send RENEW message (elapsed 77824ms, rc 3)

I can see the renew-reply in tcpdump, but odhcp6c doesn't seem to get it in the logs.
After some time it starts sending rebinds, I can see the reply in tcpdump, but again they are ignored.
Eventually the lease times out and starts solicits again.

Also the strace, if you can spot anything unusual in there.

I guess this is the next step in case the strace or the recent findings don't reveal anything.

1 Like

worth trying this i suppose... ( pastebin be broken ) pm it if you like...

renice -n -1 -p $(pidof odhcp6c)

and another thing, can you uninstall bash too... ( just want to exclude something for a few more tests onwards )...

1 Like

bash removed (wasn't using it anyway) and odhcp6c reniced, unfortunately that didn't help.

1 Like

a log ( tcpdump ) from when it was working / month or so ago... would be interesting to see if anything has changed...

edit not so relavent

NOTE: my ipv6 knowledge is limited so some of what I say could be normal / no problem...

some general observations;

  • the RA(isp-server) and dhcp server addresses are different...
  • the second route entry in the ubus call from strace may be odd...; no source... ( +no pd )...

i wonder if your isp made the dhcp server separate recently or something like that...

from your descriptions of the symptoms... initial SOLICIT generally works... it seems to be the 'switching to statefull mode'... where something goes weird...

i believe odhcp6c not 'seeing' responses is an 'after effect' of this 'weird' state being triggered... and not the cause of it... prior to the weird-state... odhcp6c-logread output looks good... but I dont see these options in the ubus call from strace ( perhaps the trace was just from a failed-state capture session )...

  • would be good if you also monitor ubus in another terminal... and get all the calls from initial success onwards... then compare with

  • what is sent in tcp dump... pay attention to the routes and sending server addresses

ubus monitor | grep notify_proto | grep ip6addr

in other words... i think the issue within the proto state tables... or something in the (pre?)renew/advertise proto formatting goes whacky...

we might be able to track down 'why'... ( inspection of raw options sent )

but tracking down how is likely a low level developer task... ( inspection of handling those options )...

No such luck unfortunately. However the same issue was part of a misconfiguration of mtu, but was supposed to be solved after the mtu was correct.

No, they always had it like this. In general they are very helpful and since it is a small village provider they were quite happy to test ipv6 connectivity with me as the first client.

That is partially correct. The RPi will eventually get the advertise, but after a lot of delay and many unread responses.

Wed Dec 23 21:03:17 2020 daemon.notice odhcp6c[15600]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:03:17 2020 daemon.notice netifd: wan6 (15600): odhcp6c[15600]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:03:33 2020 daemon.notice odhcp6c[15600]: Got a valid ADVERTISE after 15253ms

During my tests yesterday I had one time that everything worked fine, but didn't stay like this.

Wed Dec 23 21:01:38 2020 daemon.notice odhcp6c[4812]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:01:38 2020 daemon.notice odhcp6c[4812]: Got a valid ADVERTISE after 2ms
Wed Dec 23 21:01:38 2020 daemon.info odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Got a valid ADVERTISE after 2ms
Wed Dec 23 21:01:38 2020 daemon.info odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Starting REQUEST transaction (timeout 4294967295s, max rc 10)
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Send REQUEST message (elapsed 0ms, rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting REQUEST transaction (timeout 4294967295s, max rc 10)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Send REQUEST message (elapsed 0ms, rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Got a valid REPLY after 3ms
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Got a valid REPLY after 3ms
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: T1 450s, T2 720s, T3 900s
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: T1 450s, T2 720s, T3 900s
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: entering stateful-mode on pppoe-wan
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Starting <POLL> transaction (timeout 450s, max rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: entering stateful-mode on pppoe-wan
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting <POLL> transaction (timeout 450s, max rc 0)

I tried once again. For more than 20 minutes they are exchanging solicit-advertise.

root@magiatiko / > tcpdump -i pppoe-wan -evn udp port 547
tcpdump: listening on pppoe-wan, link-type LINUX_SLL (Linux cooked v1), capture size 262144 bytes

13:28:18.817648 Out ethertype IPv6 (0x86dd), length 168: (flowlabel 0x72d87, hlim 1, next-header UDP (17) payload length: 112) fe80::d832:bada:97ad:e74b.546 > ff02::1:2.547: [udp sum ok] dhcp6 solicit (xid=70612e (elapsed-time 0) (option-request SIP-servers-domain SIP-servers-address DNS-server DNS-search-list SNTP-servers NTP-server AFTR-Name opt_67 opt_94 opt_95 opt_96 opt_82) (client-ID hwaddr type 1 001e101f0000) (reconfigure-accept) (Client-FQDN) (IA_NA IAID:1 T1:0 T2:0) (IA_PD IAID:1 T1:0 T2:0))
13:28:18.821227  In ethertype IPv6 (0x86dd), length 182: (hlim 64, next-header UDP (17) payload length: 126) fe80::10c.547 > fe80::d832:bada:97ad:e74b.546: [udp sum ok] dhcp6 advertise (xid=70612e (client-ID hwaddr type 1 001e101f0000) (server-ID hwaddr type 1 6c3b6bee0d46) (preference 255) (DNS-server 2001:4860:4860::8888 2001:4860:4860::8844) (IA_PD IAID:1 T1:450 T2:720 (IA_PD-prefix 2222:3333:225:7500::/56 pltime:810 vltime:900)))
...
13:50:09.867416 Out ethertype IPv6 (0x86dd), length 168: (flowlabel 0x72d87, hlim 1, next-header UDP (17) payload length: 112) fe80::d832:bada:97ad:e74b.546 > ff02::1:2.547: [udp sum ok] dhcp6 solicit (xid=70612e (elapsed-time 65535) (option-request SIP-servers-domain SIP-servers-address DNS-server DNS-search-list SNTP-servers NTP-server AFTR-Name opt_67 opt_94 opt_95 opt_96 opt_82) (client-ID hwaddr type 1 001e101f0000) (reconfigure-accept) (Client-FQDN) (IA_NA IAID:1 T1:0 T2:0) (IA_PD IAID:1 T1:0 T2:0))
13:50:09.870379  In ethertype IPv6 (0x86dd), length 182: (hlim 64, next-header UDP (17) payload length: 126) fe80::10c.547 > fe80::d832:bada:97ad:e74b.546: [udp sum ok] dhcp6 advertise (xid=70612e (client-ID hwaddr type 1 001e101f0000) (server-ID hwaddr type 1 6c3b6bee0d46) (preference 255) (DNS-server 2001:4860:4860::8888 2001:4860:4860::8844) (IA_PD IAID:1 T1:450 T2:720 (IA_PD-prefix 2222:3333:225:7500::/56 pltime:810 vltime:900)))

In the logs odhcp6c has not detected any response:

Thu Dec 24 13:28:18 2020 daemon.notice odhcp6c[5506]: (re)starting transaction on pppoe-wan
Thu Dec 24 13:28:18 2020 daemon.notice netifd: wan6 (5506): odhcp6c[5506]: (re)starting transaction on pppoe-wan
Thu Dec 24 13:28:18 2020 daemon.notice odhcp6c[5506]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Thu Dec 24 13:28:18 2020 daemon.notice netifd: wan6 (5506): odhcp6c[5506]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)

root@magiatiko / > date
Thu Dec 24 13:52:47 CET 2020

Regarding ubus, I managed to capture both scenarios. The working one:

<- 9569fa05 #43084bd1         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{"passthru":"001700202001486048600000000000000000888820014860486000000000000000008844"},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604796,"valid":2591996,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:225:7500::/56"},{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591996}],"ip6prefix":["2222:3333:225:7500::/56,810,900"],"dns":["2001:4860:4860::8888","2001:4860:4860::8844"],"interface":"wan6"}}
-> 9d8725df #9569fa05         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{"passthru":"001700202001486048600000000000000000888820014860486000000000000000008844"},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604796,"valid":2591996,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:225:7500::/56"},{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591996}],"ip6prefix":["2222:3333:225:7500::/56,810,900"],"dns":["2001:4860:4860::8888","2001:4860:4860::8844"],"interface":"wan6"},"user":"root","group":"root"}

and the failed one:

<- c2ea4cec #43084bd1         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604790,"valid":2591990,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1790,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591990}],"dns":["2001:4860:4860::8844","2001:4860:4860::8888"],"interface":"wan6"}}
-> 9d8725df #c2ea4cec         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604790,"valid":2591990,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1790,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591990}],"dns":["2001:4860:4860::8844","2001:4860:4860::8888"],"interface":"wan6"},"user":"root","group":"root"}

I hope it can provide some insight what is going on.

1 Like

odd indeed...

i'm thinking we should try dropping in an older binary... then if the issue is still present... we know it's config / ppp / install specific...

https://github.com/wulfy23/rpi4-opkg/blob/master/odhcp6c-previous/odhcp6c_2020-03-28-f575351c-16_aarch64_cortex-a72.ipk?raw=true

I think I found the culprit. I started disabling services, like sqm, mwan3, modemmanager, removed the LTE dongle and after I disabled banIP I have a couple of successful ifup wan6
What puzzles me is why didn't it have any effect after I stopped the firewall with fw3 stop
Maybe @dibdot can help us understand?

2 Likes

I think the correct syntax is /etc/init.d/firewall stop or fw3 flush to flush all existing firewall rules/chains (incl. the conntrack table).

2 Likes

Sorry for the delay, family obligations and I needed to verify a few things before I reply.

You are right. However with fw3 stop I get this:

Summary
root@magiatiko / > iptables-save -c 
# Generated by iptables-save v1.8.4 on Tue Dec 29 17:25:03 2020
*raw
:PREROUTING ACCEPT [643:303654]
:OUTPUT ACCEPT [79:8611]
COMMIT
# Completed on Tue Dec 29 17:25:03 2020
# Generated by iptables-save v1.8.4 on Tue Dec 29 17:25:03 2020
*nat
:PREROUTING ACCEPT [91:9384]
:INPUT ACCEPT [65:7100]
:OUTPUT ACCEPT [3:156]
:POSTROUTING ACCEPT [13:754]
:dnshijack - [0:0]
[14569:2968604] -A dnshijack -j DNAT --to-destination 10.0.2.2
[0:0] -A dnshijack -j DNAT --to-destination 10.0.2.2
COMMIT
# Completed on Tue Dec 29 17:25:03 2020
# Generated by iptables-save v1.8.4 on Tue Dec 29 17:25:03 2020
*mangle
:PREROUTING ACCEPT [645:303866]
:INPUT ACCEPT [116:16343]
:FORWARD ACCEPT [513:285837]
:OUTPUT ACCEPT [80:8755]
:POSTROUTING ACCEPT [593:294592]
COMMIT
# Completed on Tue Dec 29 17:25:03 2020
# Generated by iptables-save v1.8.4 on Tue Dec 29 17:25:03 2020
*filter
:INPUT ACCEPT [2:212]
:FORWARD ACCEPT [2:173]
:OUTPUT ACCEPT [3:276]
:banIP - [0:0]
[0:0] -A banIP -o pppoe-wan -m conntrack --ctstate NEW -m set --match-set whitelist dst -j RETURN
[0:0] -A banIP -o tun2 -m conntrack --ctstate NEW -m set --match-set whitelist dst -j RETURN
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set whitelist src -j RETURN
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set whitelist src -j RETURN
[0:0] -A banIP -p udp -m udp --sport 67:68 --dport 67:68 -j RETURN
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set blacklist src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set blacklist src -j DROP
[0:0] -A banIP -o tun2 -m conntrack --ctstate NEW -m set --match-set blacklist dst -j REJECT --reject-with icmp-port-unreachable
[0:0] -A banIP -o pppoe-wan -m conntrack --ctstate NEW -m set --match-set blacklist dst -j REJECT --reject-with icmp-port-unreachable
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set tor src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set tor src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set threat src -j DROP
[33:1452] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set threat src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set debl src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set debl src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set myip src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set myip src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set yoyo src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set yoyo src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set sslbl src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set sslbl src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set feodo src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set feodo src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set dshield src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set dshield src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set proxy src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set proxy src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set iblocklist src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set iblocklist src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set drop src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set drop src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set edrop src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set edrop src -j DROP
[0:0] -A banIP -i tun2 -m conntrack --ctstate NEW -m set --match-set bogon src -j DROP
[0:0] -A banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set bogon src -j DROP
[0:0] -A banIP -o tun2 -m conntrack --ctstate NEW -m set --match-set bogon dst -j REJECT --reject-with icmp-port-unreachable
[0:0] -A banIP -o pppoe-wan -m conntrack --ctstate NEW -m set --match-set bogon dst -j REJECT --reject-with icmp-port-unreachable
COMMIT
# Completed on Tue Dec 29 17:25:03 2020

which means that banIP chain should not be used, because it is defined but never called.

The interesting detail I found out is that the fw3 stop doesn't have effect in ip6tables, can someone confirm this too?

I can verify now that the culprit for the dropped packets is bogon6 ipset. I added this logging line:
ip6tables -I banIP -i pppoe-wan -m conntrack --ctstate NEW -m set --match-set bogon_6 src -j LOG --log-prefix "BOGON6 :"
since that was the only entry in the banIP chain with increasing hits.
Turns out it is indeed dropping:

Tue Dec 29 18:02:58 2020 kern.warn kernel: [586990.009710] BOGON6 :IN=pppoe-wan OUT= MAC= SRC=fe80:0000:0000:0000:0000:0000:0000:010c DST=fe80:0000:0000:0000:4415:b44e:6dea:2350 LEN=161 TC=0 HOPLIMIT=64 FLOWLBL=0 PROTO=UDP SPT=547 DPT=546 LEN=121
Tue Dec 29 18:03:02 2020 kern.warn kernel: [586994.245495] BOGON6 :IN=pppoe-wan OUT= MAC= SRC=fe80:0000:0000:0000:0000:0000:0000:010c DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=187 TC=0 HOPLIMIT=1 FLOWLBL=0 PROTO=UDP SPT=5678 DPT=5678 LEN=147
Tue Dec 29 18:04:02 2020 kern.warn kernel: [587054.231104] BOGON6 :IN=pppoe-wan OUT= MAC= SRC=fe80:0000:0000:0000:0000:0000:0000:010c DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=187 TC=0 HOPLIMIT=1 FLOWLBL=0 PROTO=UDP SPT=5678 DPT=5678 LEN=147
Tue Dec 29 18:04:57 2020 kern.warn kernel: [587108.795173] BOGON6 :IN=pppoe-wan OUT= MAC= SRC=fe80:0000:0000:0000:0000:0000:0000:010c DST=fe80:0000:0000:0000:4415:b44e:6dea:2350 LEN=161 TC=0 HOPLIMIT=64 FLOWLBL=0 PROTO=UDP SPT=547 DPT=546 LEN=121

The only hits I can see are for 8000::/1 which includes the link local addresses.
This is bad aggregate as it won't let the dhcp replies from link local address.
As a workaround I have added the fc00::/6 in whitelist. Maybe something you could consider @dibdot to avoid any future problems and be in line with the default firewall rule, which allows the same for dhcp6 purposes.
Still I didn't understand why did it work sometimes and sometimes it didn't...

1 Like

still finding this unusual... but can confirm enabling the service also brought down my wan6 ( eventually ), great work trendy tracking it down... and apologies for all the wild goose chases!

1 Like

Thanks for the pointer! Currently I'm working on a new release and DHCPv6 is one of multiple things on my todo list. Said that this morning the new code base runs for the first time on my test device ...

root@2go_ar750s:~$ /usr/bin/banip.sh
debug banIP-0.7.0-alpha[15512] f_conf  ::: chain: banIP, log_chains (src/dst): banIP_log_src/banIP_log_dst, targets (src/dst): DROP/REJECT, lan_inputs (4/6): input_lan_rule/input_lan_rule, lan_forwards (4/6): forwarding_lan_rule/forwarding_lan_rule, wan_inputs (4/6): input_wan_rule/input_wan_rule, wan_forwards (4/6): forwarding_wan_rule/forwarding_wan_rule
info banIP-0.7.0-alpha[15512] temp base directory is '/tmp'
debug banIP-0.7.0-alpha[15512] f_temp   ::: tmp_base: /tmp, tmp_dir: /tmp/tmp.BLbIEB, pid_file: /var/run/banip.pid
debug banIP-0.7.0-alpha[15512] f_bgserv ::: status: stop, bg_pid: -, ban_realtime: true, log_service: /etc/banip/banip.service
debug banIP-0.7.0-alpha[15512] f_jsnup ::: status: running, setcnt: 0, cnt: 0
info banIP-0.7.0-alpha[15512] start banIP processing (start)
info banIP-0.7.0-alpha[15512] backup directory is '/mnt/data/banIP'
debug banIP-0.7.0-alpha[15512] f_env   ::: fetch_util: /usr/bin/curl, fetch_parm: --connect-timeout 20 --silent --show-error --location -o, ssh_daemons:  dropbear, interfaces:  trm_wwan trm_wwan6, devices:  wlan1, all_devices: eth0 br-lan eth0.1 eth0.2 wlan0 wlan1 wg0 , subnets:  192.168.254.194/24
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_4, mode: initial, chain: banIP, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_4, mode: initial, chain: banIP_log_src, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_4, mode: initial, chain: banIP_log_dst, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_6, mode: initial, chain: banIP, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_6, mode: initial, chain: banIP_log_src, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial_6, mode: initial, chain: banIP_log_dst, out_rc: 0
debug banIP-0.7.0-alpha[15512] f_ipset ::: name: initial, mode: initial, out_rc: 0

I'll contact you for testing in 2021! :wink:

2 Likes

Did you check by any chance the

?

just tested and it worked with some delay... restarting the banip service results in rules being entered them removed again... ( which i'd guess would also be triggered on/off by subsequent ifEVENTS )

prefer to use '/etc/init.d/firewall disable; /etc/init.d/firewall stop' but i'm not sure if that would change anything here...

seems the service runs independently to the firewall... which is semi-understandable... mwan3 had some recent PR discussions about if it's possible to detect a user '/etc/init.d/firewall restart' or similar...

most services you can just /etc/init.d/banip stop... but it seems to want to be disabled first or similar so perhaps something is a little whacky with it's state machine...

in summary...

/etc/init.d/banip disable; /etc/init.d/banip stop; sleep 15
/etc/init.d/firewall disable; /etc/init.d/firewall stop #OR fw3 stop #and or maybe flush #which is less permanent than disable due to triggers

EDIT... looks like somethings gone whacky now and init.d/PROCD is not happy ( messed up the state machine somehow );

################### /etc/init.d/banip start
banIP processing failed, fatal iptables error(s) during subshell processing (Raspberry Pi 4 Model B Rev 1.1, OpenWrt SNAPSHOT r15323-7ba2f5c96f)

using the script still works;

/usr/bin/banip.sh start
1 Like

@anon50098793 bottomline you'll need something like that?

Chain banIP (4 references)
 pkts bytes target     prot opt in     out     source               destination         
    1   106 RETURN     udp      *      *       fc00::/6             fc00::/6             udp spt:546 dpt:547
    0     0 DROP       all      eth3   *       ::/0                 ::/0                 ctstate NEW match-set blacklist_6 src
    0     0 REJECT     all      *      eth3    ::/0                 ::/0                 ctstate NEW match-set blacklist_6 dst reject-with icmp6-port-unreachable
[...]
1 Like

yeah that's pretty close... there are some icmp6 typically link-local but i'm not sure thats always the case;

[6:400] -A banIP -d fe80::/64 -p ipv6-icmp -j RETURN
[1:72] -A banIP -s fe80::/64 -p ipv6-icmp -j RETURN

Warning: fe80::2a2:ff:feb2:c2 is in set bogon_6
GWIP REMOVING fe80::2a2:ff:feb2:c2 from bogon_6 > GWIP ADDING fe80::2a2:ff:feb2:c2 to bogon_6_not

( fc00::/6 above prefix was 'dynamic' ) I think some more selective jumping from input_rule to weed all all the local<->local... probably best its own chain/whitelist... ( i.e. GWIP above )

OK, added another rule ...

Chain banIP (4 references)
 pkts bytes target     prot opt in     out     source               destination         
   10  1514 RETURN     udp      *      *       fc00::/6             fc00::/6             udp spt:546 dpt:547
    0     0 RETURN     icmpv6    *      *       fe80::/64            fe80::/64           
    0     0 DROP       all      eth3   *       ::/0                 ::/0                 ctstate NEW match-set DoH_6 src
[...]

If this OK I'll open a PR to fix the current version.

1 Like

looks pretty good... thanks very much!

i think the standard is fe/7 but check with trendy or he can test the PR and report back to speed things up...

Thanks, fixed in 0.3.13 - feel free to test the new version before merge, PR see here

1 Like

The ports are incorrect, source is 547 and destination 546. Also it seems that there are a couple of multicast packets dropped from the same capture sent to ports 5678. Also not to forget that icmp6 needs to be allowed as well.