Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FS#1177 - dnsmasq spams syslog on loss of WAN connection #7130

Open
openwrt-bot opened this issue Nov 18, 2017 · 6 comments
Open

FS#1177 - dnsmasq spams syslog on loss of WAN connection #7130

openwrt-bot opened this issue Nov 18, 2017 · 6 comments
Labels

Comments

@openwrt-bot
Copy link

russell:

Supply the following if possible:

  • Device problem occurs on

Observed on an APU2

  • Software versions of LEDE release, packages, etc.

DISTRIB_ID='LEDE'
DISTRIB_RELEASE='SNAPSHOT'
DISTRIB_REVISION='r5244-f0c37f6ceb'
DISTRIB_CODENAME='reboot'
DISTRIB_TARGET='x86/64'
DISTRIB_ARCH='x86_64'
DISTRIB_DESCRIPTION='LEDE Reboot SNAPSHOT r5244-f0c37f6ceb'
DISTRIB_TAINTS='no-all busybox'

opkg list_installed | grep dnsmasq

dnsmasq - 2.78-2

  • Steps to reproduce

In my case, I have an upstream service provisioned with pppoe. Occasionally, the pppoe session dies as the ISP does some kind of unannounced maintenance. Since updating recently from a March 2016 build of OpenWrt, when this outage occurs, dnsmasq sends many messages, like this:

Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied
Nov 16 02:03:10 192.168.80.1 dnsmasq[27288]: failed to send packet: Permission denied

nearly 30 per second.

@openwrt-bot
Copy link
Author

jow-:

Please provide your /etc/config/dhcp

@openwrt-bot
Copy link
Author

russell:

Here you go:

config dnsmasq option filterwin2k '0' option rebind_localhost '1' option local '/lan/' option nonegcache '0' option authoritative '1' option readethers '1' option leasefile '/tmp/dhcp.leases' option resolvfile '/tmp/resolv.conf.auto' option localservice '1' option domainneeded '0' option boguspriv '0' option localise_queries '0' option domain 'foo' option expandhosts '0' option nohosts '0' option rebind_protection '0' list notinterface 'pppoe-wan' list server '/foo/111.222.33.44' list server '/11.10.in-addr.arpa/111.222.33.44'

config dhcp 'pub'
option dhcpv6 'server'
option ra 'server'
option interface 'pub'
option start '50'
option limit '1024'
option leasetime '1h'
option force '1'

config dhcp 'wan'
option interface 'wan'
option ignore '1'

config odhcpd 'odhcpd'
option maindhcp '0'
option leasefile '/tmp/hosts/odhcpd'
option leasetrigger '/usr/sbin/odhcpd-update'
option loglevel '4'

config dhcp 'priv'
option dhcpv6 'server'
option ra 'server'
option interface 'priv'
option start '100'
option limit '150'
option leasetime '12h'
option force '1'

... plus a bunch of host and a few boot and mac sections, that don't look relevant.

@openwrt-bot
Copy link
Author

dedeckeh:

Do you still observe the dnsmasq spam log with latest trunk ?
If yes could you enable logqueries in the dnsmasq uci section ?

@openwrt-bot
Copy link
Author

Adminiuga:

I can see the same messages from DNSmasq in the snapshot from 12/21/17
Firmware Version OpenWrt SNAPSHOT r5597-dda2229 / LuCI Master (git-17.351.54937-a2a1c35)

Only in my case the WAN interface was disabled deliberately, as I'm using it as an AP only.
Network config

config interface 'loopback'
option ifname 'lo'
option proto 'static'
option ipaddr '127.0.0.1'
option netmask '255.0.0.0'

config globals 'globals'
option ula_prefix 'fdfe:efa:b00b::/48'

config interface 'lan'
option type 'bridge'
option ifname 'eth0.1'
option proto 'static'
option ipaddr '192.168.1.3'
option netmask '255.255.255.0'
option gateway '192.168.1.254'
option dns '192.168.1.10 192.168.1.11'
option stp '1'
option ip6assign '64'

config interface 'wan'
option ifname 'eth0.2'
option _orig_ifname 'eth0.2'
option _orig_bridge 'false'
option proto 'none'

config interface 'wan6'
option ifname 'eth0.2'
option _orig_ifname 'eth0.2'
option _orig_bridge 'false'
option proto 'none'

config switch
option name 'switch0'
option reset '1'
option enable_vlan '1'

config switch_vlan
option device 'switch0'
option vlan '1'
option vid '1'
option ports '0t 1 2 3'

config switch_vlan
option device 'switch0'
option vlan '2'
option vid '2'
option ports '0t'

config switch_vlan
option device 'switch0'
option vlan '3'
option vid '8'
option ports '0t 1t 2t 3t 4 5'

config interface 'WLG'
option proto 'none'
option ifname 'eth0.8'
option type 'bridge'
option stp '1'

DHCP -- pretty much default configuration. not using as a DHCP/DNS

config dnsmasq
option domainneeded '1'
option boguspriv '1'
option filterwin2k '0'
option localise_queries '1'
option rebind_protection '1'
option rebind_localhost '1'
option local '/lan/'
option domain 'lan'
option expandhosts '1'
option nonegcache '0'
option authoritative '1'
option readethers '1'
option leasefile '/tmp/dhcp.leases'
option resolvfile '/tmp/resolv.conf.auto'
option nonwildcard '1'
option localservice '1'

config dhcp 'lan'
option interface 'lan'
option ignore '1'

config dhcp 'wan'
option interface 'wan'
option ignore '1'

config odhcpd 'odhcpd'
option maindhcp '0'
option leasefile '/tmp/hosts/odhcpd'
option leasetrigger '/usr/sbin/odhcpd-update'
option loglevel '4'

DNSMasq query log

Fri Dec 22 17:28:35 2017 daemon.info dnsmasq[4286]: 20 127.0.0.1/33443 config 192.168.1.10 is NXDOMAIN
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 21 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63711 query[A] wpad.contoso.com from fd7c:86b1:8dce::6d66:307a:eb18:4e70
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 21 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63711 forwarded wpad.contoso.com to 192.168.1.12
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 21 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63711 forwarded wpad.contoso.com to 192.168.1.10
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 22 fd7c:86b1:8dce::6d66:307a:eb18:4e70/49747 query[AAAA] wpad.contoso.com from fd7c:86b1:8dce::6d66:307a:eb18:4e70
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 22 fd7c:86b1:8dce::6d66:307a:eb18:4e70/49747 forwarded wpad.contoso.com to 192.168.1.12
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 22 fd7c:86b1:8dce::6d66:307a:eb18:4e70/49747 forwarded wpad.contoso.com to 192.168.1.10
Fri Dec 22 17:28:42 2017 daemon.warn dnsmasq[4286]: possible DNS-rebind attack detected: wpad.contoso.com
Fri Dec 22 17:28:42 2017 daemon.err dnsmasq[4286]: failed to send packet: Permission denied
Fri Dec 22 17:28:42 2017 daemon.info dnsmasq[4286]: 22 fd7c:86b1:8dce::6d66:307a:eb18:4e70/49747 reply wpad.contoso.com is NODATA-IPv6
Fri Dec 22 17:28:42 2017 daemon.err dnsmasq[4286]: failed to send packet: Permission denied
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 query[A] outlook.office365.com from fd7c:86b1:8dce::6d66:307a:eb18:4e70
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 forwarded outlook.office365.com to 192.168.1.10
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 query[AAAA] outlook.office365.com from fd7c:86b1:8dce::6d66:307a:eb18:4e70
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 forwarded outlook.office365.com to 192.168.1.10
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook.ha.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook.office365.com.g.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.125.146
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.41.82
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.120.162
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.160.178
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.169.162
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.139.114
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.151.18
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.134.34
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 23 fd7c:86b1:8dce::6d66:307a:eb18:4e70/55378 reply outlook-namcentral3.office365.com is 40.97.41.66
Fri Dec 22 17:28:54 2017 daemon.err dnsmasq[4286]: failed to send packet: Permission denied
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook.ha.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook.office365.com.g.office365.com is
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:0:24::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:804:a::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:102:de::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:405:2a::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:404:f4::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:906:72::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:902:ca::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:101:3a::2
Fri Dec 22 17:28:54 2017 daemon.info dnsmasq[4286]: 24 fd7c:86b1:8dce::6d66:307a:eb18:4e70/63660 reply outlook-namcentral3.office365.com is 2603:1036:0:25::2
Fri Dec 22 17:28:54 2017 daemon.err dnsmasq[4286]: failed to send packet: Permission denied

@openwrt-bot
Copy link
Author

Adminiuga:

I can reproduce it with the snapshot from 12/21/17

@openwrt-bot
Copy link
Author

rdslw:

This still persists, even on 18.06.2

@hans, can you change status, as reporter provided all info.

If you need anything more, let me know

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant