Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 345365 - >=net-misc/networkmanager-0.8.1 does not work with dhcpcd in daemon mode
Summary: >=net-misc/networkmanager-0.8.1 does not work with dhcpcd in daemon mode
Status: RESOLVED TEST-REQUEST
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: New packages (show other bugs)
Hardware: All Linux
: High normal
Assignee: Robert Piasek (RETIRED)
URL:
Whiteboard:
Keywords:
Depends on: 252137
Blocks:
  Show dependency tree
 
Reported: 2010-11-14 08:37 UTC by Xake
Modified: 2012-04-06 15:14 UTC (History)
5 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Xake 2010-11-14 08:37:30 UTC
So what is wrong with this picture:

Nov 14 09:13:42 lillen NetworkManager[7525]: <info> NetworkManager (version 0.8.2) is starting...
Nov 14 09:13:42 lillen NetworkManager[7525]: <info> trying to start the modem manager...
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> monitoring kernel firmware directory '/lib/firmware'.
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> WiFi enabled by radio killswitch; enabled by state file
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> WWAN enabled by radio killswitch; enabled by state file
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> WiMAX enabled by radio killswitch; enabled by state file
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> Networking is enabled by state file
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): carrier is OFF
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): new Ethernet device (driver: 'sky2' ifindex: 2)
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): now managed
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): device state change: 1 -> 2 (reason 2)
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): preparing device.
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth0): deactivating device (reason: 2).
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> Added default wired connection 'Auto eth0' for /sys/devices/pci0000:00/0000:00:1c.2/0000:06:00.0/net/eth0
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): carrier is OFF
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): new Ethernet device (driver: 'sky2' ifindex: 3)
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/1
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): now managed
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): device state change: 1 -> 2 (reason 2)
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): preparing device.
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> (eth1): deactivating device (reason: 2).
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> Added default wired connection 'Auto eth1' for /sys/devices/pci0000:00/0000:00:1c.5/0000:04:00.0/net/eth1
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> modem-manager is now available
Nov 14 09:13:43 lillen NetworkManager[7525]: <warn> bluez error getting default adapter: The name org.bluez was not provided by any .service files
Nov 14 09:13:43 lillen NetworkManager[7525]: <info> Trying to start the supplicant...
Nov 14 09:13:44 lillen NetworkManager[7525]: <warn> bluez error getting default adapter: No such adapter
Nov 14 09:13:44 lillen avahi-daemon[8165]: Network interface enumeration completed.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): carrier now ON (device state 2)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 2 -> 3 (reason 40)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) starting connection 'Auto eth0'
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 3 -> 4 (reason 0)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 4 -> 5 (reason 0)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 5 -> 7 (reason 0)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> dhcpcd started with pid 8197
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): DHCPv4 client pid 8197 exited with status 0
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) started...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) complete.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) failed (no IP configuration found)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 7 -> 9 (reason 5)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Marking connection 'Auto eth0' invalid.
Nov 14 09:13:44 lillen NetworkManager[7525]: <warn> Activation (eth0) failed.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): device state change: 9 -> 3 (reason 0)
Nov 14 09:13:44 lillen NetworkManager[7525]: <info> (eth0): deactivating device (reason: 0).
Nov 14 09:13:46 lillen NetworkManager[7525]: <error> [1289722427.708] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Nov 14 09:14:04 lillen NetworkManager[7525]: <error> [1289722444.329145] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Nov 14 09:14:04 lillen NetworkManager[7525]: <error> [1289722444.329397] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Nov 14 09:14:04 lillen NetworkManager[7525]: <error> [1289722444.329619] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Nov 14 09:14:04 lillen NetworkManager[7525]: <error> [1289722444.329854] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Nov 14 09:14:04 lillen NetworkManager[7525]: <error> [1289722444.330142] [nm-manager.c:1368] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
xake@lillen ~ $ sudo ifconfig
eth0      Link encap:Ethernet  HWaddr 00:24:8c:f8:1f:5e  
          inet addr:192.168.1.80  Bcast:192.168.1.255  Mask:255.255.255.0
          inet6 addr: fe80::224:8cff:fef8:1f5e/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1244 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1768 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:223639 (218.3 KiB)  TX bytes:438154 (427.8 KiB)
          Interrupt:18 



As you see NetworkManager thinks it fails to setup a network connection (and the tray icon confirms this, and every program that asks NetworkManager if I am connected).
If I try to connect with the help of the icon, I get a messages directly from the trayicon suggesting it failed, and the connection is dropped.

I have tried bot 0.8.1 and 0.8.2 in portage.

I know that there may be much more info you need, so please ask for it.

$ emerge --info
Portage 2.2.0_alpha4 (hardened/linux/amd64/10.0, gcc-4.4.5, glibc-2.12.1-r3, 2.6.36-hardened x86_64)
=================================================================
System uname: Linux-2.6.36-hardened-x86_64-Intel-R-_Core-TM-_i7_CPU_920_@_2.67GHz-with-gentoo-2.0.1
Timestamp of tree: Sat, 13 Nov 2010 15:30:01 +0000
distcc 3.1 x86_64-pc-linux-gnu [disabled]
ccache version 2.4 [disabled]
app-shells/bash:     4.1_p9
dev-java/java-config: 2.1.11-r2
dev-lang/python:     2.6.6-r1, 3.1.2-r4::Mine!
dev-util/ccache:     2.4-r8
dev-util/cmake:      2.8.1-r2
sys-apps/baselayout: 2.0.1-r1
sys-apps/openrc:     0.6.3
sys-apps/sandbox:    2.3-r1
sys-devel/autoconf:  2.13, 2.68
sys-devel/automake:  1.9.6-r3, 1.10.3, 1.11.1
sys-devel/binutils:  2.20.1-r1
sys-devel/gcc:       4.4.5
sys-devel/gcc-config: 1.4.1
sys-devel/libtool:   2.4
sys-devel/make:      3.82
virtual/os-headers:  2.6.35 (sys-kernel/linux-headers)
Repositories: gentoo hardened-dev gamerlay-stable x11 mozilla gnome Mine
ACCEPT_KEYWORDS="amd64 ~amd64"
ACCEPT_LICENSE="*"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=native -O2 -pipe -ggdb -mtune=native"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo /etc/texmf/language.dat.d /etc/texmf/language.def.d /etc/texmf/updmap.d /etc/texmf/web2c"
CXXFLAGS="-march=native -O2 -pipe -ggdb -mtune=native"
DISTDIR="/var/portage/distfiles"
FEATURES="assume-digests binpkg-logs buildpkg distlocks fixlafiles fixpackages metadata-transfer news parallel-fetch preserve-libs protect-owned sandbox sfperms splitdebug strict test unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox"
GENTOO_MIRRORS="ftp://ftp.sunet.se/pub/os/Linux/distributions/gentoo"
INSTALL_MASK="*.la"
LANG="sv_SE.UTF-8"
LC_ALL="C"
LDFLAGS="-Wl,--as-needed -Wl,-O1 -Wl,--sort-common -Wl,--warn-once,--hash-style=gnu"
LINGUAS="sv en"
MAKEOPTS="-j10 -l10"
PKGDIR="/var/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/var/portage"
PORTDIR_OVERLAY="/var/overlays/layman/hardened-development /var/overlays/layman/gamerlay /var/overlays/layman/x11 /var/overlays/layman/mozilla /var/overlays/layman/gnome /var/overlays/mine"
SYNC="rsync://liten.csbnet.se/gentoo-portage"
USE="X a52 aac accessibility acl acpi alsa amd64 amr amrnb amrwb applet archive asyncns auto-hinter avahi bash-completion bluetooth branding bzip2 cairo ccache cdaudio cdda cdr cleartype cli connection-sharing consolekit coverart cracklib crypt cups cxx dbus device-mapper devicekit devkit dhcpcd digitalradio djvu dri dts dvd dvdr dvi eds enca encode eselect evo exif faac faad fat fbcondecor ffmpeg fftw flac fontconfig fuse gdbm gdm gdu gif gimp glib gmp gnome gnome-keyring gphoto2 gpm grammar graphite gsf gsm gstreamer gtk gudev hardened hpn ical iconv iconvacl icq icu id3tag idn ieee1394 iptc ipv6 ithreads jabber jack java6 jingle jpeg jpeg2k justify kate kvm lcms libffi libnotify libsamplerate logrotate lvm lvm2 lzma mad maps math matroska md mdadm midi mms mmx mmxext mng moonlight mp2 mp3 mpeg mpi msn mtp mudflap multilib musepack musicbrainz nautilus ncurses network-cron networkmanager nfs nls nntp nptl nptlonly ntfs ntp offensive ogg openal opencore-amr opengl openmp openntpd ots pam pango parted pcre pdf perl pic pidgin playlist png policykit pppd pulseaudio python quicktime raw readline rrdcgi rtmp samba schroedinger sensord session smp sms speex spell sse sse2 sse3 ssl ssse3 startup-notification subversion svg sysfs test tex theora thesaurus threads tiff totem truetype udev unicode upnp urandom usb userlocales v4l2 vaapi vhook videos vim-syntax vorbis webkit wmf x264 xcb xcomposite xmp xmpp xorg xrandr xscreensaver xulrunner xv xvid xvmc zeroconf zlib" ALSA_CARDS="hda-intel" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ubx" INPUT_DEVICES="evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LINGUAS="sv en" PHP_TARGETS="php5-2" QEMU_SOFTMMU_TARGETS="i386 x86_64" QEMU_USER_TARGETS="i386 x86_64" RUBY_TARGETS="ruby18" USERLAND="GNU" VIDEO_CARDS="nouveau" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account" 
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, FFLAGS, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
Comment 1 Xake 2010-11-14 08:43:07 UTC
Forgot to add that this happends most of the time, but sometimes after a reboot or two NetworkManager handles it fine.

Also worth knowing is that I have emptied /etc/conf.d/net except for some comments, and there are no residual files in /etc/NetworkManager{,system-connection} so there should not be anything there making life harder.
Comment 2 Mu Qiao (RETIRED) gentoo-dev 2010-11-19 01:28:11 UTC
I see that NM could not get owner of name 'org.freedesktop.NetworkManagerUserSettings', so have you checked your dbus settings? Is it working fine? And could you show your /etc/dbus-1/system.d/NetworkManager.conf
Comment 3 Xake 2010-11-22 07:46:58 UTC
(In reply to comment #2)
> I see that NM could not get owner of name
> 'org.freedesktop.NetworkManagerUserSettings', so have you checked your dbus
> settings? Is it working fine? And could you show your
> /etc/dbus-1/system.d/NetworkManager.conf
> 

My /etc/dbus/system.d/{nm-*,NetworkManager}.conf files are the stock ones installed by portage.
Now this morning when I started my computer nm showed this problem. just rebooting and everything works fine again.
That "<error>" is there even now currently when NetworkManager starts as it should.

By the way:
I have a script in /etc/NetworkManager/dispatcher.d that when a connection is made should among other things mount a nfs share. This mount does not happen those times nm-applet says the connection failed, so it seems like it is the daemon itself that has the problems, and not just communication between the deamon and the gnome applet.
Comment 4 Xake 2010-11-28 14:59:42 UTC
Can this be some what of a timeout being to short, resulting in a race?

If I "/etc/init.d/NetworkManager restart" when experience the problem, then the following happends, and as you can see NetworkManager gives up on finding a IP configuration in less then a second, while dhcpcd got an aknowledge about 4 seconds later:

Nov 28 15:54:43 lillen NetworkManager[8941]: <info> NetworkManager (version 0.8.2) is starting...
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> Read config file /etc/NetworkManager/nm-system-settings.conf
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> modem-manager is now available
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> monitoring kernel firmware directory '/lib/firmware'.
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Initializing!
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: management mode: managed
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Monitoring /etc/conf.d/hostname
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Monitoring /etc/conf.d/net
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Can't open /etc/wpa_supplicant/wpa_supplicant.conf for wireless security
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Loading connections
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Updating hostname
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Hostname updated to: lillen
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: Initialzation complete!
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> Loaded plugin ifnet: (C) 1999-2010 Gentoo Foundation, Inc. To report bugs please use bugs.gentoo.org with [networkmanager] or [dagger] prefix.
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: getting unmanaged specs...
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: (-795750400) ... get_connections.
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: (-795750400) connections count: 0
Nov 28 15:54:43 lillen NetworkManager[8941]:    keyfile: parsing .keep_net-misc_networkmanager-0 ... 
Nov 28 15:54:43 lillen NetworkManager[8941]:    keyfile:     error: File permissions (100644) or owner (0) were insecure
Nov 28 15:54:43 lillen NetworkManager[8941]:    keyfile: parsing Auto eth0 ... 
Nov 28 15:54:43 lillen NetworkManager[8941]:    keyfile:     read connection 'Auto eth0'
Nov 28 15:54:43 lillen NetworkManager[8941]:    SCPlugin-Ifnet: getting unmanaged specs...
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> WiFi enabled by radio killswitch; enabled by state file
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> WWAN enabled by radio killswitch; enabled by state file
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> WiMAX enabled by radio killswitch; enabled by state file
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> Networking is enabled by state file
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): carrier is OFF
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): new Ethernet device (driver: 'sky2' ifindex: 2)
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): now managed
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): device state change: 1 -> 2 (reason 2)
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): bringing up device.
Nov 28 15:54:43 lillen dhcpcd[8087]: eth0: carrier acquired
Nov 28 15:54:43 lillen dhcpcd[8087]: eth0: carrier lost
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): preparing device.
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth0): deactivating device (reason: 2).
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): carrier is OFF
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): new Ethernet device (driver: 'sky2' ifindex: 3)
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/1
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): now managed
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): device state change: 1 -> 2 (reason 2)
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): bringing up device.
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): preparing device.
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> (eth1): deactivating device (reason: 2).
Nov 28 15:54:43 lillen NetworkManager[8941]: <info> Added default wired connection 'Auto eth1' for /sys/devices/pci0000:00/0000:00:1c.5/0000:04:00.0/net/eth1
Nov 28 15:54:43 lillen dhcpcd[8087]: eth0: waiting for carrier
Nov 28 15:54:43 lillen NetworkManager[8941]: <warn> bluez error getting default adapter: The name org.bluez was not provided by any .service files
Nov 28 15:54:46 lillen dhcpcd[8087]: eth0: carrier acquired
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): carrier now ON (device state 2)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 2 -> 3 (reason 40)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) starting connection 'Auto eth0'
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 3 -> 4 (reason 0)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 4 -> 5 (reason 0)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 5 -> 7 (reason 0)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> dhcpcd started with pid 8969
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Nov 28 15:54:46 lillen dhcpcd[8969]: sending commands to master dhcpcd process
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): DHCPv4 client pid 8969 exited with status 0
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) started...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) complete.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) failed (no IP configuration found)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 7 -> 9 (reason 5)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Marking connection 'Auto eth0' invalid.
Nov 28 15:54:46 lillen NetworkManager[8941]: <warn> Activation (eth0) failed.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): device state change: 9 -> 3 (reason 0)
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): deactivating device (reason: 0).
Nov 28 15:54:46 lillen dhcpcd[8087]: eth0: rebinding lease of 192.168.1.80
Nov 28 15:54:46 lillen dhcpcd[8087]: control command: /sbin/dhcpcd -B -K -L -c /usr/libexec/nm-dhcp-client.action eth0
Nov 28 15:54:47 lillen avahi-daemon[8013]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::224:8cff:fef8:1f5e.
Nov 28 15:54:47 lillen avahi-daemon[8013]: New relevant interface eth0.IPv6 for mDNS.
Nov 28 15:54:47 lillen avahi-daemon[8013]: Registering new address record for fe80::224:8cff:fef8:1f5e on eth0.*.
Nov 28 15:54:50 lillen dhcpcd[8087]: eth0: acknowledged 192.168.1.80 from 192.168.1.5
Nov 28 15:54:50 lillen dhcpcd[8087]: eth0: checking for 192.168.1.80
Nov 28 15:54:55 lillen dhcpcd[8087]: eth0: leased 192.168.1.80 for infinity
Nov 28 15:54:55 lillen avahi-daemon[8013]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.80.
Nov 28 15:54:55 lillen avahi-daemon[8013]: New relevant interface eth0.IPv4 for mDNS.
Nov 28 15:54:55 lillen avahi-daemon[8013]: Registering new address record for 192.168.1.80 on eth0.IPv4.
Comment 5 Xake 2010-11-29 12:20:57 UTC
This seems to happen with the dhcpcd backend, if I change the useflags to "-dhcpcd dhclient" then networkmanager works with just a "/etc/init.d/NetworkManager restart" and no further problems has been noticed...
Comment 6 Robert Piasek (RETIRED) gentoo-dev 2010-11-29 17:27:45 UTC
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> dhcpcd started with pid
8969
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> Activation (eth0) Stage 3
of 5 (IP Configure Start) complete.
Nov 28 15:54:46 lillen dhcpcd[8969]: sending commands to master dhcpcd process
Nov 28 15:54:46 lillen NetworkManager[8941]: <info> (eth0): DHCPv4 client pid
8969 exited with status 0

That would suggest you have dhcpcd and dhclient4 installed. You should only use one of them. If you prefer dhcpcd, please remove dhclient. Alternatively rebuild networkmanger without dhcpcd support (that's what you already tested and it worked for you).
Comment 7 Xake 2010-11-30 05:17:12 UTC
(In reply to comment #6)
> That would suggest you have dhcpcd and dhclient4 installed. You should only use
> one of them.

First, would it not be great if you somehow could have both installed and choose between implementation in, say /etc/conf.d/NetworkManager or /etc/conf.d/net?

Secondly, from the beginning net-misc/dhcp was not installed on my computer (and I just retested without that packkage to make sure I did not had a stale dhcliet* on it either), and retesting now (i.e. change userflags back, emerge -C net-misc/dhcp, remerge networkmanager in that order) those lines still shows up in my /var/log/daemon.log every time I restart NetworkManager, so what files do nm use to detect dhclient*?
Comment 8 Xake 2010-11-30 05:21:54 UTC
(In reply to comment #7)

Forgot to clarify that in short even without net-misc/dhcp on my computer those lines shows up, and NetworkManager fails.
Comment 9 Xake 2010-11-30 05:41:54 UTC
Also, when I lookd into the build log:

<snip>
Distribution target: gentoo
if this is not correct, please specifiy your distro with --with-distro=DISTRO

ISC dhclient support: no
dhcpcd support: /sbin/dhcpcd
systemd support: no

Building documentation: no
Building tests: no

>>> Source configured.

so even if the code is built without dhclient support it looks for dhclient?
Comment 10 Xake 2010-11-30 07:07:21 UTC
And that stuff with net-misc/dhcp and dhclient was totally off for both parts:
First that message shows up for all dhcpv4 clients (no matter if it is dhclient or dhcpcd).
Secondly, this has everything to do with dhcpcd running as a daemon.


So for some reasons sometimes when I start my computer dhcpcd starts as a deamon (i.e. /etc/init.d/dhcpcd starts during default runlevel and I have yet to figure out why it sometimes gets started, sometimes not, and what tries to start it) and when this happends NetworkManager fails.

This seems to be because when nm does "/sbin/dhcpcd -B -K -L -c /usr/libexec/nm-dhcp-client.action eth0" it expects dhcpcd to keep on running, at least until an IP-address is found.
However if dhcpcd is already running, then this command send signals to that deamon and then it exits with return signal 0.
This does NetworkManager react on, and thinks it did not get a IP-address.


So here are the potential bugs that causes this:
NetworkManager: Cannot handle dhcpcd already running
OpenRC: Sometimes starts dhcpcd but I cannot figure out why
dhcpcd: seems to always close at once if daemon is already running, even when you have added "-w" option (i.e. wait for ipaddress).
Comment 11 Xake 2010-11-30 07:12:52 UTC
And for the record: I consider that NetworkManager cannot handle dhcpcd running as a daemon is a bug, since if you have more then one dhcp-connection (like one wired and one wireless or anything like that) then you may want to take advantage of only needing one dhcpcd running.
Comment 12 Xake 2010-11-30 08:44:23 UTC
There is a race condition here, and that the following:

It seems like NetworkManager provides dependency "net" for openrc when a connection is done.
However if you have anything (like sshd) that needs "net" before NetworkManager has provided "net", then openrc tries in my case to pull in "dhcpcd" to statisfy that dependency. This results in a Networkmanager failing since dhcpcd (started by nm) did not react as expected, but a working connection since dhcpcd (started by openrc) set it up correctly.

Is there any way of having NetworkManager provide dependency "net" but not satisfy dependency "net" until it has a connection?
Comment 13 Xake 2011-03-14 17:40:53 UTC
using initscripts from bug #252137 with openrc and this issue seems to be gone.
Comment 14 Alexandre Rostovtsev (RETIRED) gentoo-dev 2012-02-02 00:37:58 UTC
Is this bug still present in networkmanager-0.9.2.0-r3?
Comment 15 Pacho Ramos gentoo-dev 2012-04-06 15:14:17 UTC
(In reply to comment #14)
> Is this bug still present in networkmanager-0.9.2.0-r3?