Bug 751275 - Shutdown - possible misbehavior and error.
Summary: Shutdown - possible misbehavior and error.
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 16
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-11-04 06:47 UTC by jurek.bajor
Modified: 2013-02-14 02:49 UTC (History)
4 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2013-02-14 02:49:52 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
dmesg output (74.45 KB, text/plain)
2011-11-04 06:49 UTC, jurek.bajor
no flags Details

Description jurek.bajor 2011-11-04 06:47:37 UTC
Description of problem:

Tested F16 RC4 live-cd LXDE installed to hd.

I see these NetworkManager activities that are repeated and seem to be
identical (if this is a problem, then systemd or NetworkManager related ?).
Also an error present.

Version-Release number of selected component (if applicable):
NetworkManager-0.9.1.90-5.git20110927.fc16.i686

How reproducible:
Run F16 RC4 boot and shutdown.

Steps to Reproduce:
1. as above
2.
3.
  
Actual results:

dmesg output:

...
[   17.596968] NetworkManager[839]: <info> NetworkManager (version 0.9.1.90-5.git20110927.fc16) is starting...
[   17.596977] NetworkManager[839]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
[   17.596984] NetworkManager[839]: NetworkManager[839]: <info> NetworkManager (version 0.9.1.90-5.git20110927.fc16) is starting...
[   17.596992] NetworkManager[839]: NetworkManager[839]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
...

[  287.949443] NetworkManager[839]: <info> caught signal 15, shutting down normally.
[  287.949455] NetworkManager[839]: <warn> quit request received, terminating...
[  287.949464] NetworkManager[839]: <info> (wlan0): now unmanaged
[  287.949472] NetworkManager[839]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
[  287.949481] NetworkManager[839]: <info> (wlan0): cleaning up...
[  287.949488] NetworkManager[839]: <info> (p4p1): now unmanaged
[  287.949496] NetworkManager[839]: <info> (p4p1): device state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
[  287.949505] NetworkManager[839]: <info> (p4p1): cleaning up...
[  287.949512] NetworkManager[839]: <info> (p4p1): taking down device.

[  287.949520] NetworkManager[839]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.

  287.949529] NetworkManager[839]: NetworkManager[839]: <info> caught signal 15, shutting down normally.
[  287.950389] NetworkManager[839]: NetworkManager[839]: <warn> quit request received, terminating...
[  287.950400] NetworkManager[839]: NetworkManager[839]: <info> (wlan0): now unmanaged
[  287.950409] NetworkManager[839]: NetworkManager[839]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
[  287.950417] NetworkManager[839]: NetworkManager[839]: <info> (wlan0): cleaning up...
[  287.950425] NetworkManager[839]: NetworkManager[839]: <info> (p4p1): now unmanaged
[  287.950433] NetworkManager[839]: NetworkManager[839]: <info> (p4p1): device state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
[  287.950442] NetworkManager[839]: NetworkManager[839]: <info> (p4p1): cleaning up...
[  287.950449] NetworkManager[839]: NetworkManager[839]: <info> (p4p1): taking down device.
...

[  287.992598] NetworkManager[839]: NetworkManager[839]: <info> exiting (success)
[  287.992610] NetworkManager[839]: <info> exiting (success)
...


Expected results:


Additional info:

Comment 1 jurek.bajor 2011-11-04 06:49:21 UTC
Created attachment 531703 [details]
dmesg output

Comment 2 Michal Schmidt 2012-01-12 20:52:25 UTC
The duplication of the messages is caused by NM using openlog(3) with the LOG_PERROR flag.

LOG_PERROR makes it send the messages to stderr as well. By default all
services have their stderr bridged to syslog by systemd.
Thus all messages from NetworkManager reach the syslog twice: once directly and
once indirectly via the stderr->syslog bridge.

Comment 3 Jirka Klimes 2012-02-01 09:22:18 UTC
(In reply to comment #2)
> The duplication of the messages is caused by NM using openlog(3) with the
> LOG_PERROR flag.
> 
> LOG_PERROR makes it send the messages to stderr as well. By default all
> services have their stderr bridged to syslog by systemd.
> Thus all messages from NetworkManager reach the syslog twice: once directly and
> once indirectly via the stderr->syslog bridge.

The LOG_PERROR is used when NetworkManager is run as non-daemon foreground
process, so that logs are visible on terminal.
But, since in systemd service file NM is executed like this (NetworkManager --no-daemon) and stderr defaults to syslog in systemd, we end up with duplicated messages.

So, I think the solution is to add StandardError=null to [Service] section of
NetworkManager.service:

[Unit]
Description=Network Manager
After=syslog.target
Wants=network.target
Before=network.target

[Service]
Type=dbus
BusName=org.freedesktop.NetworkManager
StandardError=null
ExecStart=/usr/sbin/NetworkManager --no-daemon

[Install]
WantedBy=multi-user.target
Alias=dbus-org.freedesktop.NetworkManager.service

Comment 4 Jirka Klimes 2012-02-07 14:04:21 UTC
The solution from comment #3 pushed upstream:
13bba719f94d304762775831c741cc0de0edb732

Comment 5 Fedora End Of Life 2013-01-17 01:38:40 UTC
This message is a reminder that Fedora 16 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 16. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '16'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 16's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 16 is end of life. If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora, you are encouraged to click on 
"Clone This Bug" and open it against that version of Fedora.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 6 Fedora End Of Life 2013-02-14 02:49:56 UTC
Fedora 16 changed to end-of-life (EOL) status on 2013-02-12. Fedora 16 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.


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