[GH-ISSUE #54] Race condition exists in 050-openldap-populate #36

Open
opened 2026-02-27 16:47:44 +03:00 by kerem · 0 comments
Owner

Originally created by @marcboudreau on GitHub (Jun 26, 2024).
Original GitHub issue: https://github.com/rroemhild/docker-test-openldap/issues/54

On occasion, some of our tests that use this Docker image fail due to a race condition that exists in the /etc/cont-init.d/050-openldap-populate script. This condition is somewhat rare, but it does contribute to failures in some of our most flaky tests.

What's Going On

In the 050-openldap-populate script (referred to as SCRIPT from here on in), the LDAP server is started with the slapd -h "ldapi:///" -u openldap -g openldap command and then the configure_msad_features function is invoked. That function contains an echo statement and then executes this command: ldapmodify -Y EXTERNAL -H ldapi:/// -f ${CONFIG_DIR}/msad.ldif -Q. On some occasions, where presumably the GitHub runners that we are using are overloaded, we can capture this output from the Docker container running this image:

2024-06-18T21:25:37.600523518Z  [s6-init] making user provided files available at /var/run/s6/etc...exited 0.
2024-06-18T21:25:37.792060071Z  [s6-init] ensuring user provided files have correct perms...exited 0.
2024-06-18T21:25:37.795724762Z  [fix-attrs.d] applying ownership & permissions fixes...
2024-06-18T21:25:37.806944065Z  [fix-attrs.d] done.
2024-06-18T21:25:37.813947029Z  [cont-init.d] executing container initialization scripts...
2024-06-18T21:25:37.821652710Z  [cont-init.d] 000-slapd-package-config: executing... 
2024-06-18T21:25:37.827773436Z  + echo 'Reconfigure slapd...'
2024-06-18T21:25:37.827892462Z  Reconfigure slapd...
2024-06-18T21:25:37.828447892Z  + debconf-set-selections
2024-06-18T21:25:37.828944220Z  + cat
2024-06-18T21:25:37.963064170Z  + DEBIAN_FRONTEND=noninteractive
2024-06-18T21:25:37.963096642Z  + dpkg-reconfigure slapd
2024-06-18T21:25:38.132817191Z    Backing up /etc/ldap/slapd.d in /var/backups/slapd-2.4.47+dfsg-3+deb10u7... done.
2024-06-18T21:25:38.134897675Z    Moving old database directory to /var/backups:
2024-06-18T21:25:38.150842147Z    - directory unknown... done.
2024-06-18T21:25:38.215515767Z    Creating initial configuration... done.
2024-06-18T21:25:38.335932077Z    Creating LDAP directory... done.
2024-06-18T21:25:38.353411954Z  invoke-rc.d: could not determine current runlevel
2024-06-18T21:25:38.362586156Z  invoke-rc.d: policy-rc.d denied execution of restart.
2024-06-18T21:25:38.417781107Z  [cont-init.d] 000-slapd-package-config: exited 0.
2024-06-18T21:25:38.428640931Z  [cont-init.d] 010-tls-certificates: executing... 
2024-06-18T21:25:38.433227493Z  Make self-signed certificate for planetexpress.com...
2024-06-18T21:25:38.433285086Z  + [[ -f /etc/ldap/ssl/ldap.key ]]
2024-06-18T21:25:38.434368875Z  + echo 'Make self-signed certificate for planetexpress.com...'
2024-06-18T21:25:38.434376265Z  + openssl req -subj /CN=planetexpress.com -new -newkey rsa:2048 -days 365 -nodes -x509 -keyout /etc/ldap/ssl/ldap.key -out /etc/ldap/ssl/ldap.crt
2024-06-18T21:25:38.438796858Z  Generating a RSA private key
2024-06-18T21:25:38.469321748Z  .............................................+++++
2024-06-18T21:25:38.487181626Z  ........................+++++
2024-06-18T21:25:38.487420649Z  writing new private key to '/etc/ldap/ssl/ldap.key'
2024-06-18T21:25:38.487513484Z  -----
2024-06-18T21:25:38.490841946Z  + chmod 600 /etc/ldap/ssl/ldap.key
2024-06-18T21:25:38.496541338Z  [cont-init.d] 010-tls-certificates: exited 0.
2024-06-18T21:25:38.508690273Z  [cont-init.d] 020-filesystem-perms: executing... 
2024-06-18T21:25:38.513116365Z  + chown -R openldap:openldap /etc/ldap
2024-06-18T21:25:38.682975972Z  [cont-init.d] 020-filesystem-perms: exited 0.
2024-06-18T21:25:38.707501044Z  [cont-init.d] 050-openldap-populate: executing... 
2024-06-18T21:25:38.728119862Z  + slapd -h ldapi:/// -u openldap -g openldap
2024-06-18T21:25:39.159486831Z  + configure_msad_features
2024-06-18T21:25:39.159705233Z  + echo 'Configure MS-AD Extensions'
2024-06-18T21:25:39.159715374Z  + ldapmodify -Y EXTERNAL -H ldapi:/// -f /opt/openldap/bootstrap/config/msad.ldif -Q
2024-06-18T21:25:39.159767837Z  Configure MS-AD Extensions
2024-06-18T21:25:39.165172292Z  ldap_sasl_interactive_bind_s: Can't contact LDAP server (-1)
2024-06-18T21:25:39.175830996Z  [cont-init.d] 050-openldap-populate: exited 255.
2024-06-18T21:25:39.177517108Z  [cont-init.d] done.
2024-06-18T21:25:39.181471175Z  [services.d] starting services
2024-06-18T21:25:39.208770029Z  starting slapd
2024-06-18T21:25:39.215196060Z  6671fb53 @(#) $OpenLDAP: slapd  (May 14 2022 18:35:44) $
2024-06-18T21:25:39.215214791Z  	Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org>
2024-06-18T21:25:39.221658274Z  [services.d] done.
2024-06-18T21:25:39.643752375Z  6671fb53 hdb_db_open: database "dc=planetexpress,dc=com": database already in use.
2024-06-18T21:25:39.643883763Z  6671fb53 backend_startup_one (type=hdb, suffix="dc=planetexpress,dc=com"): bi_db_open failed! (-1)
2024-06-18T21:25:39.644065383Z  6671fb53 slapd stopped.
2024-06-18T21:25:40.202778182Z  starting slapd
2024-06-18T21:25:40.208287133Z  6671fb54 @(#) $OpenLDAP: slapd  (May 14 2022 18:35:44) $
2024-06-18T21:25:40.208304754Z  	Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org>
2024-06-18T21:25:40.591516907Z  6671fb54 hdb_db_open: database "dc=planetexpress,dc=com": database already in use.
2024-06-18T21:25:40.591640264Z  6671fb54 backend_startup_one (type=hdb, suffix="dc=planetexpress,dc=com"): bi_db_open failed! (-1)
2024-06-18T21:25:40.591978003Z  6671fb54 slapd stopped.

(... the slapd service continues to be started only to immediately fail)

The logs suggest that the ldapmodify command began executing before the LDAP server was ready to accept connections. Furthermore, because the e option is set in this Bash script, the failure of the ldapmodify command causes an immediate exit of the script, which leaves the LDAP server running and causes the endless loop of restarts of the slapd service.

Originally created by @marcboudreau on GitHub (Jun 26, 2024). Original GitHub issue: https://github.com/rroemhild/docker-test-openldap/issues/54 On occasion, some of our tests that use this Docker image fail due to a race condition that exists in the `/etc/cont-init.d/050-openldap-populate` script. This condition is somewhat rare, but it does contribute to failures in some of our most flaky tests. ## What's Going On In the 050-openldap-populate script (referred to as SCRIPT from here on in), the LDAP server is started with the `slapd -h "ldapi:///" -u openldap -g openldap` command and then the **configure_msad_features** function is invoked. That function contains an echo statement and then executes this command: `ldapmodify -Y EXTERNAL -H ldapi:/// -f ${CONFIG_DIR}/msad.ldif -Q`. On some occasions, where presumably the GitHub runners that we are using are overloaded, we can capture this output from the Docker container running this image: ``` 2024-06-18T21:25:37.600523518Z [s6-init] making user provided files available at /var/run/s6/etc...exited 0. 2024-06-18T21:25:37.792060071Z [s6-init] ensuring user provided files have correct perms...exited 0. 2024-06-18T21:25:37.795724762Z [fix-attrs.d] applying ownership & permissions fixes... 2024-06-18T21:25:37.806944065Z [fix-attrs.d] done. 2024-06-18T21:25:37.813947029Z [cont-init.d] executing container initialization scripts... 2024-06-18T21:25:37.821652710Z [cont-init.d] 000-slapd-package-config: executing... 2024-06-18T21:25:37.827773436Z + echo 'Reconfigure slapd...' 2024-06-18T21:25:37.827892462Z Reconfigure slapd... 2024-06-18T21:25:37.828447892Z + debconf-set-selections 2024-06-18T21:25:37.828944220Z + cat 2024-06-18T21:25:37.963064170Z + DEBIAN_FRONTEND=noninteractive 2024-06-18T21:25:37.963096642Z + dpkg-reconfigure slapd 2024-06-18T21:25:38.132817191Z Backing up /etc/ldap/slapd.d in /var/backups/slapd-2.4.47+dfsg-3+deb10u7... done. 2024-06-18T21:25:38.134897675Z Moving old database directory to /var/backups: 2024-06-18T21:25:38.150842147Z - directory unknown... done. 2024-06-18T21:25:38.215515767Z Creating initial configuration... done. 2024-06-18T21:25:38.335932077Z Creating LDAP directory... done. 2024-06-18T21:25:38.353411954Z invoke-rc.d: could not determine current runlevel 2024-06-18T21:25:38.362586156Z invoke-rc.d: policy-rc.d denied execution of restart. 2024-06-18T21:25:38.417781107Z [cont-init.d] 000-slapd-package-config: exited 0. 2024-06-18T21:25:38.428640931Z [cont-init.d] 010-tls-certificates: executing... 2024-06-18T21:25:38.433227493Z Make self-signed certificate for planetexpress.com... 2024-06-18T21:25:38.433285086Z + [[ -f /etc/ldap/ssl/ldap.key ]] 2024-06-18T21:25:38.434368875Z + echo 'Make self-signed certificate for planetexpress.com...' 2024-06-18T21:25:38.434376265Z + openssl req -subj /CN=planetexpress.com -new -newkey rsa:2048 -days 365 -nodes -x509 -keyout /etc/ldap/ssl/ldap.key -out /etc/ldap/ssl/ldap.crt 2024-06-18T21:25:38.438796858Z Generating a RSA private key 2024-06-18T21:25:38.469321748Z .............................................+++++ 2024-06-18T21:25:38.487181626Z ........................+++++ 2024-06-18T21:25:38.487420649Z writing new private key to '/etc/ldap/ssl/ldap.key' 2024-06-18T21:25:38.487513484Z ----- 2024-06-18T21:25:38.490841946Z + chmod 600 /etc/ldap/ssl/ldap.key 2024-06-18T21:25:38.496541338Z [cont-init.d] 010-tls-certificates: exited 0. 2024-06-18T21:25:38.508690273Z [cont-init.d] 020-filesystem-perms: executing... 2024-06-18T21:25:38.513116365Z + chown -R openldap:openldap /etc/ldap 2024-06-18T21:25:38.682975972Z [cont-init.d] 020-filesystem-perms: exited 0. 2024-06-18T21:25:38.707501044Z [cont-init.d] 050-openldap-populate: executing... 2024-06-18T21:25:38.728119862Z + slapd -h ldapi:/// -u openldap -g openldap 2024-06-18T21:25:39.159486831Z + configure_msad_features 2024-06-18T21:25:39.159705233Z + echo 'Configure MS-AD Extensions' 2024-06-18T21:25:39.159715374Z + ldapmodify -Y EXTERNAL -H ldapi:/// -f /opt/openldap/bootstrap/config/msad.ldif -Q 2024-06-18T21:25:39.159767837Z Configure MS-AD Extensions 2024-06-18T21:25:39.165172292Z ldap_sasl_interactive_bind_s: Can't contact LDAP server (-1) 2024-06-18T21:25:39.175830996Z [cont-init.d] 050-openldap-populate: exited 255. 2024-06-18T21:25:39.177517108Z [cont-init.d] done. 2024-06-18T21:25:39.181471175Z [services.d] starting services 2024-06-18T21:25:39.208770029Z starting slapd 2024-06-18T21:25:39.215196060Z 6671fb53 @(#) $OpenLDAP: slapd (May 14 2022 18:35:44) $ 2024-06-18T21:25:39.215214791Z Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org> 2024-06-18T21:25:39.221658274Z [services.d] done. 2024-06-18T21:25:39.643752375Z 6671fb53 hdb_db_open: database "dc=planetexpress,dc=com": database already in use. 2024-06-18T21:25:39.643883763Z 6671fb53 backend_startup_one (type=hdb, suffix="dc=planetexpress,dc=com"): bi_db_open failed! (-1) 2024-06-18T21:25:39.644065383Z 6671fb53 slapd stopped. 2024-06-18T21:25:40.202778182Z starting slapd 2024-06-18T21:25:40.208287133Z 6671fb54 @(#) $OpenLDAP: slapd (May 14 2022 18:35:44) $ 2024-06-18T21:25:40.208304754Z Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org> 2024-06-18T21:25:40.591516907Z 6671fb54 hdb_db_open: database "dc=planetexpress,dc=com": database already in use. 2024-06-18T21:25:40.591640264Z 6671fb54 backend_startup_one (type=hdb, suffix="dc=planetexpress,dc=com"): bi_db_open failed! (-1) 2024-06-18T21:25:40.591978003Z 6671fb54 slapd stopped. (... the slapd service continues to be started only to immediately fail) ``` The logs suggest that the ldapmodify command began executing before the LDAP server was ready to accept connections. Furthermore, because the `e` option is set in this Bash script, the failure of the ldapmodify command causes an immediate exit of the script, which leaves the LDAP server running and causes the endless loop of restarts of the slapd service.
Sign in to join this conversation.
No labels
pull-request
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/docker-test-openldap#36
No description provided.