Bug 846483

Summary: systemd error message is incomplete, wrong
Product: [Fedora] Fedora Reporter: R P Herrold <herrold>
Component: systemdAssignee: systemd-maint
Status: CLOSED WORKSFORME QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 17CC: johannbg, lnykryn, lpoetter, metherid, msekleta, notting, plautrba, systemd-maint, vpavlin
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-10-05 18:23:57 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description R P Herrold 2012-08-07 22:04:16 UTC
Description of problem:

I have read all of bug 844693, and scanned all open systemd bugs before filing this one ... I understand the use case for a dependency based successor to Sys V initscripts.  Fair enough, BUT: 


Restarting networking, an error message is returned, and yet networking is fully up and functional

secondary matter: the 'help' message offered is simply incomplete, and once supplemented, not a pointer to help


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

[root@fedora17-64-kvm init.d]# rpm -qa systemd\*
systemd-44-17.fc17.x86_64
systemd-sysv-44-17.fc17.x86_64


How reproducible:

on a fairly simple (under KVM) networking setup run:

# service network restart


Steps to Reproduce:
files as requested (an ifconfig below at the bottom), but nothing unusual in play
  

Actual results:

[root@fedora17-64-kvm network-scripts]# service network restart
Restarting network (via systemctl):  Job failed. See system journal and 'systemctl status' for details.
                                                           [FAILED]

but as noted networking seems to be fully restarted:

[root@fedora17-64-kvm init.d]# service network status
Configured devices:
lo em1 eth1 installation
Currently active devices:
lo em1 virbr1 virbr0 installation

so .. the message is not accurate; networking is up


second part:  The message suggests that: 
   systemctl status
might return something. ... it does:  a usage error message:

[root@fedora17-64-kvm network-scripts]# systemctl status | grep network
Too few arguments.
[root@fedora17-64-kvm network-scripts]# systemctl status network
Failed to issue method call: Unit name network is not valid.

and yet the parent initscript is named: network:

[root@fedora17-64-kvm network-scripts]# cd /etc/init.d/
[root@fedora17-64-kvm init.d]# ls
ceph      functions  iscsid    libvirt-guests     netconsole  radvd
ebtables  iscsi      libvirtd  netcf-transaction  network


Checking bug reports (the man page does not help much -- cone I knew the answer, appending a .service to the 'network' seems to point the way .... but this is not obvious ... I understand the presence of the .network to be a convention, rather than a hard requirement, as well ...), I find my way to:

[root@fedora17-64-kvm init.d]# systemctl show network.service
Id=network.service
Names=network.service
Requires=systemd-journald.socket basic.target
Wants=network.target
WantedBy=multi-user.target graphical.target
Conflicts=shutdown.target
Before=arp-ethers.service network.target ebtables.service netconsole.service shu
After=iptables.service ip6tables.service systemd-journald.socket basic.target
Description=LSB: Bring up/down networking
LoadState=loaded
ActiveState=failed
SubState=failed
InactiveExitTimestamp=Tue, 07 Aug 2012 17:12:34 -0400
InactiveExitTimestampMonotonic=949328059068
ActiveEnterTimestampMonotonic=0
ActiveExitTimestampMonotonic=0
InactiveEnterTimestamp=Tue, 07 Aug 2012 17:13:35 -0400
InactiveEnterTimestampMonotonic=949389436494
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureIsolate=no
IgnoreOnIsolate=no
IgnoreOnSnapshot=no
DefaultControlGroup=name=systemd:/system/network.service
ControlGroup=cpu:/system/network.service name=systemd:/system/network.service
NeedDaemonReload=no
JobTimeoutUSec=0
ConditionTimestamp=Tue, 07 Aug 2012 17:12:34 -0400
ConditionTimestampMonotonic=949328046110
ConditionResult=yes
Type=forking
Restart=no
NotifyAccess=none
RestartUSec=100ms
TimeoutUSec=5min
WatchdogUSec=0
WatchdogTimestampMonotonic=0
StartLimitInterval=10000000
StartLimitBurst=5
StartLimitAction=none
ExecStart={ path=/etc/rc.d/init.d/network ; argv[]=/etc/rc.d/init.d/network star
ExecReload={ path=/etc/rc.d/init.d/network ; argv[]=/etc/rc.d/init.d/network rel
ExecStop={ path=/etc/rc.d/init.d/network ; argv[]=/etc/rc.d/init.d/network stop
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=yes
GuessMainPID=no
MainPID=0
ControlPID=0
SysVStartPriority=10
SysVPath=/etc/rc.d/init.d/network
FsckPassNo=0
Result=exit-code
UMask=0022
LimitCPU=18446744073709551615
LimitFSIZE=18446744073709551615
LimitDATA=18446744073709551615
LimitSTACK=18446744073709551615
LimitCORE=18446744073709551615
LimitRSS=18446744073709551615
LimitNOFILE=4096
LimitAS=18446744073709551615
LimitNPROC=31461
LimitMEMLOCK=65536
LimitLOCKS=18446744073709551615
LimitSIGPENDING=31461
LimitMSGQUEUE=819200
LimitNICE=0
LimitRTPRIO=0
LimitRTTIME=18446744073709551615
OOMScoreAdjust=0
Nice=0
IOScheduling=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardOutput=journal+console
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SecureBits=0
CapabilityBoundingSet=18446744073709551615
MountFlags=1048576
PrivateTmp=no
PrivateNetwork=no
SameProcessGroup=no
KillMode=process
KillSignal=15
ControlGroupModify=no
ControlGroupPersistent=no
IgnoreSIGPIPE=no
ExecMainStartTimestampMonotonic=0
ExecMainExitTimestampMonotonic=0
ExecMainPID=0
ExecMainCode=0
ExecMainStatus=0
[root@fedora17-64-kvm init.d]#                          



As I read: man 5 systemd.service
I _think_ it is saying systemd should have tried:
   systemctl status network.service
when I typed:
   systemctol status network
from this section:
       If a service is requested under a certain name but no unit
       configuration file is found, systemd looks for a SysV init script by
       the same name (with the .service suffix removed) and dynamically
       creates a service unit from that script. This is useful for
       compatibility with SysV
but I assume that such intelligence exists only in systemd proper, and not in the systemctl tool.  Perhaps I need to clone this bug into an RFE to that effect



If all those lines of configuration data are supposed to yield meaning to a sysadmin, well, they dont


I would Like to look at the 'system journal' but where? ... but no mention of its man page in: man systemd in the Unix 'proper' section of: SEE ALSO


No hint of what the journal logging location (taht is the filesystem path) might be in either the man page for systemd, nor in the copious status information:

[root@fedora17-64-kvm init.d]# systemctl show network.service | grep jour
Requires=systemd-journald.socket basic.target
After=iptables.service ip6tables.service systemd-journald.socket basic.target
StandardOutput=journal+console


Expected results:

Local documentation that permits a sysadmin to read it, and find needed debugging details


Additional info:

I understand that this all may seem obvious to someone who develops systemd ... but a Unix like environment needs to not 'break expectation' of Unix-type admins by sending them to the source code, or off-machine third-party secondary sources, to solve day to day problems in the usual case


As promised above, the network configs, post restart

[root@fedora17-64-kvm init.d]# ifconfig
em1: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.16.1.188  netmask 255.255.255.0  broadcast 10.16.1.255
        inet6 fe80::21a:a0ff:fec2:579c  prefixlen 64  scopeid 0x20<link>
        ether 00:1a:a0:c2:57:9c  txqueuelen 1000  (Ethernet)
        RX packets 16821085  bytes 3328189465 (3.0 GiB)
        RX errors 0  dropped 64  overruns 0  frame 0
        TX packets 17748887  bytes 7984532992 (7.4 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device interrupt 16

installation: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::e877:28ff:fee2:f581  prefixlen 64  scopeid 0x20<link>
        ether ea:77:28:e2:f5:81  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 15193  bytes 1310142 (1.2 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 16436
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 0  (Local Loopback)
        RX packets 3537981  bytes 5669511144 (5.2 GiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 3537981  bytes 5669511144 (5.2 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

virbr0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet 192.168.122.1  netmask 255.255.255.0  broadcast 192.168.122.255
        ether 52:54:00:9a:b1:64  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

virbr1: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet 10.16.1.129  netmask 255.255.255.224  broadcast 10.16.1.159
        ether 52:54:00:82:f1:fc  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

[root@fedora17-64-kvm init.d]#     


Thank you

-- Russ herrold

Comment 1 Lukáš Nykrýn 2012-08-08 10:54:56 UTC
It would be better if you could fill separated bugs for all of this issues.
So back to the original problem. What is the output of systemctl status network.service after start fails?

Comment 2 Jóhann B. Guðmundsson 2012-08-08 13:26:23 UTC
1)
   I think the reason network fails yet network is up and running is because a) he did not disable NetworkManager or b) set "NM_CONTROLLED=no" in /etc/sysconfig/network-scripts/ifcfg-$INTERFACE or c) virt magic is controlling the network interfaces. ( not a systemd bug )

2)
  "secondary matter: the 'help' message offered is simply incomplete, and once supplemented, not a pointer to help"

He will need to file a separated bug as you suggested with specific info on how he would like to see that error msg improved 

3) 
   "service network status" 
   Here he is confusing service network status as in what is actually being done in the legacy sysv init script and systemctl status network.service and somehow expecting it being the same which it is not. ( not a systemd bug )

4)
   "systemctl status network Failed to issue method call: Unit name network is not valid. and yet the parent initscript is named: network:" here he somehow expects the .service being omitted failing to understand we also have .targets ( like network.target ) and other unit endings so the unit ending cant be omitted when systemctl is run. ( not a systemd bug )

5. The rest has been taken care of with the Documentation= for migrated units 

So this is bug winds up being essential potential man pages fixes and or improved help message which he as you suggested needs to be filed separately and of course with suggestion on how these should be improved...

Comment 3 Lennart Poettering 2012-09-14 13:25:44 UTC
Trying to disect the issues raised here:

1. systemd only reports back if a service returned an unclean error code. It is not responsible to rollback any changes a service did. If you think that the network should have been shut down again on failure, or if the network shouldn't have returned an unclean exit code, then please file a bug against the initscripts package.

2. systemd in git (and soon F18) will now explicitly mention the failed service when it suggests to run "systemctl status xxx.service". This should fix the complaint about the misleading help text. This is also tracked in https://bugzilla.redhat.com/show_bug.cgi?id=845028

3. On F18 "systemctl status network" is now implicitly equivalent to "systemctl status network.service". This should fix the respective complaint, too.

4. "systemctl show" is supposed to be a tool for scripts and such like. It's output is not supposed to be read by humans as primary interface. That's what "systemctl status" is for.

5. I changed the warning messages to refer to "journalctl" rather than the "system journal", also for F18. This should fix this issue.

6. I've also added the reference to journalctl to the SEE ALSO section of the systemd man page.

I think this resolves all issues. 

Next time, please file individual bugs, so that we can process them individually.

Comment 4 Fedora Update System 2012-09-20 19:55:01 UTC
systemd-190-1.fc18 has been submitted as an update for Fedora 18.
https://admin.fedoraproject.org/updates/systemd-190-1.fc18

Comment 5 Fedora Update System 2012-09-22 06:36:11 UTC
Package systemd-191-2.fc18, rtkit-0.11-3.fc18:
* should fix your issue,
* was pushed to the Fedora 18 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing systemd-191-2.fc18 rtkit-0.11-3.fc18'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-14581/rtkit-0.11-3.fc18,systemd-191-2.fc18
then log in and leave karma (feedback).

Comment 6 Fedora Update System 2012-09-28 00:16:37 UTC
Package glibc-2.16-17.fc18, systemd-192-1.fc18, selinux-policy-3.11.1-23.fc18, rtkit-0.11-3.fc18:
* should fix your issue,
* was pushed to the Fedora 18 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing glibc-2.16-17.fc18 systemd-192-1.fc18 selinux-policy-3.11.1-23.fc18 rtkit-0.11-3.fc18'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-14581/selinux-policy-3.11.1-23.fc18,rtkit-0.11-3.fc18,systemd-192-1.fc18,glibc-2.16-17.fc18
then log in and leave karma (feedback).

Comment 7 Fedora Update System 2012-10-01 20:08:34 UTC
Package glibc-2.16-17.fc18, rtkit-0.11-3.fc18, systemd-193-1.fc18:
* should fix your issue,
* was pushed to the Fedora 18 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing glibc-2.16-17.fc18 rtkit-0.11-3.fc18 systemd-193-1.fc18'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-14581/rtkit-0.11-3.fc18,systemd-193-1.fc18,glibc-2.16-17.fc18
then log in and leave karma (feedback).

Comment 8 R P Herrold 2012-10-05 18:23:57 UTC
Thank you for the responses and changes