F10, NetworkManager, and intermittent dns -- Update
McGuffey, David C.
DAVID.C.MCGUFFEY at saic.com
Tue Feb 3 20:59:25 UTC 2009
On Mon, 26 Jan 2009 07:21:05 -0700, Christopher A. Williams wrote:
>
> On Mon, 2009-01-26 at 08:47 -0500, Tom Horsley wrote:
> > On Mon, 26 Jan 2009 23:23:49 +1100
> > David Timms wrote:
> >
> > > Tom Horsley wrote:
> > > > On Fri, 23 Jan 2009 13:32:08 -0500
> > > > McGuffey, David C. wrote:
> > > >
> > > >> Update: Intermittent dns is still present.
> > > >
> > > > I'd strongly suspect this is NM getting the resolv.conf file
> > > > correct on initial connect, then screwing it up on
> > > > subsequent DHCP lease renewal.
> > > I get the no entries in /etc/resolv.conf directly after logging in
> > > (workaround - an NM entry with static IP, and dns). Is there a
more
> > > permanent fix for Fedora 10 (upgraded from F9) ?
> >
> > In /etc/sysconfig/network-scripts/ifcfg-eth0
> >
> > I have the line:
> >
> > PEERDNS=no
> >
> > which (in theory) prevents NM from doing anything at all to
> > the resolv.conf file when acting on that interface (of course
> > you then have to make sure you set resolv.conf yourself).
>
> I thought NM had a know bug where it did not yet respect the
PEERDNS=no
> entry.
>
> Has this been fixed?
>
> The only (and most unfortunate) way I have been able to reliably keep
my
> resolf.conf file from getting waxed by NM has been to set it as
> immutable. A _very_ nasty way of doing things, but it does work.
>
> Cheers,
>
> Chris
>
Problem persists. Have had several batches of patches pushed through
yum auto update, but nothing concerning NM to fix this problem.
I set PEERDNS=no with no affect.
I set /etc/resolv.conf to a workable solution and then removed the write
bits and set it immutable. I get errors in /var/log/messages about it,
but the behavior is still the same. After a reboot, all is OK. After a
while, dns dies. Restarting NM brings it back to life...then it dies a
few minutes later. As long as someone is actively accessing the net,
dns seems to stay up. But give it a few minutes of idle time and
something causes it to stop. Here is a snapshot of /var/log/messages
before, during, and after a NM restart. Can anyone figure out what is
going wrong with dns?
Feb 2 21:23:45 desk NetworkManager: <WARN> nm_signal_handler():
Caught signal 15, shutting down normally.
Feb 2 21:23:45 desk NetworkManager: <info> (eth0): now unmanaged Feb
2 21:23:45 desk NetworkManager: <info> (eth0): device state
change: 8 -> 1
Feb 2 21:23:45 desk NetworkManager: <info> (eth0): deactivating device
(reason: 36).
Feb 2 21:23:45 desk NetworkManager: <info> eth0: canceled DHCP
transaction, dhcp client pid 2034 Feb 2 21:23:45 desk NetworkManager:
<WARN>
nm_named_manager_remove_ip4_config(): Could not commit DNS changes.
Error: 'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 21:23:45 desk NetworkManager: <WARN> check_one_route(): (eth0)
error -34 returned from rtnl_route_del(): Sucess#012 Feb 2 21:23:45
desk avahi-daemon[2071]: Withdrawing address record for
192.168.1.2 on eth0.
Feb 2 21:23:45 desk avahi-daemon[2071]: Leaving mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.2.
Feb 2 21:23:45 desk avahi-daemon[2071]: Interface eth0.IPv4 no longer
relevant for mDNS.
Feb 2 21:23:45 desk NetworkManager: <info> (eth0): cleaning up...
Feb 2 21:23:45 desk NetworkManager: <info> (eth0): taking down device.
Feb 2 21:23:45 desk avahi-daemon[2071]: Withdrawing address record for
fe80::207:e9ff:fef2:b64d on eth0.
Feb 2 21:23:45 desk NetworkManager: <info> disconnected by the system
bus.
Feb 2 21:23:45 desk nm-dispatcher.action: Error in get_property: The
name org.freedesktop.NetworkManager was not provided by any .service
files Feb 2 21:23:46 desk NetworkManager: <info> starting...
Feb 2 21:23:46 desk NetworkManager: <WARN>
nm_generic_enable_loopback(): error -17 returned from
rtnl_addr_add():#012Sucess#012
Feb 2 21:23:46 desk NetworkManager: <info> eth0: driver is 'e100'.
Feb 2 21:23:46 desk NetworkManager: <info> Found new Ethernet device
'eth0'.
Feb 2 21:23:46 desk NetworkManager: <info> (eth0): exported as
/org/freedesktop/Hal/devices/net_00_07_e9_f2_b6_4d
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): device state
change: 1 -> 2
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): bringing up device.
Feb 2 21:23:50 desk kernel: e100: eth0: e100_watchdog: link up,
100Mbps, full-duplex Feb 2 21:23:50 desk kernel: ADDRCONF(NETDEV_UP):
eth0: link is not ready Feb 2 21:23:50 desk kernel:
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Feb 2 21:23:50 desk
NetworkManager: <info> (eth0): preparing device.
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): deactivating device
(reason: 2).
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): carrier now ON
(device state 2) Feb 2 21:23:50 desk NetworkManager: <info> (eth0):
device state
change: 2 -> 3
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) starting
connection 'System eth0'
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): device state
change: 3 -> 4
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) scheduled...
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) started...
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) scheduled...
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) complete.
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) starting...
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): device state
change: 4 -> 5
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) successful.
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) scheduled.
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) complete.
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) started...
Feb 2 21:23:50 desk NetworkManager: <info> (eth0): device state
change: 5 -> 7
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Beginning
DHCP transaction.
Feb 2 21:23:50 desk dhclient: Internet Systems Consortium DHCP Client
4.0.0 Feb 2 21:23:50 desk dhclient: Copyright 2004-2007 Internet
Systems Consortium.
Feb 2 21:23:50 desk dhclient: All rights reserved.
Feb 2 21:23:50 desk dhclient: For info, please visit
http://www.isc.org/sw/dhcp/ Feb 2 21:23:50 desk dhclient:
Feb 2 21:23:50 desk NetworkManager: <info> dhclient started with pid
4747
Feb 2 21:23:50 desk dhclient: Listening on LPF/eth0/00:07:e9:f2:b6:4d
Feb 2 21:23:50 desk dhclient: Sending on LPF/eth0/00:07:e9:f2:b6:4d
Feb 2 21:23:50 desk dhclient: Sending on Socket/fallback
Feb 2 21:23:50 desk NetworkManager: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) complete.
Feb 2 21:23:50 desk NetworkManager: <info> DHCP: device eth0 state
changed (null) -> preinit Feb 2 21:23:52 desk dhclient: DHCPDISCOVER on
eth0 to 255.255.255.255 port 67 interval 4 Feb 2 21:23:52 desk
avahi-daemon[2071]: Registering new address record for
fe80::207:e9ff:fef2:b64d on eth0.*.
Feb 2 21:23:53 desk dhclient: DHCPOFFER from 192.168.1.1 Feb 2
21:23:53 desk dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Feb 2 21:23:53 desk dhclient: DHCPACK from 192.168.1.1 Feb 2 21:23:53
desk NetworkManager: <info> DHCP: device eth0 state changed preinit ->
bound Feb 2 21:23:53 desk NetworkManager: <info> Activation (eth0)
Stage 4 of 5 (IP Configure Get) scheduled...
Feb 2 21:23:53 desk NetworkManager: <info> Activation (eth0) Stage 4
of 5 (IP Configure Get) started...
Feb 2 21:23:53 desk NetworkManager: <info> address 192.168.1.2
Feb 2 21:23:53 desk NetworkManager: <info> prefix 24 (255.255.255.0)
Feb 2 21:23:53 desk NetworkManager: <info> gateway 192.168.1.1
Feb 2 21:23:53 desk NetworkManager: <info> hostname 'desk'
Feb 2 21:23:53 desk NetworkManager: <info> nameserver '192.168.1.1'
Feb 2 21:23:53 desk NetworkManager: <info> domain name
'seclab.net'
Feb 2 21:23:53 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) scheduled...
Feb 2 21:23:53 desk NetworkManager: <info> Activation (eth0) Stage 4
of 5 (IP Configure Get) complete.
Feb 2 21:23:53 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) started...
Feb 2 21:23:53 desk avahi-daemon[2071]: Joining mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.2.
Feb 2 21:23:53 desk avahi-daemon[2071]: New relevant interface
eth0.IPv4 for mDNS.
Feb 2 21:23:53 desk avahi-daemon[2071]: Registering new address record
for 192.168.1.2 on eth0.IPv4.
Feb 2 21:23:53 desk dhclient: bound to 192.168.1.2 -- renewal in 80417
seconds.
Feb 2 21:23:54 desk NetworkManager: <WARN>
nm_named_manager_add_ip4_config(): Could not commit DNS changes. Error:
'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 21:23:54 desk NetworkManager: <info> (eth0): device state
change: 7 -> 8
Feb 2 21:23:54 desk NetworkManager: <WARN>
nm_named_manager_add_ip4_config(): Could not commit DNS changes. Error:
'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 21:23:54 desk NetworkManager: <info> Policy set 'System eth0'
(eth0) as default for routing and DNS.
Feb 2 21:23:54 desk NetworkManager: <info> Activation (eth0)
successful, device activated.
Feb 2 21:23:54 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) complete.
Feb 2 22:56:55 desk NetworkManager: <WARN> nm_signal_handler(): Caught
signal 15, shutting down normally.
Feb 2 22:56:55 desk NetworkManager: <info> (eth0): now unmanaged Feb
2 22:56:55 desk NetworkManager: <info> (eth0): device state
change: 8 -> 1
Feb 2 22:56:55 desk NetworkManager: <info> (eth0): deactivating device
(reason: 36).
Feb 2 22:56:55 desk NetworkManager: <info> eth0: canceled DHCP
transaction, dhcp client pid 4747 Feb 2 22:56:55 desk NetworkManager:
<WARN>
nm_named_manager_remove_ip4_config(): Could not commit DNS changes.
Error: 'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 22:56:55 desk NetworkManager: <WARN> check_one_route(): (eth0)
error -34 returned from rtnl_route_del(): Sucess#012 Feb 2 22:56:55
desk avahi-daemon[2071]: Withdrawing address record for
192.168.1.2 on eth0.
Feb 2 22:56:55 desk avahi-daemon[2071]: Leaving mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.2.
Feb 2 22:56:55 desk avahi-daemon[2071]: Interface eth0.IPv4 no longer
relevant for mDNS.
Feb 2 22:56:55 desk NetworkManager: <info> (eth0): cleaning up...
Feb 2 22:56:55 desk NetworkManager: <info> (eth0): taking down device.
Feb 2 22:56:55 desk avahi-daemon[2071]: Withdrawing address record for
fe80::207:e9ff:fef2:b64d on eth0.
Feb 2 22:56:55 desk NetworkManager: <info> disconnected by the system
bus.
Feb 2 22:56:56 desk NetworkManager: <info> starting...
Feb 2 22:56:56 desk NetworkManager: <WARN>
nm_generic_enable_loopback(): error -17 returned from
rtnl_addr_add():#012Sucess#012
Feb 2 22:56:56 desk NetworkManager: <info> eth0: driver is 'e100'.
Feb 2 22:56:56 desk NetworkManager: <info> Found new Ethernet device
'eth0'.
Feb 2 22:56:56 desk NetworkManager: <info> (eth0): exported as
/org/freedesktop/Hal/devices/net_00_07_e9_f2_b6_4d
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): device state
change: 1 -> 2
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): bringing up device.
Feb 2 22:57:00 desk kernel: e100: eth0: e100_watchdog: link up,
100Mbps, full-duplex Feb 2 22:57:00 desk kernel: ADDRCONF(NETDEV_UP):
eth0: link is not ready Feb 2 22:57:00 desk kernel:
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Feb 2 22:57:00 desk
NetworkManager: <info> (eth0): preparing device.
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): deactivating device
(reason: 2).
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): carrier now ON
(device state 2) Feb 2 22:57:00 desk NetworkManager: <info> (eth0):
device state
change: 2 -> 3
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) starting
connection 'System eth0'
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): device state
change: 3 -> 4
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) scheduled...
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) started...
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) scheduled...
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 1
of 5 (Device Prepare) complete.
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) starting...
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): device state
change: 4 -> 5
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) successful.
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) scheduled.
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 2
of 5 (Device Configure) complete.
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) started...
Feb 2 22:57:00 desk NetworkManager: <info> (eth0): device state
change: 5 -> 7
Feb 2 22:57:00 desk NetworkManager: <info> Activation (eth0) Beginning
DHCP transaction.
Feb 2 22:57:00 desk dhclient: Internet Systems Consortium DHCP Client
4.0.0 Feb 2 22:57:00 desk dhclient: Copyright 2004-2007 Internet
Systems Consortium.
Feb 2 22:57:00 desk dhclient: All rights reserved.
Feb 2 22:57:00 desk dhclient: For info, please visit
http://www.isc.org/sw/dhcp/ Feb 2 22:57:00 desk dhclient:
Feb 2 22:57:00 desk NetworkManager: <info> dhclient started with pid
13377
Feb 2 22:57:00 desk dhclient: Listening on LPF/eth0/00:07:e9:f2:b6:4d
Feb 2 22:57:00 desk dhclient: Sending on LPF/eth0/00:07:e9:f2:b6:4d
Feb 2 22:57:00 desk dhclient: Sending on Socket/fallback
Feb 2 22:57:00 desk dhclient: DHCPDISCOVER on eth0 to 255.255.255.255
port 67 interval 6 Feb 2 22:57:00 desk NetworkManager: <info>
Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Feb 2 22:57:00 desk NetworkManager: <info> DHCP: device eth0 state
changed (null) -> preinit Feb 2 22:57:01 desk avahi-daemon[2071]:
Registering new address record for fe80::207:e9ff:fef2:b64d on eth0.*.
Feb 2 22:57:02 desk dhclient: DHCPOFFER from 192.168.1.1 Feb 2
22:57:02 desk dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Feb 2 22:57:02 desk dhclient: DHCPACK from 192.168.1.1 Feb 2 22:57:02
desk NetworkManager: <info> DHCP: device eth0 state changed preinit ->
bound Feb 2 22:57:02 desk NetworkManager: <info> Activation (eth0)
Stage 4 of 5 (IP Configure Get) scheduled...
Feb 2 22:57:02 desk NetworkManager: <info> Activation (eth0) Stage 4
of 5 (IP Configure Get) started...
Feb 2 22:57:02 desk NetworkManager: <info> address 192.168.1.2
Feb 2 22:57:02 desk NetworkManager: <info> prefix 24 (255.255.255.0)
Feb 2 22:57:02 desk NetworkManager: <info> gateway 192.168.1.1
Feb 2 22:57:02 desk NetworkManager: <info> hostname 'desk'
Feb 2 22:57:02 desk NetworkManager: <info> nameserver '192.168.1.1'
Feb 2 22:57:02 desk NetworkManager: <info> domain name
'seclab.net'
Feb 2 22:57:02 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) scheduled...
Feb 2 22:57:02 desk NetworkManager: <info> Activation (eth0) Stage 4
of 5 (IP Configure Get) complete.
Feb 2 22:57:02 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) started...
Feb 2 22:57:02 desk avahi-daemon[2071]: Joining mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.2.
Feb 2 22:57:02 desk avahi-daemon[2071]: New relevant interface
eth0.IPv4 for mDNS.
Feb 2 22:57:02 desk avahi-daemon[2071]: Registering new address record
for 192.168.1.2 on eth0.IPv4.
Feb 2 22:57:02 desk dhclient: bound to 192.168.1.2 -- renewal in 84449
seconds.
Feb 2 22:57:03 desk NetworkManager: <WARN>
nm_named_manager_add_ip4_config(): Could not commit DNS changes. Error:
'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 22:57:03 desk NetworkManager: <info> (eth0): device state
change: 7 -> 8
Feb 2 22:57:03 desk NetworkManager: <WARN>
nm_named_manager_add_ip4_config(): Could not commit DNS changes. Error:
'Could not replace /etc/resolv.conf: Operation not permitted#012'
Feb 2 22:57:03 desk NetworkManager: <info> Policy set 'System eth0'
(eth0) as default for routing and DNS.
Feb 2 22:57:03 desk NetworkManager: <info> Activation (eth0)
successful, device activated.
Feb 2 22:57:03 desk NetworkManager: <info> Activation (eth0) Stage 5
of 5 (IP Configure Commit) complete.
[root at desk ~]#
The error message concerning /etc/resolv.conf is due to the removal of
write bit and setting it immutable. NM does create a file called
/etc/resolv.conf.tmp which appears to be a copy of my immutable
resolv.conf.
Dave McGuffey
Principal Information System Security Engineer // NSA-IEM, NSA-IAM
Save a Tree...Unless necessary don't print this e-mail
More information about the fedora-list
mailing list