Bug 46875 - Upgrade to 4.3-0 failed because of rpcbind
Upgrade to 4.3-0 failed because of rpcbind
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: NFS
UCS 4.3
Other other
: P5 normal (vote)
: UCS 4.3-1-errata
Assigned To: Arvid Requate
Philipp Hahn
:
Depends on: 47190
Blocks:
  Show dependency treegraph
 
Reported: 2018-04-23 19:01 CEST by Michael Grandjean
Modified: 2018-06-20 17:11 CEST (History)
4 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 3: Will affect average number of installed domains
How will those affected feel about the bug?: 3: A User would likely not purchase the product
User Pain: 0.257
Enterprise Customer affected?: Yes
School Customer affected?: Yes
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Michael Grandjean univentionstaff 2018-04-23 19:01:25 CEST
A customer upgraded their UCS Master from UCS 4.2-3 errata 342 to 4.3-0. Installed components are samba4, dhcp-server, printserver.

The upgrade failed with:

> [...]
> rpcbind (0.2.3-0.6) wird eingerichtet ...
> Neue Version der Konfigurationsdatei /etc/init.d/rpcbind.debian wird installiert ...
> Neue Version der Konfigurationsdatei /etc/init/rpcbind-boot.conf wird installiert ...
> Neue Version der Konfigurationsdatei /etc/init/rpcbind.conf wird installiert ...
> Created symlink /etc/systemd/system/multi-user.target.wants/rpcbind.service → /lib/systemd/system/rpcbind.service.
> Created symlink /etc/systemd/system/sockets.target.wants/rpcbind.socket → /lib/systemd/system/rpcbind.socket.
> A dependency job for rpcbind.service failed. See 'journalctl -xe' for details.
> invoke-rc.d: initscript rpcbind, action "start" failed.
> ● rpcbind.service - RPC bind portmap service
>    Loaded: loaded (/lib/systemd/system/rpcbind.service; enabled; vendor preset: enabled)
>    Active: active (exited) (Result: exit-code) since Thu 2018-04-05 21:25:36 CEST; 2 weeks 3 days ago
>      Docs: man:rpcbind(8)
>  Main PID: 974 (code=exited, status=2)
>    CGroup: /system.slice/portmap.service
> 
> Apr 23 16:21:22 ucs1 systemd[1]: Stopping LSB: RPC portmapper replacement...
> Apr 23 16:21:22 ucs1 rpcbind[20785]: Stopping rpcbind daemon....
> Apr 23 16:21:22 ucs1 systemd[1]: rpcbind.service: main process exited, code…MENT
> Apr 23 16:21:22 ucs1 systemd[1]: Stopped LSB: RPC portmapper replacement.
> Apr 23 16:21:22 ucs1 systemd[1]: Unit rpcbind.service entered failed state.
> Apr 23 16:36:43 ucs1 systemd[1]: Dependency failed for RPC bind portmap service.
> Apr 23 16:36:43 ucs1 systemd[1]: rpcbind.service: Job rpcbind.service/start…cy'.
> Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
> Hint: Some lines were ellipsized, use -l to show in full.
> dpkg: Fehler beim Bearbeiten des Paketes rpcbind (--configure):
>  Unterprozess installiertes post-installation-Skript gab den Fehlerwert 1 zurück

As a consequence and because of dependencies this affected also:

> Fehler traten auf beim Bearbeiten von:
>  rpcbind
>  nfs-common
>  nfs-kernel-server
>  univention-home-mounter
>  univention-nfs-server
>  univention-role-server-common
>  univention-bind
>  univention-server-master

This was easily fixed with "dpkg --configure -a", but afterwards the the UMC was not usable. "univention-management-console-server" and "univention-management-console-web-server" were reported as "active (exited)" by systemctl. A "restart" or "start" of the service seemed successful, but the process died immediately without logging any information. However, this was magically fixed after rebooting the server.
Comment 1 Andreas Peichert univentionstaff 2018-06-08 14:40:10 CEST
Happens again while updating from 4.2-4 errata 418 to UCS 4.3-0 for paedML

Problem is that a rpcbind service is still running and fails to start. After stopping them all, reconfigure, univention-upgrade will continue the update

root@server:~# systemctl stop rpcbind.*
root@server:~# dpkg --configure -a
Comment 2 Philipp Hahn univentionstaff 2018-06-08 14:54:55 CEST
> A dependency job for rpcbind.service failed. See 'journalctl -xe' for details.

$ systemctl cat rpcbind.service
# /lib/systemd/system/rpcbind.service
...
Requires=rpcbind.socket

My guess is that an old rpcbind is still running and blocks the socket for the new process. This is what Andreas reported, too:

(In reply to Andreas Peichert from comment #1)
> Problem is that a rpcbind service is still running and fails to start. After
> stopping them all, reconfigure, univention-upgrade will continue the update

The service is supposed to be stopped by /var/lib/dpkg/info/rpcbind.prerm before the upgrade.
Please provide the relevant part of /var/log/apt/term.log
Comment 3 Andreas Peichert univentionstaff 2018-06-13 09:27:50 CEST
/var/lib/dpkg/info/rpcbind.prerm did a "invoke-rc.d rpcbind stop" but

the socket is inactive afterwards

root@server:~# systemctl status rpcbind.socket
● rpcbind.socket - RPCbind Server Activation Socket
   Loaded: loaded (/lib/systemd/system/rpcbind.socket; enabled; vendor preset: enabled)
   Active: inactive (dead)
   Listen: /run/rpcbind.sock (Stream)
                                                                                                                                                                                                  
Jun 12 15:31:33 server systemd[1]: rpcbind.socket: Socket service rpcbind.service already active, refusing.
Jun 12 15:31:33 server systemd[1]: Failed to listen on RPCbind Server Activation Socket.

the service seems active:

root@server:~# systemctl status rpcbind.
rpcbind.service  rpcbind.socket   rpcbind.target   
root@server:~# systemctl status rpcbind.service 
● rpcbind.service - RPC bind portmap service
   Loaded: loaded (/lib/systemd/system/rpcbind.service; enabled; vendor preset: enabled)
   Active: active (exited) (Result: exit-code) since Tue 2018-06-12 14:45:25 CEST; 18h ago
     Docs: man:rpcbind(8)
 Main PID: 667 (code=exited, status=2)
    Tasks: 0 (limit: 4915)
   Memory: 0B
      CPU: 0
   CGroup: /system.slice/portmap.service

Jun 12 14:45:25 server systemd[1]: Starting LSB: RPC portmapper replacement...
Jun 12 14:45:25 server rpcbind[654]: Starting rpcbind daemon....
Jun 12 14:45:25 server systemd[1]: Started LSB: RPC portmapper replacement.
Jun 12 15:10:56 server systemd[1]: Stopping LSB: RPC portmapper replacement...
Jun 12 15:10:56 server rpcbind[3069]: Stopping rpcbind daemon....
Jun 12 15:10:56 server systemd[1]: rpcbind.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Jun 12 15:10:56 server systemd[1]: Stopped LSB: RPC portmapper replacement.
Jun 12 15:10:56 server systemd[1]: Unit rpcbind.service entered failed state.
Jun 12 15:31:33 server systemd[1]: Dependency failed for RPC bind portmap service.
Jun 12 15:31:33 server systemd[1]: rpcbind.service: Job rpcbind.service/start failed with result 'dependency'.

also the target:

root@server:~# systemctl status rpcbind.target 
● rpcbind.target - RPC Port Mapper
   Loaded: loaded (/lib/systemd/system/rpcbind.target; static; vendor preset: enabled)
   Active: active since Tue 2018-06-12 15:31:33 CEST; 17h ago
     Docs: man:systemd.special(7)

Jun 12 15:31:33 server systemd[1]: Reached target RPC Port Mapper.
Comment 5 Arvid Requate univentionstaff 2018-06-13 21:40:45 CEST
rpcbind in UCS 4.2 just shipped an init.d script and the systemd.service was generated. When the init.d script uses start-stop-daemon to stop the process, rpcbind exists with returncode 2, and systemd detects that as "(code=exited, status=2)" for the Main PID.

rpcbind in UCS 4.3 ships rpcbind.service, rpcbind.socket and rpcbind.target. The service Requires the socket unit to be started and that fails because the systemd source code first checks that the service state code is either of:
 SERVICE_DEAD or SERVICE_FAILED or SERVICE_AUTO_RESTART
but instead it is in
 SERVICE_EXITED
due to rpcbind returning 2 when it gets terminated.

The only two workarounds I currently see are:
a) Adjust the /run/systemd/generator.late/rpcbind.service to add
   "SuccessExitStatus=2" to its [Service] section.
   This could be implemented very bluntly like this in the UCS 4.2 rpcbind
   prerm:

   ## Adjust the unit file
   cp /run/systemd/generator.late/rpcbind.service /etc/systemd/system/
   echo "SuccessExitStatus=2" >> /etc/systemd/system/rpcbind.service
   systemctl daemon-reload
   ## then the normal
   invoke-rc.d rpcbind stop
   ## finally clean up
   rm /etc/systemd/system/rpcbind.service
   systemctl daemon-reload

   
b) patch rpcbind in UCS 4.2 to make ther terminate() function
   to return exit code 0 instead of 2.

When I look into the source code of rpcbind in 4.3 I see that they took option b), so I guess I prefer that too.
Comment 6 Arvid Requate univentionstaff 2018-06-19 15:54:47 CEST
My patch of the returncode of 4.2-4 rpcbind didn't fix the problem, so I reverted the changes:
bf6cc4891b | Advisory for rpcbind update in 4.2-4
eae9888c0c | Advisory for rpcbind update in 4.2-4
dbb079dd60 | Advisory for rpcbind update in 4.2-4 (QA)
ab634ef426 | Delete Advisory in 4.2-4

Removed package from errata4.2-4 scope, binary packages too, updated Package files and removed svn patches (0.2.1-6+deb8u2-errata4.2-4).


Instead I adjusted the preup.sh and postup.sh scripts in univention-updater:

9b8a194f58 | mask the rpcbind service during update (branch 4.3-1)
1ed92f195f | revert, should only go into 4.3-0
d35fc9886f | mask the rpcbind service during update (branch 4.3-0)


Signed and copied to both test repositories:

cp --reflink=auto -fv preup.sh* postup.sh* \
  /var/univention/buildsystem2/test_mirror/ftp/4.3/maintained/4.3-0/all/

cp --reflink=auto -fv preup.sh* postup.sh* \
  /var/univention/buildsystem2/mirror/testing/4.3/maintained/4.3-0/all/

sudo update_mirror.sh -v testing/4.3/maintained/4.3-0/all/
Comment 7 Philipp Hahn univentionstaff 2018-06-19 17:30:28 CEST
(In reply to Arvid Requate from comment #6)
> My patch of the returncode of 4.2-4 rpcbind didn't fix the problem, so I
> reverted the changes:
> bf6cc4891b | Advisory for rpcbind update in 4.2-4
> eae9888c0c | Advisory for rpcbind update in 4.2-4
> dbb079dd60 | Advisory for rpcbind update in 4.2-4 (QA)
> ab634ef426 | Delete Advisory in 4.2-4

OK

> Removed package from errata4.2-4 scope, binary packages too, updated Package
> files and removed svn patches (0.2.1-6+deb8u2-errata4.2-4).

OK: find /var/univention/buildsystem2/apt/ucs_4.2-0-errata4.2-4 -name \*rpcbind\*

> Instead I adjusted the preup.sh and postup.sh scripts in univention-updater:
> 
> 9b8a194f58 | mask the rpcbind service during update (branch 4.3-1)
> 1ed92f195f | revert, should only go into 4.3-0
> d35fc9886f | mask the rpcbind service during update (branch 4.3-0)

OK

> Signed and copied to both test repositories:
> 
> cp --reflink=auto -fv preup.sh* postup.sh* \
>   /var/univention/buildsystem2/test_mirror/ftp/4.3/maintained/4.3-0/all/

OK: curl http://apt.knut.univention.de/4.3/maintained/4.3-0/all/preup.sh
OK: curl http://apt.knut.univention.de/4.3/maintained/4.3-0/all/postup.sh

OK: gpgv --keyring /usr/share/keyrings/univention-archive-key-ucs-4x.gpg preup.sh.gpg preup.sh
OK: gpgv --keyring /usr/share/keyrings/univention-archive-key-ucs-4x.gpg postup.sh.gpg postup.sh

> cp --reflink=auto -fv preup.sh* postup.sh* \
>   /var/univention/buildsystem2/mirror/testing/4.3/maintained/4.3-0/all/
> 
> sudo update_mirror.sh -v testing/4.3/maintained/4.3-0/all/

OK: http://updates-test.software-univention.de/4.3/maintained/4.3-0/all/preup.sh
OK: http://updates-test.software-univention.de/4.3/maintained/4.3-0/all/postup.sh

OK: gpgv --keyring /usr/share/keyrings/univention-archive-key-ucs-4x.gpg preup.sh.gpg preup.sh
OK: gpgv --keyring /usr/share/keyrings/univention-archive-key-ucs-4x.gpg postup.sh.gpg postup.sh

...
Comment 8 Philipp Hahn univentionstaff 2018-06-20 06:12:12 CEST
OK: 4.2-3+321 → 4.3-1+112
Comment 9 Andreas Peichert univentionstaff 2018-06-20 16:58:54 CEST
Confirmed: updating from 4.1-4 errata442 to 4.3-1 errata112 is now possible in my test environment by using updates-test.software-univention.de
Comment 10 Arvid Requate univentionstaff 2018-06-20 17:11:42 CEST
Ok, I've copied the scripts to the offical repository and updated the mirror. Felix confirmed this.