[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]

Re: F10, NetworkManager, and intermittent dns -- Update



On Date: Tue, 3 Feb 2009 15:59:25 -0500, McGuffey, David C. wrote:
>
> 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 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.
>

Found another set of errors.  Could this be the root cause of my dns
problem?  I hear that NM relies on the keyring...at least for wireless.
I'm not running wireless on this box, and not running NFS. This is a
plain install of an F10 development load.

Feb  4 07:14:59 desk gdm-session-worker[7681]: gnome-keyring-daemon:
couldn't lookup keyring component setting: Failed to contact
configuration server; some possible causes are that you need to enable
TCP/IP networking for ORBit, or you have stale NFS locks due to a system
crash. See http://www.gnome.org/projects/gconf/ for information.
(Details -  1: Not running within active session)gnome-keyring-daemon:
couldn't lookup ssh component setting: Failed to contact configuration
server; some possible causes are that you need to enable TCP/IP
networking for ORBit, or you have stale NFS locks due to a system crash.
See http://www.gnome.org/projects/gconf/ for information. (Details -  1:
Not running within active session)gnome-keyring-daemon: couldn't lookup
pkcs11 component setting: Failed to contact configuration server; some
possible causes are that you need to enable TCP/IP networking for ORBit,
or you have stale NFS locks due to a system crash. See
http://www.gnome.org/projects/gconf/ for information. (Details -  1: Not
running within active session)

Dave McGuffey
Principal Information System Security Engineer // NSA-IEM, NSA-IAM
Save a Tree...Unless necessary don't print this e-mail



[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]