Bug 52959 - univention-register-network-address not called during startup - new ip (dhcp) not set
univention-register-network-address not called during startup - new ip (dhcp)...
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: General
UCS 5.0
Other Linux
: P5 normal (vote)
: UCS 5.0
Assigned To: Arvid Requate
Felix Botner
: interim-2
Depends on:
Blocks: 54664
  Show dependency treegraph
 
Reported: 2021-03-19 13:36 CET by Felix Botner
Modified: 2022-04-12 12:55 CEST (History)
3 users (show)

See Also:
What kind of report is it?: Development Internal
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
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 Felix Botner univentionstaff 2021-03-19 13:36:50 CET
joined master template, old ip 10.207.65.72
new instance with ip 10.207.65.94

-> univention-ldapsearch arecord=10.207.65.94
-> univention-ldapsearch -LLL arecord=10.207.65.72 dn
dn: relativeDomainName=master,zoneName=autotest.local,cn=dns,dc=autotest,dc=local
dn: cn=master,cn=dc,cn=computers,dc=autotest,dc=local
dn: relativeDomainName=ucs-sso,zoneName=autotest.local,cn=dns,dc=autotest,dc=local

This works with UCS 4.4.

In UCS 5 there is only one place where we register the new address

 /etc/network/if-up.d/90_dns_update

but it seems that this check in 90_dns_update

 if /bin/netcat -q0 -w1 "$ldap_master" 6670

is not compatible with the boot oder, UMC (6670) is started after ifup (added set -x to 90_dns_update)

   -> journalctl  -b| grep --regex 'netca\|management-con'
 ! Mär 19 13:13:32 master ifup[364]: + /bin/netcat -q0 -w1 master.autotest.local 6670
   Mär 19 13:13:33 master slapd[739]: Loaded metadata from "/usr/share/univention-management-console/saml/idp/ucs-sso.autotest.local.xml
 ! Mär 19 13:13:36 master univention-management-console-server[781]: Starting Univention Management Console Server: univention-management-console-server.
 ! Mär 19 13:13:50 master univention-management-console-web-server[907]: Starting Univention Management Console Web Server: univention-management-console-web-server.

In UCS 4.4 we have two services 

  /etc/init.d/univention-network-common
  /etc/network/if-up.d/90_dns_update

   -> journalctl  -b| grep --regex 'univention-network-comm\|univention-mana'
 ! Mär 19 13:29:24 master univention-management-console-server[747]: Starting Univention Management Console Server: univention-management-console-server.
 ! Mär 19 13:29:26 master univention-management-console-web-server[795]: Starting Univention Management Console Web Server: univention-management-console-web-server.
   Mär 19 13:29:40 master python2.7[760]: pam_unix(univention-management-console:auth): check pass; user unknown
   Mär 19 13:29:40 master python2.7[760]: pam_unix(univention-management-console:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=
   Mär 19 13:29:40 master python2.7[760]: pam_krb5(univention-management-console:auth): authentication failure; logname=master$ uid=0 euid=0 tty= ruser= rhost=
   Mär 19 13:29:44 master slapd[1518]: Loaded metadata from "/usr/share/univention-management-console/saml/idp/ucs-sso.autotest.local.xml
   Mär 19 13:29:46 master python2.7[760]: pam_unix(univention-management-console:auth): check pass; user unknown
   Mär 19 13:29:46 master python2.7[760]: pam_unix(univention-management-console:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=
   Mär 19 13:29:47 master python2.7[760]: pam_krb5(univention-management-console:auth): user master$ authenticated as master$@AUTOTEST.LOCAL
   Mär 19 13:29:47 master python2.7[760]: pam_unix(univention-management-console:account): could not identify user (from getpwnam(master$))
 ! Mär 19 13:29:50 master univention-network-common[1168]: save DHCP address in LDAP...done.

and probably only univention-network-common works.
Comment 1 Felix Botner univentionstaff 2021-03-19 13:48:28 CET
to reproduce:

git pull
DOCKER=true ./utils/start-test.sh scenarios/base/master-role-template.cfg
Comment 2 Felix Botner univentionstaff 2021-03-23 10:34:57 CET
OK, univention-network-common still exists (as systemd service) but it is not started/not correctly started upon system startup

-> service univention-network-common status
● univention-network-common.service - Register current IP addresses in LDAP directory
   Loaded: loaded (/lib/systemd/system/univention-network-common.service; disabled; vendor preset: enabled)


once started manually, it works

-> service univention-network-common start
root@master:~# service univention-network-common status
● univention-network-common.service - Register current IP addresses in LDAP directory
   Loaded: loaded (/lib/systemd/system/univention-network-common.service; disabled; vendor preset: enabled)
   Active: inactive (dead)
Comment 3 Philipp Hahn univentionstaff 2021-03-23 16:18:25 CET
/usr/sbin/univention-register-network-address should be called from /etc/dhcp/dhclient-exit-hooks.d/ on IP address change.

#!/bin/sh
case "${reason:-}" in
BOUND|RENEW|REBIND|REBOOT)
  [ "${new_ip_address:-}" = "${old_ip_address:-}" ] ||
    /usr/sbin/univention-register-network-address
  ;;
esac

Also see <man:dhclient-script(8)>
Comment 4 Felix Botner univentionstaff 2021-03-23 17:12:39 CET
(In reply to Philipp Hahn from comment #3)
> /usr/sbin/univention-register-network-address should be called from
> /etc/dhcp/dhclient-exit-hooks.d/ on IP address change.
> 
> #!/bin/sh
> case "${reason:-}" in
> BOUND|RENEW|REBIND|REBOOT)
>   [ "${new_ip_address:-}" = "${old_ip_address:-}" ] ||
>     /usr/sbin/univention-register-network-address
>   ;;
> esac
> 
> Also see <man:dhclient-script(8)>

The problem i see is that during boot this is probably called before the umc startup, and we change the ip via umc


from Bug #32847

(In reply to Philipp Hahn from comment #6)
> (In reply to Felix Botner from comment #5)
> > is Bug 52959 a duplicate, do we want to fix this before UCS 5.0
> 
> /usr/sbin/univention-register-network-address not being called is an old
> bug, which is not related to the removal of ifplugd.

Not sure about that, with bug #32847 we converted /etc/init.d/univention-network-common to systemd. But this service is not correctly started during boot wuth UCS 5.0-0. So it looks like a regression.

But before we go on, one question, is this release critical?
Comment 5 Florian Best univentionstaff 2021-03-23 17:31:00 CET
See also Bug #42128 for the possible cause, which changed the dependency from a running UMC-Server to a running UMC-Web-Server and Apache during startup.
Comment 6 Philipp Hahn univentionstaff 2021-03-24 13:39:58 CET
> (In reply to Philipp Hahn from comment #6)
> > (In reply to Felix Botner from comment #5)
> > > is Bug 52959 a duplicate, do we want to fix this before UCS 5.0
> > 
> > /usr/sbin/univention-register-network-address not being called is an old
> > bug, which is not related to the removal of ifplugd.
> 
> Not sure about that, with bug #32847 we converted
> /etc/init.d/univention-network-common to systemd. But this service is not
> correctly started during boot with UCS 5.0-0. So it looks like a regression.

You are right, the bug was introduced via Bug #32847 by me which also converted the init-script into a systemd.service, but forgot to add "dh --with systemd" in debian/rules.
This leads to /var/lib/dpkg/info/univention-network-common.postinst not getting the hunk to enable the service.

> But before we go on, one question, is this release critical?

Probably not, but I fixed it anyway as univention-networking-common has many more errors which I noticed while testing yesterday:

- etc/network/if-up.d/00_resolvconf vs etc/dhcp/dhclient-enter-hooks.d/resolvconf
- etc/network/if-up.d/12_univention_config_registry needs to go to etc/dhcp/dhclient-exit-hooks.d/
- there is a 15s+ delay caused by networking.service

> Startup finished in 16.747s (kernel) + 2min 30.119s (userspace) = 2min 46.867s graphical.target reached after 2min 30.101s in userspace
> journalctl  -u networking.service -b
Mär 24 13:05:52 dev38 ifup[370]: run-parts: executing 
Mär 24 13:06:04
...
Mär 24 13:06:05 dev38 ifup[370]: run-parts: executing /etc/network/if-pre-up.d/10_dhclientconf
Mär 24 13:06:10
...
Mär 24 13:06:10 dev38 ifup[370]: run-parts: executing /etc/network/if-up.d/90_dns_update
Mär 24 13:06:19
Comment 7 Felix Botner univentionstaff 2021-03-24 15:17:43 CET
(In reply to Philipp Hahn from comment #6)
> > (In reply to Philipp Hahn from comment #6)
> > > (In reply to Felix Botner from comment #5)
> > > > is Bug 52959 a duplicate, do we want to fix this before UCS 5.0
> > > 
> > > /usr/sbin/univention-register-network-address not being called is an old
> > > bug, which is not related to the removal of ifplugd.
> > 
> > Not sure about that, with bug #32847 we converted
> > /etc/init.d/univention-network-common to systemd. But this service is not
> > correctly started during boot with UCS 5.0-0. So it looks like a regression.
> 
> You are right, the bug was introduced via Bug #32847 by me which also
> converted the init-script into a systemd.service, but forgot to add "dh
> --with systemd" in debian/rules.
> This leads to /var/lib/dpkg/info/univention-network-common.postinst not
> getting the hunk to enable the service.
> 
> > But before we go on, one question, is this release critical?
> 
> Probably not, but I fixed it anyway as univention-networking-common has many
> more errors which I noticed while testing yesterday:

great
Comment 8 Felix Botner univentionstaff 2021-04-09 09:47:56 CEST
This is rather unpleasant for our internal KVM test images, especially if we want to use pre-joined images as their dns settings are not updated. Would be nice to fix this with UCS 5.0.
Comment 9 Arvid Requate univentionstaff 2021-05-10 17:32:47 CEST
Proposal: https://git.knut.univention.de/univention/ucs/-/tree/arequate/bug52959

The other cleanups proposed in Comment 6 seem like SHOULD, not MUST currently to me.
Comment 10 Arvid Requate univentionstaff 2021-05-11 11:09:51 CEST
fe73d35740 | Fix regression of Bug #32847

Package: univention-server
Version: 15.0.4-4A~5.0.0.202105111107
Branch: ucs_5.0-0

Package: univention-network-manager
Version: 12.0.2-3A~5.0.0.202105111105
Branch: ucs_5.0-0
Comment 11 Felix Botner univentionstaff 2021-05-11 13:37:55 CEST
still fails as  univention-network-common.service is started before UMC:



Mai 11 13:31:58 master systemd[1]: univention-network-common.service: Main process exited, code=exited, status=1/FAILURE
Mai 11 13:31:58 master systemd[1]: univention-network-common.service: Failed with result 'exit-code'.
Mai 11 13:31:58 master systemd[1]: Failed to start Register current IP addresses in LDAP directory.
...
Mai 11 13:32:00 master univention-management-console-server[760]: Starting Univention Management Console Server: univention-management-console-server.
...
Mai 11 13:32:06 master univention-management-console-web-server[875]: Starting Univention Management Console Web Server: univention-management-console-web-server.
Mai 11 13:32:06 master systemd[1]: Started LSB: Univention Management Console Web Server.
Mai 11 13:32:06 master systemd[1]: Reached target Start UMC-Web-Server in multiprocessing mode.
Comment 12 Arvid Requate univentionstaff 2021-05-11 16:27:05 CEST
f12ab8f2be | make univention-network-common unit wait for UMC-web-server

Package: univention-network-manager
Version: 12.0.2-4A~5.0.0.202105111626
Branch: ucs_5.0-0
Comment 13 Felix Botner univentionstaff 2021-05-11 17:28:02 CEST
looks better, but still fail 

Mai 11 17:20:41 master univention-management-console-server[761]: Starting Univention Management Console Server: univention-management-console-server.
Mai 11 17:20:48 master univention-management-console-web-server[882]: Starting Univention Management Console Web Server: univention-management-console-web-server.

Mai 11 17:20:48 master systemd[1]: Reached target Start UMC-Web-Server in multiprocessing mode.
Mai 11 17:20:48 master CRON[628]: pam_unix(cron:session): session closed for user root
Mai 11 17:20:49 master systemd[1]: Started The Apache HTTP Server.
Mai 11 17:20:49 master systemd[1]: Started Univention Portal server.

Mai 11 17:20:50 master univention-register-network-address[1417]: ServiceUnavailable: 503 on master.five.new (auth): {'status': 503, 'message': 'The Univention Management Console Web Server could not be reached.
Mai 11 17:20:50 master systemd[1]: univention-network-common.service: Main process exited, code=exited, status=1/FAILURE
Mai 11 17:20:50 master systemd[1]: univention-network-common.service: Failed with result 'exit-code'.
Mai 11 17:20:50 master systemd[1]: Failed to start Register current IP addresses in LDAP directory.
Mai 11 17:20:50 master univention-portal-server[1416]: Building portal umc

seems that although UMC has been started, it is not immediately functional
Comment 14 Arvid Requate univentionstaff 2021-05-11 19:48:16 CEST
53891c7594 | make univention-network-common retry 4 times with 5 sec delay

Version: 12.0.2-5A~5.0.0.202105111942
Comment 15 Florian Best univentionstaff 2021-05-11 20:37:42 CEST
maybe ConditionPathExists=/var/run/univention-management-console/server.socket helps.
Comment 16 Arvid Requate univentionstaff 2021-05-11 21:26:48 CEST
As discussed, we don't really want to depend on the local UMC-web-server on all systems.
As war as I understood you, the UMC-web-call requires the master to be up (and reachable).
The way we did it now is that the systemd servivce retries 4 times if the script fails.
Comment 17 Felix Botner univentionstaff 2021-05-12 10:29:31 CEST
sorry, this doesn't work as intended 

during boot univention-network-common.service is now restarted multiple times (seem that the limits don't apply/work) and the system is filled up with ipchange umc processes

-> ps aux| grep ipch| wc -l
46

maybe we could revert the service changes and move the retry to /usr/sbin/univention-register-network-address itself (except ServiceUnavailable as exc:)
Comment 18 Arvid Requate univentionstaff 2021-05-12 12:13:42 CEST
6fe948df62 | Let univention-register-network-address do the retries

Version: 12.0.2-5A~5.0.0.202105121206
Comment 19 Felix Botner univentionstaff 2021-05-12 14:38:25 CEST
OK - boot with ip change

● univention-network-common.service - Register current IP addresses in LDAP directory
   Loaded: loaded (/lib/systemd/system/univention-network-common.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Wed 2021-05-12 13:50:00 CEST; 27s ago
  Process: 1333 ExecStart=/usr/sbin/univention-register-network-address (code=exited, status=0/SUCCESS)
 Main PID: 1333 (code=exited, status=0/SUCCESS)

Mai 12 13:49:52 master systemd[1]: Starting Register current IP addresses in LDAP directory...
Mai 12 13:50:00 master univention-register-network-address[1333]: INFO: Retry (1/4) in 5 seconds.
Mai 12 13:50:00 master systemd[1]: univention-network-common.service: Succeeded.
Mai 12 13:50:00 master systemd[1]: Started Register current IP addresses in LDAP directory.
root@master:~# univention-ldapsearch arecord=* arecord


OK - boot with no ip change

● univention-network-common.service - Register current IP addresses in LDAP directory
   Loaded: loaded (/lib/systemd/system/univention-network-common.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Wed 2021-05-12 13:54:28 CEST; 12s ago
  Process: 1344 ExecStart=/usr/sbin/univention-register-network-address --verbose (code=exited, status=1/FAILURE)
 Main PID: 1344 (code=exited, status=1/FAILURE)

Mai 12 13:54:21 master systemd[1]: Starting Register current IP addresses in LDAP directory...
Mai 12 13:54:28 master univention-register-network-address[1344]: ServiceUnavailable: 503 on master.five.new (auth): {'status': 503, 'message': 'The Univention Management Console Web Server could not be reached.
Mai 12 13:54:28 master univention-register-network-address[1344]: BadRequest: 400 on master.five.new (command/ip/change): {'status': 400, 'message': 'The IP address is already in use by host record(s) for: maste
Mai 12 13:54:28 master univention-register-network-address[1344]: INFO: Retry (1/4) in 5 seconds.
Mai 12 13:54:28 master systemd[1]: univention-network-common.service: Main process exited, code=exited, status=1/FAILURE
Mai 12 13:54:28 master systemd[1]: univention-network-common.service: Failed with result 'exit-code'.
Mai 12 13:54:28 master systemd[1]: Failed to start Register current IP addresses in LDAP directory.

OK - no dhcp

● univention-network-common.service - Register current IP addresses in LDAP directory
   Loaded: loaded (/lib/systemd/system/univention-network-common.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Wed 2021-05-12 13:57:00 CEST; 33min ago
  Process: 1307 ExecStart=/usr/sbin/univention-register-network-address --verbose (code=exited, status=0/SUCCESS)
 Main PID: 1307 (code=exited, status=0/SUCCESS)

Mai 12 13:56:59 master systemd[1]: Starting Register current IP addresses in LDAP directory...
Mai 12 13:57:00 master univention-register-network-address[1307]: INFO: eth0 is not configured as dhcp device.
Mai 12 13:57:00 master systemd[1]: univention-network-common.service: Succeeded.
Mai 12 13:57:00 master systemd[1]: Started Register current IP addresses in LDAP directory.

nameserver1 and dns/forwarder1 are correctly set (nameserver1 -> own ip, dns/forwarder1 -> dhcp nameserver)

no changelog entry necessary
Comment 20 Florian Best univentionstaff 2021-05-25 16:00:49 CEST
UCS 5.0 has been released:
 https://docs.software-univention.de/release-notes-5.0-0-en.html
 https://docs.software-univention.de/release-notes-5.0-0-de.html

If this error occurs again, please use "Clone This Bug".