NetworkManager fills log on start up until dhcdbd has started

ok, maybe this could deserve a bit more fine tuning.

I am seeing this too, except I had 71681 messages. My poor cpu is dying under the logcheck load. :(

I would mention that this was fine (after fixing #137744 got fixed) until today's upgrade.

I'll clarify my last comment. I was seeing #137744. Then 0.6.5-0ubuntu11 fix 137744. Then there was a non-network-manager update (I believe it was dbus related), that started causing the above messages. I may be wrong, but believe the critical line is:

NetworkManager: <WARN> nm_dhcp_manager_begin_transaction(): dhcdbd not running!

$ grep 'dhcdbd not running' /var/log/daemon.log.0|wc -l
14150

we should try to fix this for RC

so how long does it take in these cases for dhcdcb to start? (e.g. what time window do those 14150 lines cover)?

This morning I had 1,104 activation requests (20,976 lines) over a period of 6 seconds.

$ egrep 'Oct 3 .* dhcdbd not running' /var/log/daemon.log.0|head -1
Oct 3 07:30:34 lupin NetworkManager: <WARN> nm_dhcp_manager_get_state_for_device(): dhcdbd not running!

$ egrep 'Oct 3 .* dhcdbd not running' /var/log/daemon.log.0|tail -1
Oct 3 07:31:10 lupin NetworkManager: <WARN> nm_dhcp_manager_begin_transaction(): dhcdbd not running!

$ egrep 'Oct 3 .* dhcdbd not running' /var/log/daemon.log.0|wc -l
9924

network-manager (0.6.5-0ubuntu15) gutsy; urgency=low

  * debian/patches/41z_lp138217_use_timeout_to_schedule_activation.patch,series:
    don't use idle_source to schedule activation, but rest a bit by using a
    timeout_source with 250ms delay (LP: #138217).
  * debian/network-manager.postinst: sleep 2 seconds after ifblacklist_migrate.sh
    (LP: #146757).
  * debian/patches/41w_lp145683_cancel_scan_in_supplicant_cleanup.patch,series: first part
    for lp145683 - cancel pending scans on terminate (LP: #145683).
  * debian/patches/41wa_lp145683_wpa_ctrl_check_select_result_for_error.patch,series:
    second part to fix lp145683; test select result for errors (in case of
    TERMINATE) (LP: #145683).
  * debian/patches/41y_queue_if_dbus_name_is_taken_on_startup.patch,series: make
    restart of network manager more failsafe and even allow to take over name
    ownership. When ownership is taken over (dbus signal |NameLost| received), we
    shutdown cleanly by sending |X| through |nm_shutdown_pipe| (LP: #85113).
  * debian/patches/41x_lp145653_reraise_fatal_signals.patch: re-raise fatal
    signals (LP: #145653).

 -- Alexander Sack <email address hidden> Tue, 02 Oct 2007 13:32:50 +0200

Has this bug been fixed yet? I am getting killed here with my logs being filled up by NetworkManager. How do I prevent it from starting? I tried to grep for it in /etc/init.d but none of the scripts contain it. I killed it manually, and of course, I lost connection. Upon restarting networking, I got connection back without NetworkManager processes running:

=> ps -ef | grep NetworkManager
root 5958 1 0 08:47 ? 00:00:51 /usr/sbin/NetworkManager --pid-file /var/run/NetworkManager/NetworkManager.pid
root 5974 1 0 08:47 ? 00:00:29 /usr/sbin/NetworkManagerDispatcher --pid-file /var/run/NetworkManager/NetworkManagerDispatcher.pid
bmynars 29539 26348 0 10:47 pts/1 00:00:00 grep NetworkManager
root 29567 5974 0 10:47 ? 00:00:00 sh -c /etc/NetworkManager/dispatcher.d/01ifupdown eth0 pre-up

So, if I do not need it, why does it start in the first place?

It fills up syslog and daemon.log files (very small sample only):

Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Apr 27 10:48:30 tux-229 NetworkManager: <WARN> nm_dhcp_manager_begin_transaction(): dhcdbd not running!
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) failure scheduled...
Apr 27 10:48:30 tux-229 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.

Forgot to mention in my previous comment, I am running Hardy Heron.

Alexander, if the fix was released on 09/08/2007, has this bug been re-introduced in Hard Heron? My log file gets just flooded with NetworkManager messages.

I'm getting the errors as well. After a minute or so, it finally succeeds and I'm able to connect.

Hardy Heron. Network Manager v0.6.6; network driver is 'b44', which oddly is not displaying in the Connection Information dialog. My wireless NIC (ipw2200) card seems to work (at least a lot quicker than wired network connection).