Text only | Text with Images

OPNsense Forum

Archive => 22.7 Legacy Series => Topic started by: andrema2 on July 29, 2022, 10:01:52 PM

Title: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: andrema2 on July 29, 2022, 10:01:52 PM
Hi

I have seen at Unbound log that it has restarted itself 3 times since 9am today exactly every 2 hours.

I didn't see any other information on the log that could explain it. Any one else having this issue ?
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: ar on July 29, 2022, 10:44:55 PM
Same here, except it seems to be every 45 minutes, see attachment. I increased verbosity, maybe something comes up.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: jclendineng on July 29, 2022, 11:12:54 PM
Every 20 minutes here, fun times :)
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on July 29, 2022, 11:35:23 PM
Does it perhaps restart at dhcp renewal of one the network interfaces?
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: chtse53 on July 29, 2022, 11:38:38 PM
Mine frequently renews the wan ip address, which didn't change, and caused unbound to restart.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: ar on July 30, 2022, 12:56:00 AM
Level 5 logs just show <code>got control cmd quit</code> for every thread, so not much more info there.

Code Select

2022-07-30T00:22:10 Informational unbound [12754:0] info: server stats for thread 0: 198 queries, 61 answers from cache, 137 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2022-07-30T00:22:10 Debug unbound [12754:0] debug: comm_point_close of 36: event_del
2022-07-30T00:22:10 Debug unbound [12754:0] debug: cleanup.
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 7
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 7
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 6
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 6
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 5
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 5
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 4
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 4
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 3
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 3
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 2
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 2
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join success 1
2022-07-30T00:22:10 Debug unbound [12754:1] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:6] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:7] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:0] debug: join 1
2022-07-30T00:22:10 Debug unbound [12754:5] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:3] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:4] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:2] debug: got control cmd quit
2022-07-30T00:22:10 Debug unbound [12754:0] debug: stop threads
2022-07-30T00:22:10 Informational unbound [12754:0] info: service stopped (unbound 1.16.1).
2022-07-30T00:22:09 Informational unbound [12754:3] info: send_udp over interface: 127.0.0.1
2022-07-30T00:22:09 Debug unbound [12754:3] debug: using localzone . transparent
2022-07-30T00:22:09 Informational unbound [12754:3] info: receive_udp on interface: 127.0.0.1
2022-07-30T00:22:09 Informational unbound [12754:5] info: send_udp over interface: 127.0.0.1
2022-07-30T00:22:09 Debug unbound [12754:5] debug: using localzone localdomain. transparent
2022-07-30T00:22:09 Informational unbound [12754:5] info: receive_udp on interface: 127.0.0.1
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on July 30, 2022, 10:46:26 AM
I have checked my logs, and indeed unbound is restarted upon dhcp renewal. Wouldn't it make sense to make it a bit smarter and only restart when the ip address changes?
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: andrema2 on July 30, 2022, 02:08:21 PM
Yeah, this is not how it was working before. I upgraded to 22.7_4 and the behaviour is the same. Apparently there is something wrong with the current implementation.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on July 30, 2022, 09:16:24 PM
Might be a side effect of https://github.com/opnsense/core/issues/5624

Need to check on Monday.

I need one info from everyone having this issue: under WAN settings, what is your IPv4 type?


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: Scuro on July 30, 2022, 09:53:04 PM
Quote from: franco on July 30, 2022, 09:16:24 PM
I need one info from everyone having this issue: under WAN settings, what is your IPv4 type?

IPv4 Configuration Type: DHCP
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on July 30, 2022, 10:01:30 PM
I have a fiber setup with internet access on one vlan (a PPPoE connection which uses dhcp) and I have IP TV on another vlan which also uses dhcp, but directly, without PPPoE.
Please let me know if you need more specific info.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: joysense on July 30, 2022, 11:41:26 PM
Same issue. Noticed some tcp errors since I was using DoT. Had switch over to dnsmasq in mean time
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on July 31, 2022, 11:11:35 AM
In my case Unbound restart with a 30 min intervall. Wan uses DHCP on IPv4.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on July 31, 2022, 12:46:27 PM
Has anyone checked their IPv4 lease time? It might "coincide" with the reload interval measured.


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on July 31, 2022, 04:26:00 PM
It does coincide

https://www.imagebam.com/view/MEBZHA2 (https://www.imagebam.com/view/MEBZHA2)

https://www.imagebam.com/view/MEBZHA5 (https://www.imagebam.com/view/MEBZHA5)
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: andrema2 on July 31, 2022, 06:32:19 PM
Yes, it does coincide.

I was able to fixed it by assigning a fix IP4 for my WAN interface. I assume it won't be possible for all user cases.

Cheers
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 12:27:55 PM
A little curious about output of the following as well:

# opnsense-log | grep "On (IP address:"


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: jclendineng on August 01, 2022, 02:15:54 PM
Quote from: franco on July 30, 2022, 09:16:24 PM
Might be a side effect of https://github.com/opnsense/core/issues/5624

Need to check on Monday.

I need one info from everyone having this issue: under WAN settings, what is your IPv4 type?


Cheers,
Franco

Im using iPv4/DHCP only
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: jclendineng on August 01, 2022, 02:18:46 PM
Quote from: miroco on July 31, 2022, 04:26:00 PM
It does coincide

https://www.imagebam.com/view/MEBZHA2 (https://www.imagebam.com/view/MEBZHA2)

https://www.imagebam.com/view/MEBZHA5 (https://www.imagebam.com/view/MEBZHA5)

Interesting..In any case, unbound should not restart on WAN renew anyhow right? Unless im missing something :) Personally I dont have WAN interface selected in unbound anyways.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 02:21:19 PM
Unbound restart behaviour changed in 22.1 for complex reasons. For now we need to focus on 22.7 behavioural change instead.


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on August 01, 2022, 02:26:25 PM
This is my sanitized contribution

Code Select
root@opnsense:~ # opnsense-log | grep "On (IP address:"
<11>1 2022-08-01T00:17:49+02:00 xyz.ddns.net opnsense 2016 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T00:47:50+02:00 xyz.ddns.net opnsense 54016 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T01:15:35+02:00 xyz.ddns.net opnsense 10061 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T01:45:36+02:00 xyz.ddns.net opnsense 64671 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T02:14:25+02:00 xyz.ddns.net opnsense 63640 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T02:44:04+02:00 xyz.ddns.net opnsense 22639 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T03:12:09+02:00 xyz.ddns.net opnsense 85320 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T03:40:11+02:00 xyz.ddns.net opnsense 22974 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T04:10:11+02:00 xyz.ddns.net opnsense 1829 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T04:38:55+02:00 xyz.ddns.net opnsense 90592 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T05:06:43+02:00 xyz.ddns.net opnsense 11486 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T05:36:44+02:00 xyz.ddns.net opnsense 22493 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T06:06:45+02:00 xyz.ddns.net opnsense 9184 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T06:36:44+02:00 xyz.ddns.net opnsense 33091 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T07:06:45+02:00 xyz.ddns.net opnsense 87989 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T07:36:03+02:00 xyz.ddns.net opnsense 76252 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T08:04:28+02:00 xyz.ddns.net opnsense 76523 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T08:33:24+02:00 xyz.ddns.net opnsense 58550 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T09:03:24+02:00 xyz.ddns.net opnsense 35992 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T09:33:18+02:00 xyz.ddns.net opnsense 96828 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T10:03:19+02:00 xyz.ddns.net opnsense 38573 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T10:32:38+02:00 xyz.ddns.net opnsense 83571 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T11:02:39+02:00 xyz.ddns.net opnsense 34587 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T11:32:38+02:00 xyz.ddns.net opnsense 4381 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T12:01:54+02:00 xyz.ddns.net opnsense 66697 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T12:31:55+02:00 xyz.ddns.net opnsense 6420 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T13:01:54+02:00 xyz.ddns.net opnsense 60180 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T13:31:55+02:00 xyz.ddns.net opnsense 24014 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
<11>1 2022-08-01T14:01:54+02:00 xyz.ddns.net opnsense 91467 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 83.x.y.z) (interface: WAN[wan]) (real interface: igb0).
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 02:52:47 PM
@miroco

Is this always the same address masked as 83.x.y.z?


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 01, 2022, 03:35:49 PM
Here it is:

Code Select
<11>1 2022-08-01T00:06:59+02:00 haanjdj.ddns.net opnsense 33441 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T00:37:00+02:00 haanjdj.ddns.net opnsense 96416 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T01:07:00+02:00 haanjdj.ddns.net opnsense 56016 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T01:37:00+02:00 haanjdj.ddns.net opnsense 75297 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T02:07:00+02:00 haanjdj.ddns.net opnsense 25915 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T02:37:00+02:00 haanjdj.ddns.net opnsense 34125 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T03:07:01+02:00 haanjdj.ddns.net opnsense 52943 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T03:37:01+02:00 haanjdj.ddns.net opnsense 63009 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T04:07:01+02:00 haanjdj.ddns.net opnsense 92674 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T04:37:01+02:00 haanjdj.ddns.net opnsense 57190 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T05:07:01+02:00 haanjdj.ddns.net opnsense 82629 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T05:37:01+02:00 haanjdj.ddns.net opnsense 61527 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T06:07:01+02:00 haanjdj.ddns.net opnsense 79509 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T06:37:01+02:00 haanjdj.ddns.net opnsense 59281 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T07:07:01+02:00 haanjdj.ddns.net opnsense 57220 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T07:37:01+02:00 haanjdj.ddns.net opnsense 71620 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T08:07:02+02:00 haanjdj.ddns.net opnsense 37606 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T08:37:02+02:00 haanjdj.ddns.net opnsense 8296 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T09:07:02+02:00 haanjdj.ddns.net opnsense 48452 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T09:37:02+02:00 haanjdj.ddns.net opnsense 82335 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T10:07:02+02:00 haanjdj.ddns.net opnsense 5514 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T10:37:02+02:00 haanjdj.ddns.net opnsense 37886 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T11:07:02+02:00 haanjdj.ddns.net opnsense 15882 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T11:37:02+02:00 haanjdj.ddns.net opnsense 22409 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T12:07:02+02:00 haanjdj.ddns.net opnsense 72066 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T12:37:03+02:00 haanjdj.ddns.net opnsense 99822 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T13:07:03+02:00 haanjdj.ddns.net opnsense 56535 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T13:37:03+02:00 haanjdj.ddns.net opnsense 41725 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T14:07:03+02:00 haanjdj.ddns.net opnsense 26938 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T14:37:03+02:00 haanjdj.ddns.net opnsense 90437 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
<11>1 2022-08-01T15:07:03+02:00 haanjdj.ddns.net opnsense 25213 - [meta sequenceId="3"] /usr/local/etc/rc.newwanip: On (IP address: 10.181.48.207) (interface: WAN_IPTV[opt1]) (real interface: igb1_vlan4).
root@haanjdj:~ #
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 03:47:16 PM
@dinguz: does the cache file exist? Content matches IP?

# cat /tmp/igb1_vlan4_oldip


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 01, 2022, 03:53:23 PM
Quote from: franco on August 01, 2022, 03:47:16 PM
@dinguz: does the cache file exist? Content matches IP?

Yes, it's the same.

Code Select
root@haanjdj:~ # cat /tmp/igb1_vlan4_oldip
10.181.48.207
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 04:07:06 PM
*scratches head*
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on August 01, 2022, 04:18:03 PM
Code Select
@miroco

Is this always the same address masked as 83.x.y.z?


Cheers,
Franco

Yes it is.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 01, 2022, 04:35:06 PM
Ok, we are looking at the right spot but not very precisely. Does this light up anything?

# opnsense-log | grep plugins_configure.\*unbound


Thanks,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on August 01, 2022, 04:45:31 PM
This is my contribution

Code Select
root@opnsense:~ # opnsense-log | grep plugins_configure.\*unbound
<13>1 2022-08-01T00:17:50+02:00 xyz.ddns.net opnsense 2016 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T00:47:50+02:00 xyz.ddns.net opnsense 54016 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T01:15:36+02:00 xyz.ddns.net opnsense 10061 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T01:45:36+02:00 xyz.ddns.net opnsense 64671 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T02:14:25+02:00 xyz.ddns.net opnsense 63640 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T02:44:04+02:00 xyz.ddns.net opnsense 22639 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T03:12:10+02:00 xyz.ddns.net opnsense 85320 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T03:40:11+02:00 xyz.ddns.net opnsense 22974 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T04:10:11+02:00 xyz.ddns.net opnsense 1829 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T04:38:55+02:00 xyz.ddns.net opnsense 90592 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T05:06:43+02:00 xyz.ddns.net opnsense 11486 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T05:36:44+02:00 xyz.ddns.net opnsense 22493 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T06:06:45+02:00 xyz.ddns.net opnsense 9184 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T06:36:44+02:00 xyz.ddns.net opnsense 33091 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T07:06:45+02:00 xyz.ddns.net opnsense 87989 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T07:36:03+02:00 xyz.ddns.net opnsense 76252 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T08:04:28+02:00 xyz.ddns.net opnsense 76523 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T08:33:24+02:00 xyz.ddns.net opnsense 58550 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T09:03:24+02:00 xyz.ddns.net opnsense 35992 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T09:33:18+02:00 xyz.ddns.net opnsense 96828 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T10:03:19+02:00 xyz.ddns.net opnsense 38573 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T10:32:38+02:00 xyz.ddns.net opnsense 83571 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T11:02:39+02:00 xyz.ddns.net opnsense 34587 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T11:32:38+02:00 xyz.ddns.net opnsense 4381 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T12:01:54+02:00 xyz.ddns.net opnsense 66697 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T12:31:55+02:00 xyz.ddns.net opnsense 6420 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T13:01:54+02:00 xyz.ddns.net opnsense 60180 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T13:31:55+02:00 xyz.ddns.net opnsense 24014 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T14:01:55+02:00 xyz.ddns.net opnsense 91467 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T14:30:05+02:00 xyz.ddns.net opnsense 26010 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T14:58:37+02:00 xyz.ddns.net opnsense 13911 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T15:28:11+02:00 xyz.ddns.net opnsense 36178 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T15:58:12+02:00 xyz.ddns.net opnsense 50632 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T16:27:48+02:00 xyz.ddns.net opnsense 36874 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 01, 2022, 04:50:28 PM
same here:

Code Select

root@haanjdj:~ # opnsense-log | grep plugins_configure.\*unbound
<13>1 2022-08-01T00:07:00+02:00 haanjdj.ddns.net opnsense 33441 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T00:37:00+02:00 haanjdj.ddns.net opnsense 96416 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T01:07:00+02:00 haanjdj.ddns.net opnsense 56016 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T01:37:00+02:00 haanjdj.ddns.net opnsense 75297 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T02:07:00+02:00 haanjdj.ddns.net opnsense 25915 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T02:37:01+02:00 haanjdj.ddns.net opnsense 34125 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T03:07:01+02:00 haanjdj.ddns.net opnsense 52943 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T03:37:01+02:00 haanjdj.ddns.net opnsense 63009 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T04:07:01+02:00 haanjdj.ddns.net opnsense 92674 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T04:37:01+02:00 haanjdj.ddns.net opnsense 57190 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T05:07:01+02:00 haanjdj.ddns.net opnsense 82629 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T05:37:01+02:00 haanjdj.ddns.net opnsense 61527 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T06:07:01+02:00 haanjdj.ddns.net opnsense 79509 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T06:37:01+02:00 haanjdj.ddns.net opnsense 59281 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T07:07:01+02:00 haanjdj.ddns.net opnsense 57220 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T07:37:01+02:00 haanjdj.ddns.net opnsense 71620 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T08:07:02+02:00 haanjdj.ddns.net opnsense 37606 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T08:37:02+02:00 haanjdj.ddns.net opnsense 8296 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T09:07:02+02:00 haanjdj.ddns.net opnsense 48452 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T09:37:02+02:00 haanjdj.ddns.net opnsense 82335 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T10:07:02+02:00 haanjdj.ddns.net opnsense 5514 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T10:37:02+02:00 haanjdj.ddns.net opnsense 37886 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T11:07:02+02:00 haanjdj.ddns.net opnsense 15882 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T11:37:02+02:00 haanjdj.ddns.net opnsense 22409 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T12:07:02+02:00 haanjdj.ddns.net opnsense 72066 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T12:37:03+02:00 haanjdj.ddns.net opnsense 99822 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T13:07:03+02:00 haanjdj.ddns.net opnsense 56535 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T13:37:03+02:00 haanjdj.ddns.net opnsense 41725 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T14:07:03+02:00 haanjdj.ddns.net opnsense 26938 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T14:37:03+02:00 haanjdj.ddns.net opnsense 90437 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T15:07:03+02:00 haanjdj.ddns.net opnsense 25213 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T15:37:03+02:00 haanjdj.ddns.net opnsense 48230 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T16:07:03+02:00 haanjdj.ddns.net opnsense 56664 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())
<13>1 2022-08-01T16:37:03+02:00 haanjdj.ddns.net opnsense 64993 - [meta sequenceId="6"] plugins_configure hosts (execute task : unbound_hosts_generate())



please DM me if you need web/SSH access to the box, as it's just a home router.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: bunchofreeds on August 02, 2022, 05:30:25 AM
Just joining in here as I'm seeing the same.

Using DHCP on the WAN which has a lease time of 5 mins meaning Unbound restarts every 2.5 mins :)

2022-08-02T15:27:06   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:24:36   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:22:07   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:19:36   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:17:06   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:14:36   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:12:06   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:09:37   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:07:06   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.   
2022-08-02T15:04:36   Notice   unbound   [62126:0] notice: Restart of unbound 1.16.1.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 02, 2022, 09:13:46 AM
So there is two issues here:

1. New 22.7 behaviour surfaced spurious Unbound HUP reloads through hosts regeneration (which was the case forever)

https://github.com/opnsense/core/commit/7aaa6a263b1

2. Actual regression in 22.7 causing the new behaviour

https://github.com/opnsense/core/commit/bb4743a7322

I'd recommend trying both in tandem:

# opnsense-patch 7aaa6a263b1 bb4743a7322

...and report back the results. :)


Thanks,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on August 02, 2022, 01:21:14 PM
I applied the patch and rebooted the machine to get a reference point.

Code Select
2022-08-02T10:12:12 Notice shutdown reboot by root:

I don't have any instance of [Restart of Unbound 1.16.1] after 10:05:26
Nor do I have any instance of [IPv4 renewal is starting on 'igb0'] after 10:14:35

However, the 30 min IP renewal seems to continue normally

Code Select
2022-08-02T13:11:28 Notice dhclient Creating resolv.conf
2022-08-02T12:43:18 Notice dhclient Creating resolv.conf
2022-08-02T12:13:18 Notice dhclient Creating resolv.conf
2022-08-02T11:43:18 Notice dhclient Creating resolv.conf
2022-08-02T11:13:18 Notice dhclient Creating resolv.conf
2022-08-02T10:43:17 Notice dhclient Creating resolv.conf
2022-08-02T10:13:17 Notice dhclient Creating resolv.conf
2022-08-02T10:05:24 Notice dhclient Creating resolv.conf
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on August 02, 2022, 01:25:03 PM
Sure, dhclient needs to react and invokes dhclient-script, but the script no longer calls rc.newwanip as was the case on 22.1.


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 02, 2022, 04:31:27 PM
I applied the patches earlier today, rebooted for good measure, and I'm happy to report that unbound hasn't been restarted since. Thanks!
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: nodakbarnes on August 02, 2022, 06:21:27 PM
So I applied the patches as well on my Protecli FW2B and it has resolved the issue for me.

Thanks Franco!
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: mueller on August 02, 2022, 06:42:03 PM
... will there be a hotfix here again? :)
I have the same problem.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 02, 2022, 07:23:23 PM
Quote from: mueller on August 02, 2022, 06:42:03 PM
... will there be a hotfix here again? :)
I have the same problem.

I read in another topic it's scheduled for 22.7.1 which will probably be released next week.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: mueller on August 02, 2022, 07:35:19 PM
Very good, because that is quite annoying :)
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: dinguz on August 02, 2022, 08:00:09 PM
Quote from: mueller on August 02, 2022, 07:35:19 PM
Very good, because that is quite annoying :)

You can apply the patch manually as described earlier in this topic, it won't mess up the official releases.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: mueller on August 02, 2022, 08:17:27 PM
Yes, I think that's where it starts to stop for me ;)
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: RamSense on August 02, 2022, 09:46:19 PM
I installed the patch and it has resolved the issue for me also. thnx
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: bunchofreeds on August 02, 2022, 10:18:31 PM
Added both patches and looks resolved! Thanks @franco

# opnsense-patch 7aaa6a263b1 bb4743a7322

Unbound is no longer restarting when then WAN DHCP lease renews
No more "Error opnsense/usr/local/etc/rc.newwanip" in system logs

Thanks again!
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: miroco on August 02, 2022, 10:23:14 PM
9 h later and Unbound is till behaving.  :) Thank you Franco.
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: mueller on August 02, 2022, 11:56:27 PM
It took me a while to realize that you have to enter the above command (# opnsense-patch 7aaa6a263b1 bb4743a7322) via the Secure Shell :-/

I thought I had to download any patches and copy them to certain places etc..

Now everything runs great, many, many thanks
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: scottj on September 04, 2022, 09:19:37 PM
Thanks - this fixed my issue too.  I was having Unbound restart errors in the logs.

I just updated yesterday to:

OPNsense 22.7_4-amd64
FreeBSD 13.1-RELEASE
OpenSSL 1.1.1q 5 Jul 2022

Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on September 05, 2022, 09:40:58 AM
Because 22.7_4 is *not* the latest version.


Cheers,
Franco
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: scottj on September 05, 2022, 06:34:14 PM
Ah, ok. I did not check after doing the initial upgrade.
After upgrading again, it's will working.

I'm now at:

OPNsense 22.7.3_2-amd64
FreeBSD 13.1-RELEASE-p2
OpenSSL 1.1.1q 5 Jul 2022

Thanks!
Title: Re: Unbound Restarting every 2 hours after upgrade to 22.7
Post by: franco on September 05, 2022, 08:56:55 PM
 :)
Text only | Text with Images