Bug 2001764

Summary: [RHEL-9.0] After nfs-idmapd stopped we can see failure like nfs-idmapd.service: Failed with result 'exit-code'
Product: Red Hat Enterprise Linux 9 Reporter: Yongcheng Yang <yoyang>
Component: nfs-utilsAssignee: Steve Dickson <steved>
Status: CLOSED ERRATA QA Contact: Yongcheng Yang <yoyang>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 9.0CC: dtardon, steved, systemd-maint-list, xzhou
Target Milestone: rcKeywords: EasyFix, Patch, Reproducer, Triaged
Target Release: ---Flags: pm-rhel: mirror+
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: nfs-utils-2.5.4-12.el9 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-11-15 11:22:03 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 Yongcheng Yang 2021-09-07 07:02:10 UTC
Description of problem:
Afer we stopping the service nfs-idmapd, it shows as "failed (Result: exit-code)" but not (like rhel8) "inactive (dead)".

I's weird that /usr/lib/systemd/system/nfs-idmapd.service has not changed.

Version-Release number of selected component (if applicable):
nfs-utils-2.5.4-5.el9

How reproducible:
always & esay

Steps to Reproduce:
(systemctl start nfs-idmapd)
1. systemctl stop nfs-idmapd
2. systemctl status nfs-idmapd (and check the failed logs)
3.

Actual results:
[root@rhel-9-latest ~]# systemctl status nfs-idmapd
● nfs-idmapd.service - NFSv4 ID-name mapping service
     Loaded: loaded (/usr/lib/systemd/system/nfs-idmapd.service; static)
     Active: active (running) since Mon 2021-09-06 22:16:04 EDT; 4h 27min ago
    Process: 1617 ExecStart=/usr/sbin/rpc.idmapd (code=exited, status=0/SUCCESS)
   Main PID: 1622 (rpc.idmapd)
      Tasks: 1 (limit: 1448)
     Memory: 692.0K
        CPU: 5ms
     CGroup: /system.slice/nfs-idmapd.service
             └─1622 /usr/sbin/rpc.idmapd

Sep 06 22:16:04 rhel-9-latest systemd[1]: Starting NFSv4 ID-name mapping service...
Sep 06 22:16:04 rhel-9-latest rpc.idmapd[1622]: Setting log level to 0
Sep 06 22:16:04 rhel-9-latest systemd[1]: Started NFSv4 ID-name mapping service.
[root@rhel-9-latest ~]# systemctl stop nfs-idmapd
[root@rhel-9-latest ~]# systemctl status nfs-idmapd
× nfs-idmapd.service - NFSv4 ID-name mapping service
     Loaded: loaded (/usr/lib/systemd/system/nfs-idmapd.service; static)
     Active: failed (Result: exit-code) since Tue 2021-09-07 02:44:02 EDT; 1s ago
    Process: 1617 ExecStart=/usr/sbin/rpc.idmapd (code=exited, status=0/SUCCESS)
   Main PID: 1622 (code=exited, status=1/FAILURE)
        CPU: 6ms

Sep 06 22:16:04 rhel-9-latest systemd[1]: Starting NFSv4 ID-name mapping service...
Sep 06 22:16:04 rhel-9-latest rpc.idmapd[1622]: Setting log level to 0
Sep 06 22:16:04 rhel-9-latest systemd[1]: Started NFSv4 ID-name mapping service.
Sep 07 02:44:02 rhel-9-latest rpc.idmapd[1622]: exiting on signal 15
Sep 07 02:44:02 rhel-9-latest systemd[1]: Stopping NFSv4 ID-name mapping service...
Sep 07 02:44:02 rhel-9-latest systemd[1]: nfs-idmapd.service: Main process exited, code=exited, status=1/FAILURE
Sep 07 02:44:02 rhel-9-latest systemd[1]: nfs-idmapd.service: Failed with result 'exit-code'.
Sep 07 02:44:02 rhel-9-latest systemd[1]: Stopped NFSv4 ID-name mapping service.
[root@rhel-9-latest ~]# cat /var/log/messages | egrep -i "idmapd.*failed"
Sep  7 02:44:02 rhel-9-latest systemd[1]: nfs-idmapd.service: Failed with result 'exit-code'.
Sep  7 02:44:02 rhel-9-latest audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=nfs-idmapd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[root@rhel-9-latest ~]# rpm -q nfs-utils
nfs-utils-2.5.4-5.el9.x86_64
[root@rhel-9-latest ~]#

Expected results:
Compared with RHEL8:
[root@rhel-85-latest ~]# systemctl stop nfs-idmapd
[root@rhel-85-latest ~]# systemctl status nfs-idmapd
* nfs-idmapd.service - NFSv4 ID-name mapping service
   Loaded: loaded (/usr/lib/systemd/system/nfs-idmapd.service; static; vendor preset: disabled)
   Active: inactive (dead) since Tue 2021-09-07 02:49:59 EDT; 2s ago
  Process: 708 ExecStart=/usr/sbin/rpc.idmapd (code=exited, status=0/SUCCESS)
 Main PID: 712 (code=killed, signal=TERM)

Sep 06 22:04:39 rhel-85-latest systemd[1]: Starting NFSv4 ID-name mapping service...
Sep 06 22:04:39 rhel-85-latest rpc.idmapd[712]: Setting log level to 0
Sep 06 22:04:39 rhel-85-latest systemd[1]: Started NFSv4 ID-name mapping service.
Sep 07 02:49:59 rhel-85-latest systemd[1]: Stopping NFSv4 ID-name mapping service...
Sep 07 02:49:59 rhel-85-latest systemd[1]: nfs-idmapd.service: Succeeded.
Sep 07 02:49:59 rhel-85-latest systemd[1]: Stopped NFSv4 ID-name mapping service.
[root@rhel-85-latest ~]# cat /var/log/messages | egrep -i "idmapd.*failed"
[root@rhel-85-latest ~]# exit

Additional info:

Comment 3 Yongcheng Yang 2022-01-26 09:16:11 UTC
This warning is emitted by the systemd and disappears if started/stopped by hand:
[root@dell-per750-08 ~]# >/var/log/messages
[root@dell-per750-08 ~]# rpc.idmapd
[root@dell-per750-08 ~]# pkill rpc.idmapd
[root@dell-per750-08 ~]# cat /var/log/messages
Jan 26 04:08:15 dell-per750-08 rpc.idmapd[66688]: Setting log level to 0
Jan 26 04:08:18 dell-per750-08 rpc.idmapd[66688]: exiting on signal 15
[root@dell-per750-08 ~]# systemctl start nfs-idmapd
[root@dell-per750-08 ~]# systemctl stop nfs-idmapd
[root@dell-per750-08 ~]# cat /var/log/messages
Jan 26 04:08:15 dell-per750-08 rpc.idmapd[66688]: Setting log level to 0
Jan 26 04:08:18 dell-per750-08 rpc.idmapd[66688]: exiting on signal 15
Jan 26 04:10:05 dell-per750-08 systemd[1]: Starting NFSv4 ID-name mapping service...
Jan 26 04:10:05 dell-per750-08 rpc.idmapd[66739]: Setting log level to 0
Jan 26 04:10:05 dell-per750-08 systemd[1]: Started NFSv4 ID-name mapping service.
Jan 26 04:10:08 dell-per750-08 rpc.idmapd[66739]: exiting on signal 15
Jan 26 04:10:08 dell-per750-08 systemd[1]: Stopping NFSv4 ID-name mapping service...
Jan 26 04:10:08 dell-per750-08 systemd[1]: nfs-idmapd.service: Main process exited, code=exited, status=1/FAILURE  <<<<<<
Jan 26 04:10:08 dell-per750-08 systemd[1]: nfs-idmapd.service: Failed with result 'exit-code'.                     <<<<<<
Jan 26 04:10:08 dell-per750-08 systemd[1]: Stopped NFSv4 ID-name mapping service.
[root@dell-per750-08 ~]# rpm -q systemd
systemd-249-9.el9.x86_64
[root@dell-per750-08 ~]#

I'm changing this under component systemd for now.

Comment 4 David Tardon 2022-01-26 13:21:08 UTC
(In reply to Yongcheng Yang from comment #0)
> Sep 07 02:44:02 rhel-9-latest systemd[1]: nfs-idmapd.service: Main process
> exited, code=exited, status=1/FAILURE

rpc.idmapd exited with exit code 1, which means a failure. Either fix that or, if rpc.idmapd really should do this, add SuccessExitStatus=1 to the unit file.

Comment 5 Yongcheng Yang 2022-02-17 14:18:04 UTC
(In reply to David Tardon from comment #4)
> (In reply to Yongcheng Yang from comment #0)
> > Sep 07 02:44:02 rhel-9-latest systemd[1]: nfs-idmapd.service: Main process
> > exited, code=exited, status=1/FAILURE
> 
> rpc.idmapd exited with exit code 1, which means a failure. Either fix that
> or, if rpc.idmapd really should do this, add SuccessExitStatus=1 to the unit
> file.

Thanks for the information!

And there's a patch sent to upstream recently: 
https://patchwork.kernel.org/project/linux-nfs/patch/20220218012732.1549586-1-haowenchao@huawei.com/

Comment 6 Yongcheng Yang 2022-03-07 13:03:59 UTC
We may need this nfs-utils upstream patch:

commit 9abd3b4b57155dfdfd6895e6086ef550ee56fc49
Author: Wenchao Hao <haowenchao>
Date:   Tue Feb 22 16:06:51 2022 -0500

    idmapd: Fix error status when nfs-idmapd exits

Comment 20 errata-xmlrpc 2022-11-15 11:22:03 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (nfs-utils bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:8376