Page MenuHomePhorge
Create Task
Maniphest T8385

kolab-saslauthd fails on Almalinux 9 with status=2/INVALIDARGUMENT
Open, Needs TriagePublic
Actions

Description

I am running Kolab 16 on Almalinux 9.
kolab-saslauthd is kolab-saslauthd-0.9.0.7-1.5.el9.kolab_16.noarch
Without any further log message the kolab-saslauthd fails with just the following message in the journal log:
kolab-saslauthd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT

This disables all logins
Can I do to increase the log messages?

Details

Ticket Type
Task

Event Timeline

Spenneberg triaged this task as Needs Triage priority.Aug 2 2024, 9:32 AM
Spenneberg created this task.
ghane subscribed.Aug 2 2024, 10:00 AM

the debug option is " -d " with an integer up to 9

Spenneberg added a comment.Aug 9 2024, 3:32 PM

Thanks a lot. Saslauthd fails every 3-14 days. Once I have more data, I will add it to the ticket.

Spenneberg added a comment.Wed, Sep 4, 10:48 AM

I have increased the debug output to 5 so far. Currently it only logs failed authentications. I will increase it to 9 now. I was a bit hesitant because of the log size.

Spenneberg added a comment.EditedTue, Sep 10, 10:09 AM

Ok. I have increased the debug output to 9. Unfortunately nothing is logged. kolab-saslauthd failed at 08:03:39 and is automatically restarted.

/var/log/messages:
Sep 10 08:03:39 xchg3 systemd[1]: kolab-saslauthd.service: Main process exited,
code=exited, status=2/INVALIDARGUMENT

In /var/log/kolab/pykolab.log nothing noticable is logged before the restart:
2024-09-10 08:03:38,930 pykolab.auth DEBUG [3565584] Binding with bind_dn: uid=k
olab-service,ou=Special Users,dc=spenneberg,dc=net and password: ***
2024-09-10 08:03:38,931 pykolab.auth DEBUG [3565584] * <ldap.ldapobject.Recon
nectLDAPObject object at 0x7f045fca4280> ldap://localhost:389 - ReconnectLDAPObj
ect.simple_bind
2024-09-10 08:03:38,931 pykolab.auth DEBUG [3565584] (('uid=kolab-service,ou=Sp
ecial Users,dc=spenneberg,dc=net',
2024-09-10 08:03:38,931 pykolab.auth DEBUG [3565584] 'XXXXXXXX',
2024-09-10 08:03:38,931 pykolab.auth DEBUG [3565584] None,
2024-09-10 08:03:38,932 pykolab.auth DEBUG [3565584] None),
2024-09-10 08:03:38,932 pykolab.auth DEBUG [3565584] {})
2024-09-10 08:03:38,933 pykolab.auth DEBUG [3565584] * <ldap.ldapobject.Recon
nectLDAPObject object at 0x7f045fca4280> ldap://localhost:389 - ReconnectLDAPObj
ect.result4
2024-09-10 08:03:38,933 pykolab.auth DEBUG [3565584] ((1, 1, -1, 0, 0, 0), {})
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.i
d AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key,
entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.i
d AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key,
entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.i
d AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key,
entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.i
d AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key,
entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,962 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.61s ago] ('spenneberg.net',)
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,964 sqlalchemy.engine.Engine INFO [3565584] SELECT entries.id AS entries_id, entries.domain AS entries_domain, entries."key" AS entries_key, entries.value AS entries_value, entries.last_change AS entries_last_change
FROM entries
WHERE entries."key" = ?
2024-09-10 08:03:38,969 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.62s ago] ('(&(|(mail=hendrik)(mail=hendrik@spenneberg.net)(alias=hendrik)(alias=hendrik@spenneberg.net)(uid=hendrik)(uid=hendrik@spenneberg.net))(objectclass=inetorgperson))',)
2024-09-10 08:03:38,969 sqlalchemy.engine.Engine INFO [3565584] [cached since 29.62s ago] ('(&(|(mail=hendrik)(mail=hendrik@spenneberg.net)(alias=hendrik)(alias=hendrik@spenneberg.net)(uid=hendrik)(uid=hendrik@spenneberg.net))(objectclass=inetorgperson))',)
2024-09-10 08:03:38,969 pykolab.auth_cache DEBUG [3565584] Entry found: {'_sa_instance_state': <sqlalchemy.orm.state.InstanceState object at 0x7f045f110760>, 'value': 'uid=hendrik,ou=People,dc=spenneberg,dc=net', 'last_change': datetime.datetime(2024, 9, 10, 6, 10, 1, 40844), 'id': 2, 'domain': None, 'key': '(&(|(mail=hendrik)(mail=hendrik@spenneberg.net)(alias=hendrik)(alias=hendrik@spenneberg.net)(uid=hendrik)(uid=hendrik@spenneberg.net))(objectclass=inetorgperson))'}
2024-09-10 08:03:38,970 pykolab.auth_cache DEBUG [3565584] Returning: 'uid=hendrik,ou=People,dc=spenneberg,dc=net'
2024-09-10 08:03:38,970 pykolab.conf DEBUG [3565584] Die Option ldap/timeout existiert in der Konfigurationsdatei /etc/kolab/kolab.conf nicht, sie wird aus den Standardeinstellungen geholt
2024-09-10 08:03:38,970 pykolab.auth DEBUG [3565584] Binding with bind_dn: uid=hendrik,ou=People,dc=spenneberg,dc=net and password: **
2024-09-10 08:03:38,970 pykolab.auth DEBUG [3565584] * <ldap.ldapobject.ReconnectLDAPObject object at 0x7f045fca4280> ldap://localhost:389 - ReconnectLDAPObject.simple_bind
2024-09-10 08:03:38,970 pykolab.auth DEBUG [3565584] (('uid=hendrik,ou=People,dc=spenneberg,dc=net', '+++++"', None, None), {})
2024-09-10 08:03:38,971 pykolab.auth DEBUG [3565584] * <ldap.ldapobject.ReconnectLDAPObject object at 0x7f045fca4280> ldap://localhost:389 - ReconnectLDAPObject.result4
2024-09-10 08:03:38,971 pykolab.auth DEBUG [3565584] ((2, 1, -1, 0, 0, 0), {})
2024-09-10 08:03:38,998 pykolab.auth INFO [3565584] Authentifizierung für 'hendrik' erfolgreich

2024-09-10 08:03:39,118 pykolab.auth DEBUG [3565584] Aufgerufen für Domäne None
2024-09-10 08:03:39,118 pykolab.auth DEBUG [3565584] Benutze Abschnitt os-s.de und Domäne os-s.de
2024-09-10 08:03:39,119 pykolab.auth DEBUG [3565584] Benutze Abschnitt os-s.de und Domäne os-s.de
2024-09-10 08:03:39,119 pykolab.auth DEBUG [3565584] Verbinde zu Authentifizierungsbackend für Domäne os-s.de

Any further hints?