Bug 459205 - NM spams logs, doesn't connect
Summary: NM spams logs, doesn't connect
Keywords:
Status: CLOSED NEXTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 9
Hardware: All
OS: Linux
high
high
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 462339 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-08-14 23:19 UTC by Bradley
Modified: 2009-03-08 19:30 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-01-08 04:18:02 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
only log to syslog any 5 minutes (1.19 KB, patch)
2008-10-10 11:09 UTC, Mario Torre
no flags Details | Diff
only log to syslog any 5 minutes (2nd version) (1.81 KB, patch)
2008-10-19 14:12 UTC, Mario Torre
no flags Details | Diff

Description Bradley 2008-08-14 23:19:18 UTC
Description of problem:

NM gets 'stuck' and spams logs.

Version-Release number of selected component (if applicable):

NetworkManager-0.7.0-0.11.svn3930.fc9.x86_64 (from koji)
kernel-2.6.25.11-97.fc9.x86_64
wpa_supplicant-0.6.3-6.1bb.fc9.x86_64 (patched for bug 449754)

How reproducible:

Often, but not always

Steps to Reproduce:
1. Log in to X
2. Nothing plugged into ethernet port, wireless connection active
  
Actual results:

nm starts logging tons of:

NetworkManager: <WARN>  nm_error_monitoring_device_link_state(): error monitoring wired ethernet link state: error occurred while waiting for data on socket

Doesn't connect - nm-applet has both circles as grey (not green)

Expected results:

Connects, doesn't spam logs

Additional info:

If I restart NM a few times, this stops happening. Related to NM upgrade - kernel hasn't changed.

[root@plum ~]# grep -c monitoring_device_link /var/log/messages
2889364

When running NM from a shell with -no-daemon, the logs are:

NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Config: set interface ap_scan to 1
NetworkManager: <info>  (wlan0): supplicant connection state change: 0 -> 2
NetworkManager: <WARN>  nm_error_monitoring_device_link_state(): error monitoring wired ethernet link state: error occurred while waiting for data on socket

NetworkManager: <WARN>  nm_error_monitoring_device_link_state(): error monitoring wired ethernet link state: error occurred while waiting for data on socket

.... etc, until I kill it

Comment 1 Bradley 2008-10-01 14:31:46 UTC
*** Bug 462339 has been marked as a duplicate of this bug. ***

Comment 2 Mario Torre 2008-10-09 14:22:37 UTC
There should be something to do about this, NM is filling my /var and renders the system unusable.

Is is possible to filter out his messages?

Comment 3 Mario Torre 2008-10-10 11:08:14 UTC
It's strange enough, and it seems to not be always spamming.

Anyway, this patch should help reduce the number of spam messages :)

Maybe you need to rework it a bit, but seems to work for me.

Comment 4 Mario Torre 2008-10-10 11:09:48 UTC
Created attachment 320005 [details]
only log to syslog any 5 minutes

Be careful, this is not about caching the log message, it may miss some other important information.

Comment 5 Mario Torre 2008-10-19 14:10:49 UTC
I reworked the patch so that only this message is sent to the log system any 5 minutes. I'm not very used to the g_signal thingy, so I'm not sure it's 100% correct (it seems to work).

Also, I'm not sure of the internals of NetworkManager, but I don't see anything in the code that tells me that this message can come from different sources (and if so, the message is always the same anyway), so I guess that suppressing instead of catching is not a big issue here. Maybe we could add a counter to tell the user something like "I tried that many times in the last 5 minutes and got always the same error, so I give up and log it".

Comment 6 Mario Torre 2008-10-19 14:12:59 UTC
Created attachment 320801 [details]
only log to syslog any 5 minutes (2nd version)

Comment 7 Dan Williams 2008-11-25 16:08:50 UTC
What wireless hardware do people have?  Other reports from other distros indicate this is due to a _WiFi_ driver, not an ethernet driver (the NM logs use "wired" regardless of the type).  Does rmmod-ing any wifi driver you have stop the spam?

Comment 8 Dan Williams 2008-11-25 18:31:10 UTC
fix upstream in svn r4334

Comment 9 Bradley 2008-11-25 22:40:32 UTC
iwl4965 for me. I'll try rmmod next time it happens

Comment 10 Bradley 2008-11-26 01:19:21 UTC
rmmod didn't help. I'll try the new version when it hits koji, but I've only ever had this happen at uni, and I'm only here for another couple of weeks.

Comment 11 Neal Becker 2008-12-08 13:29:36 UTC
Ahh! It's doing it again!
Dec  8 08:23:26 nbecker1 NetworkManager: <WARN>  nm_error_monitoring_device_link_state(): error monitoring wired ethernet link state: error occurred while waiting for data on socket#012

I'm running a backup (heavily using eth0).  rsyslog is running loadave 53%, NM is running 40%.  My disk will soon fill with these log messages!\

This is NetworkManager-0.7.0-0.12.svn4326.fc10.x86_64

Comment 12 Dan Williams 2008-12-09 17:20:57 UTC
FYI, this should be fixed upstream in r4334 and will get into the next fedora build.

Comment 13 Neal Becker 2008-12-11 02:55:16 UTC
Thanks.  Please drop a note here when a new build is available.  The problem here is pretty severe.  It happened again today, this time not doing any backups or anything special.  Killing rsyslog leaves NM running 100% cpu.  I have to kill NM.

Comment 14 Fedora Update System 2009-01-05 02:28:09 UTC
NetworkManager-0.7.0-1.git20090102.fc10,NetworkManager-vpnc-0.7.0-1.svn13.fc10,NetworkManager-openvpn-0.7.0-18.svn11.fc10,NetworkManager-pptp-0.7.0-1.svn16.fc10 has been submitted as an update for Fedora 10.
http://admin.fedoraproject.org/updates/NetworkManager-0.7.0-1.git20090102.fc10,NetworkManager-vpnc-0.7.0-1.svn13.fc10,NetworkManager-openvpn-0.7.0-18.svn11.fc10,NetworkManager-pptp-0.7.0-1.svn16.fc10

Comment 15 Fedora Update System 2009-01-05 02:30:08 UTC
NetworkManager-0.7.0-1.git20090102.fc9,NetworkManager-vpnc-0.7.0-1.svn13.fc9,NetworkManager-openvpn-0.7.0-18.svn11.fc9,NetworkManager-pptp-0.7.0-1.svn16.fc9 has been submitted as an update for Fedora 9.
http://admin.fedoraproject.org/updates/NetworkManager-0.7.0-1.git20090102.fc9,NetworkManager-vpnc-0.7.0-1.svn13.fc9,NetworkManager-openvpn-0.7.0-18.svn11.fc9,NetworkManager-pptp-0.7.0-1.svn16.fc9

Comment 16 Fedora Update System 2009-01-07 09:08:42 UTC
NetworkManager-0.7.0-1.git20090102.fc10, NetworkManager-vpnc-0.7.0-1.svn13.fc10, NetworkManager-openvpn-0.7.0-18.svn11.fc10, NetworkManager-pptp-0.7.0-1.svn16.fc10 has been pushed to the Fedora 10 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update NetworkManager NetworkManager-vpnc NetworkManager-openvpn NetworkManager-pptp'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/F10/FEDORA-2009-0023

Comment 17 Fedora Update System 2009-01-07 09:36:49 UTC
NetworkManager-0.7.0-1.git20090102.fc9, NetworkManager-vpnc-0.7.0-1.svn13.fc9, NetworkManager-openvpn-0.7.0-18.svn11.fc9, NetworkManager-pptp-0.7.0-1.svn16.fc9 has been pushed to the Fedora 9 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing-newkey update NetworkManager NetworkManager-vpnc NetworkManager-openvpn NetworkManager-pptp'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/F9/FEDORA-2009-0222

Comment 18 Fedora Update System 2009-01-08 04:17:47 UTC
NetworkManager-0.7.0-1.git20090102.fc10, NetworkManager-vpnc-0.7.0-1.svn13.fc10, NetworkManager-openvpn-0.7.0-18.svn11.fc10, NetworkManager-pptp-0.7.0-1.svn16.fc10 has been pushed to the Fedora 10 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 19 Fedora Update System 2009-03-06 17:51:40 UTC
NetworkManager-0.7.0.99-1.fc9,NetworkManager-vpnc-0.7.0.99-1.fc9,NetworkManager-openvpn-0.7.0.99-1.fc9,NetworkManager-pptp-0.7.0.99-1.fc9,NetworkManager-openconnect-0.7.0.99-1.fc9 has been submitted as an update for Fedora 9.
http://admin.fedoraproject.org/updates/NetworkManager-0.7.0.99-1.fc9,NetworkManager-vpnc-0.7.0.99-1.fc9,NetworkManager-openvpn-0.7.0.99-1.fc9,NetworkManager-pptp-0.7.0.99-1.fc9,NetworkManager-openconnect-0.7.0.99-1.fc9

Comment 20 Fedora Update System 2009-03-08 19:30:11 UTC
NetworkManager-0.7.0.99-1.fc9, NetworkManager-vpnc-0.7.0.99-1.fc9, NetworkManager-openvpn-0.7.0.99-1.fc9, NetworkManager-pptp-0.7.0.99-1.fc9, NetworkManager-openconnect-0.7.0.99-1.fc9 has been pushed to the Fedora 9 stable repository.  If problems still persist, please make note of it in this bug report.


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