View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0006113SOGoBackend Generalpublic2025-04-08 14:422025-04-14 09:02
Reporterzhb Assigned Toqhivert  
PrioritynormalSeverityminorReproducibilityhave not tried
Status resolvedResolutionfixed 
Summary0006113: BUG: LDAP placeholder doesn't work when change password
Description

Dear developers,

It's an iRedMail server with OpenLDAP backend, LDAP related config in sogo.conf attached below.
The problem is, when end user logins and changing password:

  • with baseDN = "domainName=%d,o=domains,dc=a,dc=io"; in sogo.conf, SOGo reports Password change failed.
  • if i remove the domainName=%d, part from baseDN, baseDN = "o=domains,dc=a,dc=io";, changing password works.

With LDAPDebugEnabled = YES; in sogo.conf, it logs lines below:

Apr 08 10:37:52 sogod [27570]: <0x0xaaab000b3ea0[NGLdapConnection]> Using ldap_initialize for LDAP URL: ldap://127.0.0.1:389
Apr 08 10:37:52 sogod [27570]: <0x0xaaaaff7b8bf0[NGLdapConnection]> Using ldap_initialize for LDAP URL: ldap://127.0.0.1:389
2025-04-08 10:37:52.105 sogod[27570:27570] -[NGLdapConnection _searchAtBaseDN:qualifier:attributes:scope:]: search at base 'domainname=%d,o=domains,dc=a,dc=io' filter '(&(mail=user@a.io)(objectClass=mailUser)(accountStatus=active)(enabledService=mail)(enabledService=sogo))' for attrs 'dn'
Apr 08 10:37:52 sogod [27570]: 172.16.179.1 "POST /SOGo/so/changePassword HTTP/1.0" 403 30/69 0.009 - - 0 - 15

As you can see in 3rd line, it uses domainname=%d,o=domains,dc=a,dc=io as base dn without replacing %d by the real domain name a.io in user's email address.

Here's the full SOGoUserSources in sogo.conf:

SOGoUserSources = (
        {
            // Used for user authentication
            type = ldap;
            id = users;
            canAuthenticate = YES;
            isAddressBook = NO;
            displayName = "LDAP Authentication";

            hostname = "ldap://127.0.0.1:389";
            // baseDN = "o=domains,dc=a,dc=io";
            baseDN = "domainName=%d,o=domains,dc=a,dc=io";
            bindDN = "cn=vmail,dc=a,dc=io";
            bindPassword = "3wPTJ9uVj2upxBgDlw7OWfP2AT6hIGFA";
            filter = "objectClass=mailUser AND accountStatus=active AND enabledService=mail AND enabledService=sogo";
            scope = SUB;

            // always keep binding to the LDAP server using the DN of the
            // currently authenticated user. bindDN and bindPassword are still
            // required to find DN of the user.
            // Note: with default LDAP acl configured by iRedMail, user doesn't
            //       have privilege to query o=domains,dc=a,dc=io.
            //       so this doesn't work.
            //bindAsCurrentUser = YES;

            // The algorithm used for password encryption when changing
            // passwords without Password Policies enabled.
            // Possible values are: plain, crypt, md5-crypt, ssha, ssha512.
            userPasswordAlgorithm = ssha;

            CNFieldName = cn;
            IDFieldName = mail;
            // value of UIDFieldName must be unique on entire server
            UIDFieldName = mail;
            IMAPLoginFieldName = mail;
            MailFieldNames = (mail);
            bindFields = (mail);

            ModulesConstraints = {
                Mail = { enabledService = sogowebmail; };
                Calendar = { enabledService = sogocalendar; };
                ActiveSync = { enabledService = sogoactivesync; };
            };

            GroupObjectClasses = (
                "mailList",
                "group",
                "groupOfNames",
                "groupOfUniqueNames",
                "posixgroup"
            );
        }
    );
TagsNo tags attached.

Activities

qhivert

qhivert

2025-04-08 15:05

administrator   ~0018173

Hello, could you tell me what version/nightly are you using?
And is this new or it was never tested/seen before?
zhb

zhb

2025-04-08 15:12

reporter   ~0018174

  • OS: Rocky 9
  • CPU: arm64 / aarch64
  • I didn't test this before, also didn't receive reports from other server admins either.
  • sogo and sope packages:
sogo-5.12.0-el9.1744070400.el9.aarch64
sogo-activesync-5.12.0-el9.1744070400.el9.aarch64
sogo-tool-5.12.0-el9.1744070400.el9.aarch64
sogo-ealarms-notify-5.12.0-el9.1744070400.el9.aarch64
sope49-xml-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-core-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-gdl1-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-gdl1-contentstore-5.12.0-el9.1744070400.el9.aarch64
sope49-ldap-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-mime-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-appserver-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-sbjson-2.3.1-5.12.0.1742860800.el9.1.aarch64
sope49-cards-5.12.0-el9.1744070400.el9.aarch64
sope49-gdl1-mysql-4.9-5.12.0.1742860800.el9.1.aarch64
qhivert

qhivert

2025-04-09 06:53

administrator   ~0018176

Well I didn't manage to reproduce it but I push a commit with a potential fix -> https://github.com/Alinto/sogo/commit/ca425e6752fd28d68e35cc4c1b7dd6f7b3c43ab4
Available tomorrow with the nightly.
zhb

zhb

2025-04-09 09:11

reporter   ~0018177

Thank you very much, @qhivert. I will test it when nightly build is available and update here.
zhb

zhb

2025-04-10 03:39

reporter   ~0018181

Tried with new nightly build, still failed:

Apr 09 23:35:03 sogod [16179]: <0x0xaaaaf4b78cf0[NGLdapConnection]> Using ldap_initialize for LDAP URL: ldap://127.0.0.1:389
Apr 09 23:35:03 sogod [16179]: <0x0xaaaaf4a6c2e0[NGLdapConnection]> Using ldap_initialize for LDAP URL: ldap://127.0.0.1:389
2025-04-09 23:35:03.325 sogod[16179:16179] -[NGLdapConnection _searchAtBaseDN:qualifier:attributes:scope:]: search at base 'domainname=%d,o=domains,dc=a,dc=io' filter '(&(mail=user@a.io)(objectClass=mailUser)(accountStatus=active)(enabledService=mail)(enabledService=sogo))' for attrs 'dn'
Apr 09 23:35:03 sogod [16179]: 172.16.179.1 "POST /SOGo/so/changePassword HTTP/1.0" 403 30/69 0.020 - - 896K - 14

I also turned on debug mode in OpenLDAP (with loglevel = -1), and it logs the same search base dn:

Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=1 SRCH base="domainName=%d,o=domains,dc=a,dc=io" scope=2 deref=0 filter="(&(mail=user@a.io)(objectClass=mailUser)(accountStatus=active)(enabledService=mail)(enabledService=sogo))"

sope / sogo packages:

sope49-xml-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-core-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-gdl1-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-gdl1-contentstore-5.12.0-el9.1744156800.el9.aarch64
sope49-ldap-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-mime-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-appserver-4.9-5.12.0.1742860800.el9.1.aarch64
sope49-sbjson-2.3.1-5.12.0.1742860800.el9.1.aarch64
sope49-cards-5.12.0-el9.1744156800.el9.aarch64
sope49-gdl1-mysql-4.9-5.12.0.1742860800.el9.1.aarch64
sogo-5.12.0-el9.1744156800.el9.aarch64
sogo-activesync-5.12.0-el9.1744156800.el9.aarch64
sogo-tool-5.12.0-el9.1744156800.el9.aarch64
sogo-ealarms-notify-5.12.0-el9.1744156800.el9.aarch64
zhb

zhb

2025-04-10 03:43

reporter   ~0018182

Full openldap debug log attached below.
SOGo connects to LDAP server with the bindDN and bindPassword correctly, and it succeeds. But it fails to find the full DN of login user due to not expand placeholder %d by real domain name.

Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: slap_listener_activate(8):
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 busy
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: >>> slap_listener(ldap:///)
Apr 10 11:37:40 rk9 slapd[16286]: daemon: accept() = 16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: listen=8, new connection on 16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 16r
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: read active on 16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: added 16r (active) listener=(nil)
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 fd=16 ACCEPT from IP=127.0.0.1:38624 (IP=0.0.0.0:389)
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16)
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16): got connid=1002
Apr 10 11:37:40 rk9 slapd[16286]: connection_read(16): checking for input on id=1002
Apr 10 11:37:40 rk9 slapd[16286]: op tag 0x60, time 1744256260
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=0 do_bind
Apr 10 11:37:40 rk9 slapd[16286]: >>> dnPrettyNormal: <cn=vmail,dc=a,dc=io>
Apr 10 11:37:40 rk9 slapd[16286]: <<< dnPrettyNormal: <cn=vmail,dc=a,dc=io>, <cn=vmail,dc=a,dc=io>
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=0 BIND dn="cn=vmail,dc=a,dc=io" method=128
Apr 10 11:37:40 rk9 slapd[16286]: do_bind: version=3 dn="cn=vmail,dc=a,dc=io" method=128
Apr 10 11:37:40 rk9 slapd[16286]: ==> mdb_bind: dn: cn=vmail,dc=a,dc=io
Apr 10 11:37:40 rk9 slapd[16286]: mdb_dn2entry("cn=vmail,dc=a,dc=io")
Apr 10 11:37:40 rk9 slapd[16286]: => mdb_dn2id("cn=vmail,dc=a,dc=io")
Apr 10 11:37:40 rk9 slapd[16286]: <= mdb_dn2id: got id=0x2
Apr 10 11:37:40 rk9 slapd[16286]: => mdb_entry_decode:
Apr 10 11:37:40 rk9 slapd[16286]: <= mdb_entry_decode
Apr 10 11:37:40 rk9 slapd[16286]: => access_allowed: result not in cache (userPassword)
Apr 10 11:37:40 rk9 slapd[16286]: => access_allowed: auth access to "cn=vmail,dc=a,dc=io" "userPassword" requested
Apr 10 11:37:40 rk9 slapd[16286]: => acl_get: [1] attr userPassword
Apr 10 11:37:40 rk9 slapd[16286]: => acl_mask: access to entry "cn=vmail,dc=a,dc=io", attr "userPassword" requested
Apr 10 11:37:40 rk9 slapd[16286]: => acl_mask: to value by "", (=0)
Apr 10 11:37:40 rk9 slapd[16286]: <= check a_dn_pat: anonymous
Apr 10 11:37:40 rk9 slapd[16286]: <= acl_mask: [1] applying auth(=xd) (stop)
Apr 10 11:37:40 rk9 slapd[16286]: <= acl_mask: [1] mask: auth(=xd)
Apr 10 11:37:40 rk9 slapd[16286]: => slap_access_allowed: auth access granted by auth(=xd)
Apr 10 11:37:40 rk9 slapd[16286]: => access_allowed: auth access granted by auth(=xd)
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=0 BIND dn="cn=vmail,dc=a,dc=io" mech=SIMPLE bind_ssf=0 ssf=0
Apr 10 11:37:40 rk9 slapd[16286]: do_bind: v3 bind: "cn=vmail,dc=a,dc=io" to "cn=vmail,dc=a,dc=io"
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_result: conn=1002 op=0 p=3
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_result: err=0 matched="" text=""
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_response: msgid=1 tag=97 err=0
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=0 RESULT tag=97 err=0 qtime=0.000037 etime=0.000257 text=
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 16r
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: read active on 16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16)
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16): got connid=1002
Apr 10 11:37:40 rk9 slapd[16286]: connection_read(16): checking for input on id=1002
Apr 10 11:37:40 rk9 slapd[16286]: op tag 0x63, time 1744256260
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=1 do_search
Apr 10 11:37:40 rk9 slapd[16286]: >>> dnPrettyNormal: <domainname=%d,o=domains,dc=a,dc=io>
Apr 10 11:37:40 rk9 slapd[16286]: <<< dnPrettyNormal: <domainName=%d,o=domains,dc=a,dc=io>, <domainName=%d,o=domains,dc=a,dc=io>
Apr 10 11:37:40 rk9 slapd[16286]: SRCH "domainname=%d,o=domains,dc=a,dc=io" 2 0    0 0 0
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: AND
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter_list
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: EQUALITY
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: EQUALITY
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: EQUALITY
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: EQUALITY
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]: begin get_filter
Apr 10 11:37:40 rk9 slapd[16286]: EQUALITY
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter_list
Apr 10 11:37:40 rk9 slapd[16286]: end get_filter 0
Apr 10 11:37:40 rk9 slapd[16286]:    filter: (&(mail=user@a.io)(objectClass=mailUser)(accountStatus=active)(enabledService=mail)(enabledService=sogo))
Apr 10 11:37:40 rk9 slapd[16286]:    attrs: dn
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=1 SRCH base="domainName=%d,o=domains,dc=a,dc=io" scope=2 deref=0 filter="(&(mail=user@a.io)(objectClass=mailUser)(accountStatus=active)(enabledService=mail)(enabledService=sogo))"
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=1 SRCH attr=dn
Apr 10 11:37:40 rk9 slapd[16286]: ==> limits_get: conn=1002 op=1 self="cn=vmail,dc=a,dc=io" this="domainName=%d,o=domains,dc=a,dc=io"
Apr 10 11:37:40 rk9 slapd[16286]: => mdb_search
Apr 10 11:37:40 rk9 slapd[16286]: mdb_dn2entry("domainName=%d,o=domains,dc=a,dc=io")
Apr 10 11:37:40 rk9 slapd[16286]: => mdb_dn2id("domainName=%d,o=domains,dc=a,dc=io")
Apr 10 11:37:40 rk9 slapd[16286]: <= mdb_dn2id: get failed: MDB_NOTFOUND: No matching key/data pair found (-30798)
Apr 10 11:37:40 rk9 slapd[16286]: => mdb_entry_decode:
Apr 10 11:37:40 rk9 slapd[16286]: <= mdb_entry_decode
Apr 10 11:37:40 rk9 slapd[16286]: => access_allowed: disclose access to "o=domains,dc=a,dc=io" "entry" requested
Apr 10 11:37:40 rk9 slapd[16286]: => dn: [6] cn=vmail,dc=a,dc=io
Apr 10 11:37:40 rk9 slapd[16286]: => dn: [7] cn=vmailadmin,dc=a,dc=io
Apr 10 11:37:40 rk9 slapd[16286]: => dnpat: [8] domainName=([^,]+),o=domains,dc=a,dc=io$ nsub: 1
Apr 10 11:37:40 rk9 slapd[16286]: => dn: [9] o=domains,dc=a,dc=io
Apr 10 11:37:40 rk9 slapd[16286]: => acl_get: [9] matched
Apr 10 11:37:40 rk9 slapd[16286]: => acl_get: [9] attr entry
Apr 10 11:37:40 rk9 slapd[16286]: => acl_mask: access to entry "o=domains,dc=a,dc=io", attr "entry" requested
Apr 10 11:37:40 rk9 slapd[16286]: => acl_mask: to all values by "cn=vmail,dc=a,dc=io", (=0)
Apr 10 11:37:40 rk9 slapd[16286]: <= check a_dn_pat: anonymous
Apr 10 11:37:40 rk9 slapd[16286]: <= check a_dn_pat: self
Apr 10 11:37:40 rk9 slapd[16286]: <= check a_dn_pat: cn=vmail,dc=a,dc=io
Apr 10 11:37:40 rk9 slapd[16286]: <= acl_mask: [3] applying read(=rscxd) (stop)
Apr 10 11:37:40 rk9 slapd[16286]: <= acl_mask: [3] mask: read(=rscxd)
Apr 10 11:37:40 rk9 slapd[16286]: => slap_access_allowed: disclose access granted by read(=rscxd)
Apr 10 11:37:40 rk9 slapd[16286]: => access_allowed: disclose access granted by read(=rscxd)
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_result: conn=1002 op=1 p=3
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_result: err=10 matched="o=domains,dc=a,dc=io" text=""
Apr 10 11:37:40 rk9 slapd[16286]: send_ldap_response: msgid=2 tag=101 err=32
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 16r
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: read active on 16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=1 SEARCH RESULT tag=101 err=32 qtime=0.000034 etime=0.002186 nentries=0 text=
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16)
Apr 10 11:37:40 rk9 slapd[16286]: connection_get(16): got connid=1002
Apr 10 11:37:40 rk9 slapd[16286]: connection_read(16): checking for input on id=1002
Apr 10 11:37:40 rk9 slapd[16286]: op tag 0x42, time 1744256260
Apr 10 11:37:40 rk9 slapd[16286]: ber_get_next on fd 16 failed errno=0 (Success)
Apr 10 11:37:40 rk9 slapd[16286]: connection_read(16): input error=-2 id=1002, closing.
Apr 10 11:37:40 rk9 slapd[16286]: connection_closing: readying conn=1002 sd=16 for close
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on 1 descriptor
Apr 10 11:37:40 rk9 slapd[16286]: daemon: activity on:
Apr 10 11:37:40 rk9 slapd[16286]: 
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Apr 10 11:37:40 rk9 slapd[16286]: connection_close: deferring conn=1002 sd=16
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=2 do_unbind
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 op=2 UNBIND
Apr 10 11:37:40 rk9 slapd[16286]: connection_resched: attempting closing conn=1002 sd=16
Apr 10 11:37:40 rk9 slapd[16286]: connection_close: conn=1002 sd=16
Apr 10 11:37:40 rk9 slapd[16286]: daemon: removing 16
Apr 10 11:37:40 rk9 slapd[16286]: conn=1002 fd=16 closed
qhivert

qhivert

2025-04-14 07:23

administrator   ~0018183

Hello,
Could you use the debugger -> https://www.sogo.nu/support/faq/how-do-i-debug-sogo.html ?

And put a breakpoint there -> https://github.com/Alinto/sogo/blob/148fab9409abf703f56ae8ed701547f23d685711/SoObjects/SOGo/LDAPSource.m#L785

b SoObjects/SOGo/LDAPSource.m:785

Then open sogo and go change your password, the debugger will stop there. Print _baseDN and _pristineBaseDN

po _baseDN
po pristineBaseDN

It everything's fine, _pristineBaseDN contains %d and _baseDN the usermail.
If not, the method called just after [self updateBaseDNFromLogin: login]; is supposed to make the change. Go to the next steps by typing n and check those value again.
If this is correct, add a breakpoint later at https://github.com/Alinto/sogo/blob/148fab9409abf703f56ae8ed701547f23d685711/SoObjects/SOGo/LDAPSource.m#L805

b SoObjects/SOGo/LDAPSource.m:805

Type cto continue the program until it stop there and print userDN

po userDN

And tell me the result.
zhb

zhb

2025-04-14 08:09

reporter   ~0018184

Hi @qhivert,

Seems the issue has been fixed by you on 2025-04-09, i tested again moment ago and it works fine now.
Thank you very much. :)
qhivert

qhivert

2025-04-14 09:02

administrator   ~0018185

You're welcome ;)

Issue History

Date Modified Username Field Change
2025-04-08 14:42 zhb New Issue
2025-04-08 15:05 qhivert Note Added: 0018173
2025-04-08 15:07 qhivert Assigned To => qhivert
2025-04-08 15:07 qhivert Status new => feedback
2025-04-08 15:12 zhb Note Added: 0018174
2025-04-08 15:12 zhb Status feedback => assigned
2025-04-09 06:53 qhivert Note Added: 0018176
2025-04-09 09:11 zhb Note Added: 0018177
2025-04-10 03:39 zhb Note Added: 0018181
2025-04-10 03:43 zhb Note Added: 0018182
2025-04-14 07:23 qhivert Note Added: 0018183
2025-04-14 07:23 qhivert Status assigned => feedback
2025-04-14 08:09 zhb Note Added: 0018184
2025-04-14 08:09 zhb Status feedback => assigned
2025-04-14 09:02 qhivert Note Added: 0018185
2025-04-14 09:02 qhivert Status assigned => resolved
2025-04-14 09:02 qhivert Resolution open => fixed