`ipactl restart` fails with `Unknown error when retrieving list of services from LDAP: not enough values to unpack (expected 2, got 1)`

[Andrea Stacchiotti]

Hello everyone,
freshly installed ipa server on Oracle Linux 9, via the ansible role at
https://github.com/freeipa/ansible-freeipa/blob/master/roles/ipaserver/RE...

The installation goes apparently well, but if I try restarting the service I get the error
in the subject, which prevents dirsrv from starting, a debug log is at the end.

This is apparently a known issue, as https://access.redhat.com/solutions/5268961 exists to
address it, but I don't have a subscription and I found no other results on the
internet.
It seems to be an issue finding services, but `ipa service-find` finds HTTP and ldap as
expected.

Can someone help? Thanks

------------
[root@ipa-innovation opc]# ipactl start -d
ipa: DEBUG: importing all plugin modules in ipaserver.plugins...
ipa: DEBUG: importing plugin module ipaserver.plugins.aci
[...]
Starting Directory Service
ipa: DEBUG: Starting external process
ipa: DEBUG: args=['/bin/systemctl', 'start',
'dirsrv(a)PRIVATE-ACUS-EU.service']
ipa: DEBUG: Process finished, return code=0
ipa: DEBUG: Starting external process
ipa: DEBUG: args=['/bin/systemctl', 'is-active',
'dirsrv(a)PRIVATE-ACUS-EU.service']
ipa: DEBUG: Process finished, return code=0
ipa: DEBUG: stdout=active

ipa: DEBUG: stderr=
ipa: DEBUG: wait_for_open_ports: localhost [389] timeout 120
ipa: DEBUG: waiting for port: 389
ipa: DEBUG: SUCCESS: port: 389
ipa: DEBUG: Start of dirsrv(a)PRIVATE-ACUS-EU.service complete
ipa: DEBUG: Starting external process
ipa: DEBUG: args=['/bin/systemctl', 'is-active',
'dirsrv(a)PRIVATE-ACUS-EU.service']
ipa: DEBUG: Process finished, return code=0
ipa: DEBUG: stdout=active

ipa: DEBUG: stderr=
Failed to read data from service file: Unknown error when retrieving list of services from
LDAP: not enough values to unpack (expected 2, got 1)
Shutting down
ipa: DEBUG: Starting external process
ipa: DEBUG: args=['/bin/systemctl', 'stop',
'dirsrv(a)PRIVATE-ACUS-EU.service']
ipa: DEBUG: Process finished, return code=0
ipa: DEBUG: Stop of dirsrv(a)PRIVATE-ACUS-EU.service complete
ipa: DEBUG:   File
"/usr/lib/python3.9/site-packages/ipaserver/install/installutils.py", line 781,
in run_script
    return_value = main_function()

  File "/usr/lib/python3.9/site-packages/ipaserver/install/ipactl.py", line 735,
in main
    ipa_start(options)

  File "/usr/lib/python3.9/site-packages/ipaserver/install/ipactl.py", line 398,
in ipa_start
    raise IpactlError(rval=e.rval)

ipa: DEBUG: The ipactl command failed, exception: IpactlError:

[Rob Crittenden]

Andrea Stacchiotti via FreeIPA-users wrote:
>  Hello everyone,
>  freshly installed ipa server on Oracle Linux 9, via the ansible role at
> https://github.com/freeipa/ansible-freeipa/blob/master/roles/ipaserver/RE...
>  
>  The installation goes apparently well, but if I try restarting the service I get the
> error in the subject, which prevents dirsrv from starting, a debug log is at the end.
>  
>  This is apparently a known issue, as https://access.redhat.com/solutions/5268961 exists
> to address it, but I don't have a subscription and I found no other results on the
> internet.
>  It seems to be an issue finding services, but `ipa service-find` finds HTTP and ldap as
> expected.
>  
>  Can someone help? Thanks
>  
>  ------------
>  [root@ipa-innovation opc]# ipactl start -d
>  ipa: DEBUG: importing all plugin modules in ipaserver.plugins...
>  ipa: DEBUG: importing plugin module ipaserver.plugins.aci
>  [...]
>  Starting Directory Service
>  ipa: DEBUG: Starting external process
>  ipa: DEBUG: args=['/bin/systemctl', 'start',
> 'dirsrv(a)PRIVATE-ACUS-EU.service']
>  ipa: DEBUG: Process finished, return code=0
>  ipa: DEBUG: Starting external process
>  ipa: DEBUG: args=['/bin/systemctl', 'is-active',
> 'dirsrv(a)PRIVATE-ACUS-EU.service']
>  ipa: DEBUG: Process finished, return code=0
>  ipa: DEBUG: stdout=active
>  
>  ipa: DEBUG: stderr=
>  ipa: DEBUG: wait_for_open_ports: localhost [389] timeout 120
>  ipa: DEBUG: waiting for port: 389
>  ipa: DEBUG: SUCCESS: port: 389
>  ipa: DEBUG: Start of dirsrv(a)PRIVATE-ACUS-EU.service complete
>  ipa: DEBUG: Starting external process
>  ipa: DEBUG: args=['/bin/systemctl', 'is-active',
> 'dirsrv(a)PRIVATE-ACUS-EU.service']
>  ipa: DEBUG: Process finished, return code=0
>  ipa: DEBUG: stdout=active
>  
>  ipa: DEBUG: stderr=
>  Failed to read data from service file: Unknown error when retrieving list of services
> from LDAP: not enough values to unpack (expected 2, got 1)
>  Shutting down
>  ipa: DEBUG: Starting external process
>  ipa: DEBUG: args=['/bin/systemctl', 'stop',
> 'dirsrv(a)PRIVATE-ACUS-EU.service']
>  ipa: DEBUG: Process finished, return code=0
>  ipa: DEBUG: Stop of dirsrv(a)PRIVATE-ACUS-EU.service complete
>  ipa: DEBUG:   File
> "/usr/lib/python3.9/site-packages/ipaserver/install/installutils.py", line 781,
> in run_script
>      return_value = main_function()
>  
>    File "/usr/lib/python3.9/site-packages/ipaserver/install/ipactl.py", line
> 735, in main
>      ipa_start(options)
>  
>    File "/usr/lib/python3.9/site-packages/ipaserver/install/ipactl.py", line
> 398, in ipa_start
>      raise IpactlError(rval=e.rval)
>  
>  ipa: DEBUG: The ipactl command failed, exception: IpactlError:  
I don't think this is related to the KCS. That had to do with ldap_uri
missing from /etc/ipa/default.conf and your 389 instance is starting ok.

Unfortunately the backtrace doesn't include where the "not enough values
to unpack" is originating. Maybe we can work backwards.

ipactl starts dirsrv and then runs a query and uses that to identify
which services to start. You can look in your
/var/log/dirsrv/slapd-REALM/access to see if the below query is being
executed and how many records are returned. If it isn't there then we'll
know it didn't even get as far as to do the query.

If it does then can you provide the output of:

$ kinit admin
$ ldapsearch -o ldif-wrap=no -LLL -Q -Y GSSAPI -b
cn=ipa.example.test,cn=masters,cn=ipa,cn=etc,dc=example,dc=test
"(&(objectClass=ipaConfigObject)(|(ipaConfigString=enabledService)(ipaConfigString=hiddenService)))"
cn ipaConfigString

You'll need to substitute in your domain for dc=example,dc=test and your
current hostname for ipa.example.test.

I'm not 100% sure this is where the data that isn't split is originating
but it seems like a good candidate.

rob

[Andrea Stacchiotti]

Thank you for your answer.

There is no record in the /var/log/dirsrv/slapd-REALM/access logfile at the time of `ipact
start`, which means it didn't even get to the query.

To get kinit and ldapsearch to work I had to reinstall ipa, when I do I get a valid
kerberos token and a good result, see at the bottom.

Then I try `ipactl restart` and I get the same bug again, now the services are down and I
can't bring them up, unless I reinstall.
My team is trying different installation methods and OSes, maybe we can figure it out.

Any help is appreciated.

[root@ipa-innovation slapd-PRIVATE-ACUS-EU]# klist
Ticket cache: KCM:0
Default principal: admin(a)PRIVATE.ACUS.EU

Valid starting       Expires              Service principal
05/09/2024 15:39:44  05/10/2024 15:04:45  krbtgt/PRIVATE.ACUS.EU(a)PRIVATE.ACUS.EU
[root@ipa-innovation slapd-PRIVATE-ACUS-EU]# ldapsearch -o ldif-wrap=no -LLL -Q -Y GSSAPI
-b cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
"(&(objectClass=ipaConfigObject)(|(ipaConfigString=enabledService)(ipaConfigString=hiddenService)))"
cn ipaConfigString
dn:
cn=KDC,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
cn: KDC
ipaConfigString: startOrder 10
ipaConfigString: pacTktSignSupported
ipaConfigString: kdcProxyEnabled
ipaConfigString: enabledService

dn:
cn=KPASSWD,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
cn: KPASSWD
ipaConfigString: startOrder 20
ipaConfigString: enabledService

dn:
cn=KEYS,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
cn: KEYS
ipaConfigString: startOrder 41
ipaConfigString: enabledService

dn:
cn=OTPD,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
cn: OTPD
ipaConfigString: startOrder 80
ipaConfigString: enabledService

dn:
cn=HTTP,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
cn: HTTP
ipaConfigString: startOrder 40
ipaConfigString: enabledService

[Rob Crittenden]

Andrea Stacchiotti via FreeIPA-users wrote:
>  Thank you for your answer.
>  
>  There is no record in the /var/log/dirsrv/slapd-REALM/access logfile at the time of
> `ipact start`, which means it didn't even get to the query.
>  
>  To get kinit and ldapsearch to work I had to reinstall ipa, when I do I get a valid
> kerberos token and a good result, see at the bottom.
>  
>  Then I try `ipactl restart` and I get the same bug again, now the services are down and I
> can't bring them up, unless I reinstall.
>  My team is trying different installation methods and OSes, maybe we can figure it out.
>  
>  Any help is appreciated.
>  
>  [root@ipa-innovation slapd-PRIVATE-ACUS-EU]# klist
>  Ticket cache: KCM:0
>  Default principal: admin(a)PRIVATE.ACUS.EU
>  
>  Valid starting       Expires              Service principal
>  05/09/2024 15:39:44  05/10/2024 15:04:45  krbtgt/PRIVATE.ACUS.EU(a)PRIVATE.ACUS.EU
>  [root@ipa-innovation slapd-PRIVATE-ACUS-EU]# ldapsearch -o ldif-wrap=no -LLL -Q -Y GSSAPI
> -b cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
> "(&(objectClass=ipaConfigObject)(|(ipaConfigString=enabledService)(ipaConfigString=hiddenService)))"
> cn ipaConfigString
>  dn:
> cn=KDC,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
>  cn: KDC
>  ipaConfigString: startOrder 10
>  ipaConfigString: pacTktSignSupported
>  ipaConfigString: kdcProxyEnabled
>  ipaConfigString: enabledService
>  
>  dn:
> cn=KPASSWD,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
>  cn: KPASSWD
>  ipaConfigString: startOrder 20
>  ipaConfigString: enabledService
>  
>  dn:
> cn=KEYS,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
>  cn: KEYS
>  ipaConfigString: startOrder 41
>  ipaConfigString: enabledService
>  
>  dn:
> cn=OTPD,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
>  cn: OTPD
>  ipaConfigString: startOrder 80
>  ipaConfigString: enabledService
>  
>  dn:
> cn=HTTP,cn=ipa-innovation.private.acus.eu,cn=masters,cn=ipa,cn=etc,dc=private,dc=acus,dc=eu
>  cn: HTTP
>  ipaConfigString: startOrder 40
>  ipaConfigString: enabledService 
The only split()s in ipactl, which is likely the source of the error,
are separating the hostname from the port in the ldap_url when it is not
an ldapi url and separating startOrder from its precedence. Those values
look correct.

rob