Bug 473785 - NetworkManager generates useless /etc/resolv.conf
Summary: NetworkManager generates useless /etc/resolv.conf
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 10
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-11-30 15:50 UTC by Joachim Backes
Modified: 2009-10-15 04:06 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-10-15 04:06:57 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Joachim Backes 2008-11-30 15:50:01 UTC
Description of problem:
NetworkManager generates a useless /etc/resolv.conf without a nameserver entry:
--------------- snip -------------------
# Generated by NetworkManager
domain Speedport_W_700V
search Speedport_W_700V


# No nameservers found; try putting DNS servers into your
# ifcfg files in /etc/sysconfig/network-scripts like so:
#
# DNS1=xxx.xxx.xxx.xxx
# DNS2=xxx.xxx.xxx.xxx
# DOMAIN=lab.foo.com bar.foo.com

----------------- snip ------------------

Version-Release number of selected component (if applicable):
NetworkManager-0.7.0-0.12.svn4326.fc10.i386

How reproducible:
each time

Steps to Reproduce:
1./etc/init.d/NetworkManager start
2.
3.
  
Actual results:
see above

Expected results:
nameserver entry in /etc/resolv.conf: 
nameserver 192.168.179.1

Additional info:
Output of NetworkManager --no-daemon
-------------------- snip --------------------
NetworkManager: <info>  starting...
-- Error received: File exists
-- Original message: type=0x14 length=56 flags=<REQUEST,ACK,ATOMIC> sequence-nr=1228059533 pid=4198936
NetworkManager: <WARN>  nm_generic_enable_loopback(): error -17 returned from rtnl_addr_add():
Sucess

NetworkManager: nm_device_ethernet_new: assertion `driver != NULL' failed
NetworkManager: nm_device_ethernet_new: assertion `driver != NULL' failed
NetworkManager: <info>  eth0: driver is 'forcedeth'.
NetworkManager: <info>  Found new Ethernet device 'eth0'.
NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_0c_76_c0_40_36
NetworkManager: <info>  Trying to start the supplicant...
NetworkManager: <info>  (eth0): carrier now ON (device state 1)
NetworkManager: <info>  (eth0): device state change: 1 -> 2
NetworkManager: <info>  (eth0): preparing device.
NetworkManager: <info>  (eth0): deactivating device (reason: 2).
-- Error received: Numerical result out of range
-- Original message: type=0x19 length=56 flags=<REQUEST,ACK> sequence-nr=1228059544 pid=4198936
NetworkManager: <WARN>  check_one_route(): (eth0) error -34 returned from rtnl_route_del(): Sucess

NetworkManager: <info>  (eth0): device state change: 2 -> 3
NetworkManager: <info>  Activation (eth0) starting connection 'System eth0'
NetworkManager: <info>  (eth0): device state change: 3 -> 4
NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (eth0): device state change: 4 -> 5
NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) successful.
NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager: <info>  (eth0): device state change: 5 -> 7
NetworkManager: <info>  Activation (eth0) Beginning DHCP transaction.
Internet Systems Consortium DHCP Client 4.0.0
Copyright 2004-2007 Internet Systems Consortium.
All rights reserved.
For info, please visit http://www.isc.org/sw/dhcp/

NetworkManager: <info>  dhclient started with pid 4635
NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Listening on LPF/eth0/00:0c:76:c0:40:36
Sending on   LPF/eth0/00:0c:76:c0:40:36
Sending on   Socket/fallback
NetworkManager: <info>  DHCP: device eth0 state changed (null) -> preinit
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPOFFER from 192.168.179.1
DHCPREQUEST on eth0 to 255.255.255.255 port 67
DHCPACK from 192.168.179.1
NetworkManager: <info>  DHCP: device eth0 state changed preinit -> bound
NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
NetworkManager: <info>    address 192.168.179.107
NetworkManager: <info>    prefix 24 (255.255.255.0)
NetworkManager: <info>    gateway 192.168.179.1
NetworkManager: <info>    nameserver '192.168.179.1'
NetworkManager: <info>    domain name 'Speedport_W_700V'
NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
bound to 192.168.179.107 -- renewal in 138326 seconds.nameserver '192.168.179.1'
Stopping nscd: [  OK  ]
Starting nscd: [  OK  ]
NetworkManager: <info>  (eth0): device state change: 7 -> 8
Stopping nscd: [  OK  ]
Starting nscd: [  OK  ]
NetworkManager: <info>  Policy set 'System eth0' (eth0) as default for routing and DNS.
NetworkManager: <info>  Activation (eth0) successful, device activated.
NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
---------------------- snip ---------------------------

Comment 1 yrtimiD 2008-12-11 20:30:52 UTC
I confirm this bug. Have same behavior.
versions:
NetworkManager-0.7.0-0.12.svn4326.fc10.i386
dhcp-4.0.0-33.fc10.i386
dhclient-4.0.0-33.fc10.i386

output of /var/log/messages after "service NetworkManager start":
Dec 11 22:23:18 localhost NetworkManager: <info>  starting...                                                                
Dec 11 22:23:18 localhost NetworkManager: <WARN>  nm_generic_enable_loopback(): error -17 returned from rtnl_addr_add():#012Sucess#012                                                                                                                    
Dec 11 22:23:18 localhost NetworkManager: <info>  eth1: driver is '8139too'.                                                 
Dec 11 22:23:18 localhost NetworkManager: <info>  Found new Ethernet device 'eth1'.                                          
Dec 11 22:23:18 localhost NetworkManager: <info>  (eth1): exported as /org/freedesktop/Hal/devices/net_00_00_21_f3_2a_b7     
Dec 11 22:23:18 localhost NetworkManager: <info>  eth0: driver is '8139too'.                                                 
Dec 11 22:23:18 localhost NetworkManager: <info>  Found new Ethernet device 'eth0'.                                          
Dec 11 22:23:18 localhost NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_00_21_f3_2a_b4     
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): device state change: 1 -> 2                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): bringing up device.                                                
Dec 11 22:23:22 localhost kernel: eth1: link up, 100Mbps, full-duplex, lpa 0xC5E1                                            
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): preparing device.                                                  
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): deactivating device (reason: 2).                                   
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): carrier now ON (device state 2)                                    
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): device state change: 2 -> 3                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) starting connection 'System eth1'                        
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): device state change: 3 -> 4                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...               
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): device state change: 1 -> 2                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): bringing up device.                                                
Dec 11 22:23:22 localhost kernel: eth0: link up, 100Mbps, full-duplex, lpa 0x45E1                                            
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): preparing device.                                                  
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): deactivating device (reason: 2).                                   
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): carrier now ON (device state 2)                                    
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): device state change: 2 -> 3                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) started...                 
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...             
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) complete.                  
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) starting connection 'System eth0'                        
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): device state change: 3 -> 4                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...               
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) starting...              
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): device state change: 4 -> 5                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) successful.              
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.             
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) complete.                
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...                 
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...             
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.                  
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) started...             
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth1): device state change: 5 -> 7                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) scheduled...             
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.              
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...              
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): device state change: 4 -> 5                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) successful.              
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.             
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.                
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) started...               
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) scheduled...          
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) complete.                
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...             
Dec 11 22:23:22 localhost NetworkManager: <info>  (eth0): device state change: 5 -> 7                                        
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Beginning DHCP transaction.                              
Dec 11 22:23:22 localhost dhclient: Internet Systems Consortium DHCP Client 4.0.0                                            
Dec 11 22:23:22 localhost NetworkManager: <info>  dhclient started with pid 12296                                            
Dec 11 22:23:22 localhost dhclient: Copyright 2004-2007 Internet Systems Consortium.                                         
Dec 11 22:23:22 localhost dhclient: All rights reserved.                                                                     
Dec 11 22:23:22 localhost dhclient: For info, please visit http://www.isc.org/sw/dhcp/                                       
Dec 11 22:23:22 localhost dhclient:                                                                                          
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.              
Dec 11 22:23:22 localhost NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) started...            
Dec 11 22:23:22 localhost dhclient: Listening on LPF/eth0/00:00:21:f3:2a:b4                                                  
Dec 11 22:23:22 localhost dhclient: Sending on   LPF/eth0/00:00:21:f3:2a:b4                                                  
Dec 11 22:23:22 localhost dhclient: Sending on   Socket/fallback                                                             
Dec 11 22:23:23 localhost NetworkManager: <info>  (eth1): device state change: 7 -> 8                                        
Dec 11 22:23:23 localhost NetworkManager: <info>  Policy set 'System eth1' (eth1) as default for routing and DNS.            
Dec 11 22:23:23 localhost NetworkManager: <info>  Activation (eth1) successful, device activated.                            
Dec 11 22:23:23 localhost NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) complete.             
Dec 11 22:23:23 localhost NetworkManager: <info>  DHCP: device eth0 state changed (null) -> preinit                          
Dec 11 22:23:24 localhost dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7                               
Dec 11 22:23:24 localhost dhclient: DHCPOFFER from 10.163.128.1
Dec 11 22:23:24 localhost dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Dec 11 22:23:24 localhost dhclient: DHCPACK from 10.163.128.1
Dec 11 22:23:24 localhost dhclient: bound to 84.XXX.XXX.190 -- renewal in 34583 seconds.
Dec 11 22:23:24 localhost NetworkManager: <info>  DHCP: device eth0 state changed preinit -> bound
Dec 11 22:23:24 localhost NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Dec 11 22:23:24 localhost NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Dec 11 22:23:24 localhost NetworkManager: <info>    address 84.XXX.XXX.190
Dec 11 22:23:24 localhost NetworkManager: <info>    prefix 22 (255.255.252.0)
Dec 11 22:23:24 localhost NetworkManager: <info>    gateway 84.XXX.XXX.1
Dec 11 22:23:24 localhost NetworkManager: <info>    hostname 'yserver'
Dec 11 22:23:24 localhost NetworkManager: <info>    nameserver '192.117.235.235'
Dec 11 22:23:24 localhost NetworkManager: <info>    nameserver '62.219.186.7'
Dec 11 22:23:24 localhost NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Dec 11 22:23:24 localhost NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Dec 11 22:23:24 localhost NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Dec 11 22:23:25 localhost NetworkManager: <info>  Policy set 'System eth1' (eth1) as default for routing and DNS.
Dec 11 22:23:25 localhost NetworkManager: <info>  (eth0): device state change: 7 -> 8
Dec 11 22:23:25 localhost NetworkManager: <info>  Activation (eth0) successful, device activated.
Dec 11 22:23:25 localhost NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.


resolv.conf after "start" finished:
# No nameservers found; try putting DNS servers into your
# ifcfg files in /etc/sysconfig/network-scripts like so:
#
# DNS1=xxx.xxx.xxx.xxx
# DNS2=xxx.xxx.xxx.xxx
# DOMAIN=lab.foo.com bar.foo.com

Comment 2 Lou 2009-01-11 08:12:58 UTC
I also have problem with NetworkManager to create a usable /etc/resolv.conf when /etc/sysconf/readonly-root is modified with TEMPORARY_STATE="yes". The problem seems to be NetworkManager attempt to create a temporary file called /etc/resolv.conf.tmp first then copies it back to the bind-mounted /etc/resolv.conf which is causing a device busy kind of error. I haven't looked into the source code of NetworkManager but I have similar problems with /etc/mtab under fuse/zfs-fuse which is also trying to mv /etc/mtab.tmp to /etc/mtab which is also bind-mounted to the /var/lib/stateless/writable/etc/mtab. When I unmount zfs filesystems, it will emit error messages telling me unable to rename /etc/mtab.tmp to /etc/mtab because the device is busy. I think change the mv to cat with a redirection to the bind-mounted file will solve these problems.

Comment 3 Joachim Backes 2009-01-11 08:24:02 UTC
The problem in my box seems to be another one:

cat /etc/sysconfig/readonly-root
----------------------------- snip ----------------------
# Set to 'yes' to mount the system filesystems read-only.
READONLY=no
# Set to 'yes' to mount various temporary state as either tmpfs
# or on the block device labelled RW_LABEL. Implied by READONLY
TEMPORARY_STATE=no
# Place to put a tmpfs for temporary scratch writable space
RW_MOUNT=/var/lib/stateless/writable
# Label on local filesystem which can be used for temporary scratch space
RW_LABEL=stateless-rw
# Options to use for temporary mount
RW_OPTIONS=
# Label for partition with persistent data
STATE_LABEL=stateless-state
# Where to mount to the persistent data
STATE_MOUNT=/var/lib/stateless/state
# Options to use for peristent mount
STATE_OPTIONS=
---------------------- snap ------------------------------

Comment 4 Lou 2009-01-11 21:53:22 UTC
Then, do I need to file another bug report?

Comment 5 Dan Williams 2009-02-13 12:46:09 UTC
(In reply to comment #3)
> The problem in my box seems to be another one:
> 
> cat /etc/sysconfig/readonly-root
> ----------------------------- snip ----------------------
> # Set to 'yes' to mount the system filesystems read-only.
> READONLY=no
> # Set to 'yes' to mount various temporary state as either tmpfs
> # or on the block device labelled RW_LABEL. Implied by READONLY
> TEMPORARY_STATE=no
> # Place to put a tmpfs for temporary scratch writable space
> RW_MOUNT=/var/lib/stateless/writable
> # Label on local filesystem which can be used for temporary scratch space
> RW_LABEL=stateless-rw
> # Options to use for temporary mount
> RW_OPTIONS=
> # Label for partition with persistent data
> STATE_LABEL=stateless-state
> # Where to mount to the persistent data
> STATE_MOUNT=/var/lib/stateless/state
> # Options to use for peristent mount
> STATE_OPTIONS=
> ---------------------- snap ------------------------------

Is /etc/ mounted as a tmpfs or something like that?

Comment 6 Niels Haase 2009-04-10 20:34:54 UTC
Reporter, could you please reply to the previous question? If you won't reply in one month, I will have to close this bug as INSUFFICIENT_DATA. Thank you.

-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 7 Joachim Backes 2009-04-11 06:00:42 UTC
1. No, /etc/ is not mounted as tmpfs or something other.
2. Since some NetworkManager versions, my /etc/resolv.conf is OK (I reported this already to another thread).

Comment 8 Dan Williams 2009-10-15 04:06:57 UTC
Ok, thanks for the report.  Please let us know if this happens again!


Note You need to log in before you can comment on or make changes to this bug.