Bug 459205 - NM spams logs, doesn't connect
NM spams logs, doesn't connect
Status: CLOSED NEXTRELEASE
Product: Fedora
Classification: Fedora
Component: NetworkManager (Show other bugs)
9
All Linux
high Severity high
: ---
: ---
Assigned To: Dan Williams
Fedora Extras Quality Assurance
: Regression
: 462339 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2008-08-14 19:19 EDT by Bradley
Modified: 2009-03-08 15:30 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2009-01-07 23:18:02 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


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

  None (edit)
Description Bradley 2008-08-14 19:19:18 EDT
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 10:31:46 EDT
*** Bug 462339 has been marked as a duplicate of this bug. ***
Comment 2 Mario Torre 2008-10-09 10:22:37 EDT
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 07:08:14 EDT
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 07:09:48 EDT
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 10:10:49 EDT
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 10:12:59 EDT
Created attachment 320801 [details]
only log to syslog any 5 minutes (2nd version)
Comment 7 Dan Williams 2008-11-25 11:08:50 EST
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 13:31:10 EST
fix upstream in svn r4334
Comment 9 Bradley 2008-11-25 17:40:32 EST
iwl4965 for me. I'll try rmmod next time it happens
Comment 10 Bradley 2008-11-25 20:19:21 EST
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 08:29:36 EST
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 12:20:57 EST
FYI, this should be fixed upstream in r4334 and will get into the next fedora build.
Comment 13 Neal Becker 2008-12-10 21:55:16 EST
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-04 21:28:09 EST
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-04 21:30:08 EST
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 04:08:42 EST
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 04:36:49 EST
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-07 23:17:47 EST
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 12:51:40 EST
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 15:30:11 EDT
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.