[solved] I think I lost network-manager on last d-u

[GoinEasy9]

This is my journalctl -xn:

Code: [Select]

Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: in0: +2.84 V (min = +1.81 V, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: in1: +2.75 V (min = +1.24 V, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: +3.3V: +3.31 V (min = +4.37 V$
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: in4: +3.01 V (min = +2.66 V, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: in5: +2.51 V (min = +0.74 V, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: in6: +1.61 V (min = +0.71 V, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: 3VSB: +4.03 V (min = +5.54 V,$
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: fan2: 0 RPM (min = 22 RPM) [A$
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: temp1: 39.0 C (min = 87.0 C, $
Apr 03 19:45:55 siduction64kdefx sensord[1448]: Sensor alarm: Chip it8721-isa-0290: temp2: 34.0 C (min = 19.0 C, $My journalctl -b -p err looks much the same, just lengthy.  I'm experimenting with sensor configs, that are directed at ASUS boards, to try to stop these alarms.  I don't think they have anything to do with NetworkManager coming up.

[ayla]

Maybe

Code: [Select]

journalctl -b|grep NetworkManageror

Code: [Select]

journalctl -b|grep wlancan give a hint, then.

[UP2L8]

Just performed a d-up a few minutes ago and no issues for me with network-manager being removed under LXDE.

[vilde]

Are everybody happy with their network-manager now? Shall we mark this thread as solved?

[absolut]

can anyone please confirm that already existing network entries in the network-manager are preserved in the new version? thanks in advance

[vilde]

can anyone please confirm that already existing network entries in the network-manager are preserved in the new version? thanks in advance

I can only tell for me, from  n-m 0.9.8.8-4 to nm 0.9.8.8-5 was a clean update without problems

[ayla]

from 0.9.8.0-5 to 0.9.8.8-5 no problems here also.

All earlier used connections available.

[GoinEasy9]

NetworkManager is working just fine here, except, I still have it at the top of the blame list: 
$ systemd-analyze blame
         16.231s NetworkManager.service
         15.604s ModemManager.service
         15.327s dirmngr.service
         11.263s cron.service
          4.719s preload.service
          4.693s acpi-support.service

@ayla, Sorry, it took me a while to get back and run "$ journalctl -b|grep NetworkManager".  It seems like it's activating and deactivating eth0 a few times and then hangs on IPv6 for a bit.  I'll probably look into why it sets itself up and then deactivates because it's "managed", and try to Google the warns, or why it takes 10 seconds to write DNS information to /sbin/resolvconf. The output is below:

Code: [Select]

$ journalctl -b|grep NetworkManager
Apr 08 00:42:39 siduction64kdefx NetworkManager[1233]: <info> NetworkManager (version 0.9.8.8) is starting...
Apr 08 00:42:39 siduction64kdefx NetworkManager[1233]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
Apr 08 00:42:39 siduction64kdefx NetworkManager[1233]: <info> WEXT support is enabled
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: init!
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: update_system_hostname
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPluginIfupdown: management mode: unmanaged
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:15.1/0000:08:00.0/net/eth0, iface: eth0)
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:15.1/0000:08:00.0/net/eth0, iface: eth0): no ifupdown configuration found.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/lo, iface: lo)
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/lo, iface: lo): no ifupdown configuration found.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: end _init.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: <info> Loaded plugin ifupdown: (C) 2008 Canonical Ltd.  To report bugs please use the NetworkManager mailing list.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: Ifupdown: get unmanaged devices count: 0
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: (25090832) ... get_connections.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: SCPlugin-Ifupdown: (25090832) ... get_connections (managed=false): return empty list.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: Ifupdown: get unmanaged devices count: 0
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: <info> monitoring kernel firmware directory '/lib/firmware'.
Apr 08 00:42:40 siduction64kdefx NetworkManager[1233]: <info> monitoring ifupdown state file '/run/network/ifstate'.
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> WiFi hardware radio set enabled
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> WiFi enabled by radio killswitch; enabled by state file
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> WWAN enabled by radio killswitch; enabled by state file
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> WiMAX enabled by radio killswitch; enabled by state file
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> Networking is enabled by state file
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <warn> failed to allocate link cache: (-26) Protocol mismatch
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): carrier is OFF
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): new Ethernet device (driver: 'r8169' ifindex: 2)
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): bringing up device.
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): preparing device.
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> (eth0): deactivating device (reason 'managed') [2]
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> Added default wired connection 'Wired connection 1' for /sys/devices/pci0000:00/0000:00:15.1/0000:08:00.0/net/eth0
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Apr 08 00:42:41 siduction64kdefx NetworkManager[1233]: <info> ModemManager available in the bus
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): carrier now ON (device state 20)
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Auto-activating connection 'Wired connection 1'.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) starting connection 'Wired connection 1'
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> NetworkManager state is now CONNECTING
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: prepare -> config (reason 'none') [40 50 0]
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: config -> ip-config (reason 'none') [50 70 0]
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> dhclient started with pid 1833
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Beginning IP6 addrconf.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Apr 08 00:42:43 siduction64kdefx NetworkManager[1233]: <info> (eth0): DHCPv4 state changed nbi -> preinit
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info> (eth0): DHCPv4 state changed preinit -> bound
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   address 192.168.1.107
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   prefix 24 (255.255.255.0)
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   gateway 192.168.1.1
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   nameserver '167.206.13.180'
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   nameserver '167.206.13.181'
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info>   nameserver '192.168.1.1'
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Apr 08 00:42:44 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) started...
Apr 08 00:42:45 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Apr 08 00:42:45 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) complete.
Apr 08 00:42:45 siduction64kdefx NetworkManager[1233]: <info> (eth0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Apr 08 00:42:46 siduction64kdefx NetworkManager[1233]: <info> NetworkManager state is now CONNECTED_GLOBAL
Apr 08 00:42:46 siduction64kdefx NetworkManager[1233]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS.
Apr 08 00:42:46 siduction64kdefx NetworkManager[1233]: <info> Writing DNS information to /sbin/resolvconf
Apr 08 00:42:56 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) successful, device activated.
Apr 08 00:43:03 siduction64kdefx NetworkManager[1233]: <info> (eth0): IP6 addrconf timed out or failed.
Apr 08 00:43:03 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Apr 08 00:43:03 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) started...
Apr 08 00:43:03 siduction64kdefx NetworkManager[1233]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) complete.

[vilde]

I give you my outputs. I also have a ssd but maybe the proportions can be to any help?

Code: [Select]

vilde@T410:~$ systemd-analyze blame
          2.049s systemd-udev-settle.service
          1.153s ModemManager.service
          1.104s acpi-fakekey.service
           652ms NetworkManager.service
           406ms acpi-support.service
           202ms keyboard-setup.service
           149ms bluetooth.service
           125ms systemd-logind.service
           121ms sidu-base.service
           120ms systemd-fsck-root.service
           118ms bootlogs.service
           117ms networking.service
           107ms loadcpufreq.service
           100ms gpm.service
            89ms console-setup.service
            63ms systemd-udev-trigger.service
            55ms ntp.service
            54ms cron.service
            53ms irqbalance.service
            52ms resolvconf.service
            52ms rpcbind.service
            50ms mdadm-raid.service
            48ms hdparm.service
            47ms systemd-modules-load.service
            44ms lm-sensors.service
            42ms preload.service
            42ms udisks2.service
            41ms vnstat.service
            41ms glances.service
            38ms polkitd.service
            34ms mdadm.service
            34ms wpa_supplicant.service
            31ms alsa-restore.service
            31ms console-kit-log-system-start.service
            30ms dev-hugepages.mount
            30ms systemd-tmpfiles-setup-dev.service
            28ms dev-mqueue.mount
            27ms smartmontools.service
            27ms sys-kernel-debug.mount
            26ms lvm2-activation-early.service
            25ms ifplugd.service
            25ms lightdm.service
            22ms screen-cleanup.service
            22ms cpufrequtils.service
            21ms systemd-sysctl.service
            21ms kbd.service
            21ms motd.service
            17ms hddtemp.service
            17ms keymap.service
            16ms console-kit-daemon.service
            15ms systemd-tmpfiles-setup.service
            14ms pppd-dns.service
            12ms saned.service
            12ms systemd-user-sessions.service
            12ms rc-local.service
            12ms dns-clean.service
            10ms lvm2-activation.service
             9ms systemd-update-utmp-runlevel.service
             8ms systemd-remount-fs.service
             8ms upower.service
             7ms systemd-udevd.service
             5ms avahi-daemon.service
             5ms systemd-journal-flush.service
             4ms sys-fs-fuse-connections.mount
             4ms run-lock.mount
             3ms dev-disk-by\x2duuid-b9c9563e\x2d8088\x2d46d2\x2d8a5c\x2dc020bfe007fb.swap
             2ms run-user.mount
             2ms systemd-random-seed-load.service


Code: [Select]

vilde@T410:~$ journalctl -b|grep NetworkManager
apr 08 07:34:31 T410 NetworkManager[978]: <info> NetworkManager (version 0.9.8.8) is starting...
apr 08 07:34:31 T410 NetworkManager[978]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
apr 08 07:34:31 T410 NetworkManager[978]: <info> WEXT support is enabled
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: init!
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: update_system_hostname
apr 08 07:34:31 T410 NetworkManager[978]: SCPluginIfupdown: management mode: unmanaged
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:19.0/net/eth0, iface: eth0)
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:19.0/net/eth0, iface: eth0): no ifupdown configuration found.
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0, iface: wlan0)
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0, iface: wlan0): no ifupdown configuration found.
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/lo, iface: lo)
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/lo, iface: lo): no ifupdown configuration found.
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: end _init.
apr 08 07:34:31 T410 NetworkManager[978]: <info> Loaded plugin ifupdown: (C) 2008 Canonical Ltd.  To report bugs please use the NetworkManager mailing list.
apr 08 07:34:31 T410 NetworkManager[978]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
apr 08 07:34:31 T410 NetworkManager[978]: Ifupdown: get unmanaged devices count: 0
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: (146725216) ... get_connections.
apr 08 07:34:31 T410 NetworkManager[978]: SCPlugin-Ifupdown: (146725216) ... get_connections (managed=false): return empty list.
apr 08 07:34:31 T410 NetworkManager[978]: keyfile: parsing dd-wrt-vilde ...
apr 08 07:34:31 T410 NetworkManager[978]: keyfile:     read connection 'dd-wrt-vilde'
apr 08 07:34:32 T410 NetworkManager[978]: Ifupdown: get unmanaged devices count: 0
apr 08 07:34:32 T410 NetworkManager[978]: <info> monitoring kernel firmware directory '/lib/firmware'.
apr 08 07:34:32 T410 NetworkManager[978]: <info> monitoring ifupdown state file '/run/network/ifstate'.
apr 08 07:34:32 T410 NetworkManager[978]: <info> rfkill1: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy0/rfkill1) (driver iwlwifi)
apr 08 07:34:32 T410 NetworkManager[978]: <info> WiFi hardware radio set enabled
apr 08 07:34:32 T410 NetworkManager[978]: <info> WiFi enabled by radio killswitch; enabled by state file
apr 08 07:34:32 T410 NetworkManager[978]: <info> WWAN enabled by radio killswitch; enabled by state file
apr 08 07:34:32 T410 NetworkManager[978]: <info> WiMAX enabled by radio killswitch; enabled by state file
apr 08 07:34:32 T410 NetworkManager[978]: <info> Networking is enabled by state file
apr 08 07:34:32 T410 NetworkManager[978]: <warn> failed to allocate link cache: (-26) Protocol mismatch
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): carrier is OFF
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): new Ethernet device (driver: 'e1000e' ifindex: 2)
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): bringing up device.
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): preparing device.
apr 08 07:34:32 T410 NetworkManager[978]: <info> (eth0): deactivating device (reason 'managed') [2]
apr 08 07:34:32 T410 NetworkManager[978]: <info> Added default wired connection 'Trådbunden anslutning 1' for /sys/devices/pci0000:00/0000:00:19.0/net/eth0
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): using nl80211 for WiFi device control
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): new 802.11 WiFi device (driver: 'iwlwifi' ifindex: 3)
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/1
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): bringing up device.
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): preparing device.
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): deactivating device (reason 'managed') [2]
apr 08 07:34:32 T410 NetworkManager[978]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
apr 08 07:34:32 T410 NetworkManager[978]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
apr 08 07:34:32 T410 NetworkManager[978]: <info> ModemManager available in the bus
apr 08 07:34:32 T410 NetworkManager[978]: <info> wpa_supplicant started
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0) supports 5 scan SSIDs
apr 08 07:34:32 T410 NetworkManager[978]: <warn> Trying to remove a non-existant call id.
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: starting -> ready
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: ready -> inactive
apr 08 07:34:32 T410 NetworkManager[978]: <info> (wlan0) supports 5 scan SSIDs
apr 08 07:34:36 T410 NetworkManager[978]: <info> Auto-activating connection 'dd-wrt-vilde'.
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) starting connection 'dd-wrt-vilde'
apr 08 07:34:36 T410 NetworkManager[978]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
apr 08 07:34:36 T410 NetworkManager[978]: <info> NetworkManager state is now CONNECTING
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
apr 08 07:34:36 T410 NetworkManager[978]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0/wireless): connection 'dd-wrt-vilde' has security, and secrets exist.  No new secrets needed.
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: added 'ssid' value 'dd-wrt-vilde'
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: added 'scan_ssid' value '1'
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: added 'auth_alg' value 'OPEN'
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: added 'psk' value '<omitted>'
apr 08 07:34:36 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
apr 08 07:34:36 T410 NetworkManager[978]: <info> Config: set interface ap_scan to 1
apr 08 07:34:36 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: inactive -> scanning
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: scanning -> authenticating
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: authenticating -> associating
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'dd-wrt-vilde'.
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
apr 08 07:34:39 T410 NetworkManager[978]: <info> dhclient started with pid 2128
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Beginning IP6 addrconf.
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
apr 08 07:34:39 T410 NetworkManager[978]: <info> (wlan0): DHCPv4 state changed preinit -> reboot
apr 08 07:34:39 T410 NetworkManager[978]: <info>   address 192.168.1.79
apr 08 07:34:39 T410 NetworkManager[978]: <info>   prefix 24 (255.255.255.0)
apr 08 07:34:39 T410 NetworkManager[978]: <info>   gateway 192.168.1.254
apr 08 07:34:39 T410 NetworkManager[978]: <info>   hostname 'T410'
apr 08 07:34:39 T410 NetworkManager[978]: <info>   nameserver '192.168.1.254'
apr 08 07:34:39 T410 NetworkManager[978]: <info>   domain name 'lan'
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
apr 08 07:34:39 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) started...
apr 08 07:34:40 T410 NetworkManager[978]: <info> (wlan0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
apr 08 07:34:40 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) complete.
apr 08 07:34:40 T410 NetworkManager[978]: <info> (wlan0): device state change: secondaries -> activated (reason 'none') [90 100 0]
apr 08 07:34:40 T410 NetworkManager[978]: <info> NetworkManager state is now CONNECTED_GLOBAL
apr 08 07:34:40 T410 NetworkManager[978]: <info> Policy set 'dd-wrt-vilde' (wlan0) as default for IPv4 routing and DNS.
apr 08 07:34:40 T410 NetworkManager[978]: <info> Writing DNS information to /sbin/resolvconf
apr 08 07:34:40 T410 NetworkManager[978]: <info> Activation (wlan0) successful, device activated.
apr 08 07:34:59 T410 NetworkManager[978]: <info> (wlan0): IP6 addrconf timed out or failed.
apr 08 07:34:59 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
apr 08 07:34:59 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) started...
apr 08 07:34:59 T410 NetworkManager[978]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) complete.

[ayla]

 http://paste.siduction.org/20140408144039 -> my output of journalctl -b|grep NetworkManager
Can't find anything  uncommon in your log by comparing this three, except the long time span after "Writing DNS information to /sbin/resolvconf" you mentioned, but I have no idea which reason this could have.

greets
ayla

[dibl]

I just learned about the critical-chain option -- very interesting way to look at a service and see what is involved to start it.  On my system, rc-local.service is the slow one.  Here is the output:

Code: [Select]

root@imerabox:/home# systemd-analyze critical-chain rc-local.service
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.


graphical.target @2min 7.821s
└─multi-user.target @2min 7.821s
  └─getty.target @2min 7.821s
    └─getty@tty1.service @2min 7.821s
      └─rc-local.service @1.439s +2min 6.381s
        └─basic.target @1.426s
          └─sockets.target @1.426s
            └─dbus.socket @1.426s
              └─sysinit.target @1.425s
                └─console-setup.service @1.196s +228ms
                  └─kbd.service @1.185s +10ms
                    └─remote-fs.target @1.184s
                      └─local-fs.target @1.181s
                        └─run-vmblock\x2dfuse.mount @1min 56.752s
                          └─local-fs-pre.target @310ms
                            └─systemd-remount-fs.service @304ms +5ms
                              └─keyboard-setup.service @167ms +119ms
                                └─keymap.service @128ms +38ms
                                  └─systemd-journald.socket @128ms
                                    └─-.mount @127ms

I guess my vmware is involved in the slow start of that one.  All other services are very fast here:

Code: [Select]

root@imerabox:/home# systemd-analyze blame                         
     2min 6.381s rc-local.service
          1.202s vmware.service
          1.047s lm-sensors.service
          1.009s var_log_dirs.service
           783ms mnt-DATA.mount
           662ms vmware-USBArbitrator.service
           423ms hddtemp.service
           325ms samba.service
           320ms systemd-udev-settle.service
           264ms exim4.service
           228ms nmbd.service
           228ms console-setup.service
.
.
.

EDIT:  Fixed my rc-local -- look at this boot:

Code: [Select]

root@imerabox:/# systemd-analyze blame
          1.055s lm-sensors.service
          1.013s var_log_dirs.service
           768ms vmware-USBArbitrator.service
           750ms mnt-DATA.mount
           415ms hddtemp.service
           336ms samba.service
           284ms exim4.service
           250ms console-setup.service
           233ms nmbd.service
           208ms samba-ad-dc.service
           157ms nfs-kernel-server.service
           150ms systemd-fsck-root.service
           143ms smbd.service
           126ms ddclient.service
           117ms console-kit-daemon.service
           113ms sysfsutils.service
            95ms tor.service
            92ms systemd-tmpfiles-setup-dev.service
            90ms keyboard-setup.service
.
.
.

[ayla]

very interesting one, indeed.

systemd is getting a nicer and nicer playground... 

[GoinEasy9]

Thanks @vilde, @ayla and @dibl.  After looking at your "blame", I can only surmise that there's something about my local machine that's causing my problems.   

@dibl thanks for showing me "critical-chain".  It also shows the time gaps, but, still no clues, since I can't find where resolvconf.service is located.

Code: [Select]

# systemd-analyze critical-chain NetworkManager.service
graphical.target @27.585s
└─multi-user.target @27.585s
  └─pulseaudio.service @27.425s +159ms
    └─NetworkManager.service @8.620s +18.805s
      └─basic.target @8.513s
        └─sockets.target @8.513s
          └─dbus.socket @8.513s
            └─sysinit.target @8.498s
              └─networking.service @7.866s +632ms
                └─resolvconf.service @7.129s +735ms
                  └─local-fs.target @7.067s
                    └─run-rpc_pipefs.mount @8.227s
                      └─local-fs-pre.target @5.075s
                        └─systemd-remount-fs.service @4.963s +111ms
                          └─keyboard-setup.service @1.685s +2.020s
                            └─systemd-udevd.service @1.613s +70ms
                              └─systemd-tmpfiles-setup-dev.service @919ms +692ms
                                └─systemd-journald.socket @892ms
                                  └─-.mount @891msIt would be nice if I could locate resolvconf.service.  Does anyone know where it's hiding?  I'm trying to go through the wants, targets and services to see if I can find exactly where the bottlenecks are.  I'm also wondering if this has anything to do with my disabling ntp.service or apache2.service. 
Anyway, back to experimenting.

Thanks for all the responses.

[dibl]

@GoinEasy9, here's a random thought.  What if you booted a siduction Live ISO on that same hardware, and then checked the systemd-analyze blame output?  Maybe you could learn something by comparing the two outputs.

[GoinEasy9]

Thanks dibl, I put it on my list.