#51172 389-ds broke CLDAP plugin in FreeIPA
Closed: wontfix 3 years ago by abbra. Opened 3 years ago by abbra.

With filter protection policies, 389-ds broke CLDAP plugin in FreeIPA. The plugin handles connectionless LDAP requests over UDP/389 in Active Directory: https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-adts/895a7744-aff3-4f64-bcfa-f8c05915d2e9

# dsconf IPA1-TEST config get nsslapd-verify-filter-schema
nsslapd-verify-filter-schema: process-safe

With 389-ds-base-1.4.4.2-1.fc32.x86_64 I see the following issue in wireshark:

Lightweight Directory Access Protocol
    LDAPMessage searchRequest(1) "<ROOT>" baseObject
        messageID: 1
        protocolOp: searchRequest (3)
            searchRequest
                baseObject: 
                scope: baseObject (0)
                derefAliases: neverDerefAliases (0)
                sizeLimit: 0
                timeLimit: 0
                typesOnly: False
                Filter: (&(DnsDomain=ipa1.test)(NtVer=0x00000014))
                    filter: and (0)
                        and: (&(DnsDomain=ipa1.test)(NtVer=0x00000014))
                            and: 2 items
                                Filter: (DnsDomain=ipa1.test)
                                    and item: equalityMatch (3)
                                        equalityMatch
                                Filter: (NtVer=0x00000014)
                                    and item: equalityMatch (3)
                                        equalityMatch
                attributes: 1 item
                    AttributeDescription: netlogon
        [Response In: 6]

responded with

Lightweight Directory Access Protocol
    LDAPMessage searchResDone(1) success (Invalid attribute in filter - results may not be complete.) [0 results]
        messageID: 1
        protocolOp: searchResDone (5)
            searchResDone
                resultCode: success (0)
                matchedDN: 
                errorMessage: Invalid attribute in filter - results may not be complete.
        [Response To: 4]
        [Time: 0.000401000 seconds]

SSSD logs show:

(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://m1.ipa1.test:389/??base] with fd [31].
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://m1.ipa1.test:389
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_print_server] (0x2000): Searching 192.168.122.132:389
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=ipa1.test)(NtVer=\14\00\00\00))][].
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon]
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_op_add] (0x2000): New operation 1 timeout 6
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_process_result] (0x2000): Trace: sh[0x564a867b2cb0], connected[1], ops[0x564a867b2a40], ldap[0x564a867aee10]
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), Invalid attribute in filter - results may not be complete.
(2020-06-22 18:30:24): [be[ipa2.test]] [sdap_op_destructor] (0x2000): Operation 1 finished

and in 389-ds' access log it is recorded as:

[22/Jun/2020:18:30:24.054250632 +0300] conn=54 fd=89 slot=89 connection from 192.168.122.59 to 192.168.122.132
[22/Jun/2020:18:30:24.054519732 +0300] conn=54 op=0 SRCH base="" scope=0 filter="(&(dnsdomain=ipa1.test)(ntver=\14))" attrs="netlogon"
[22/Jun/2020:18:30:24.054599171 +0300] conn=54 op=0 RESULT err=0 tag=101 nentries=0 etime=0.000314399 - Invalid attribute in filter - results may not be complete.
[22/Jun/2020:18:30:24.054853471 +0300] conn=54 op=1 UNBIND
[22/Jun/2020:18:30:24.054877761 +0300] conn=54 op=1 fd=89 closed - U1

Note that access log has wrong filter component logged (cut off).

Unfortunately, it is not possible to set the filter check to warn to test:

[root@m1 ~]# dsconf IPA1-TEST config add nsslapd-verify-filter-schema=warn
Successfully added "nsslapd-verify-filter-schema"
[root@m1 ~]# dsconf IPA1-TEST config get nsslapd-verify-filter-schema
nsslapd-verify-filter-schema: process-safe
[root@m1 ~]# dsconf IPA1-TEST config add nsslapd-verify-filter-schema=warn
Error: Type or value exists
[root@m1 ~]# dsconf IPA1-TEST config get nsslapd-verify-filter-schema
nsslapd-verify-filter-schema: process-safe
[root@m1 ~]# dsctl IPA1-TEST restart
Instance "IPA1-TEST" has been restarted
[root@m1 ~]# dsconf IPA1-TEST config get nsslapd-verify-filter-schema
nsslapd-verify-filter-schema: process-safe

After Mark and Viktor helped me with warn-invalid setting, I still see broken search response:

Lightweight Directory Access Protocol
    LDAPMessage searchRequest(1) "<ROOT>" baseObject
        messageID: 1
        protocolOp: searchRequest (3)
            searchRequest
                baseObject: 
                scope: baseObject (0)
                derefAliases: neverDerefAliases (0)
                sizeLimit: 0
                timeLimit: 0
                typesOnly: False
                Filter: (&(DnsDomain=ipa1.test)(NtVer=0x00000014))
                    filter: and (0)
                        and: (&(DnsDomain=ipa1.test)(NtVer=0x00000014))
                            and: 2 items
                                Filter: (DnsDomain=ipa1.test)
                                    and item: equalityMatch (3)
                                        equalityMatch
                                            attributeDesc: DnsDomain
                                            assertionValue: ipa1.test
                                Filter: (NtVer=0x00000014)
                                    and item: equalityMatch (3)
                                        equalityMatch
                                            attributeDesc: NtVer
                                            Version Flags: 0x00000014, V5EX: Client requested version 5 extended netlogon response, VCS: Client has asked for the closest site information
                                                .... .... .... .... .... .... .... ...0 = V1: Version 1 netlogon response not requested
                                                .... .... .... .... .... .... .... ..0. = V5: Version 5 netlogon response not requested
                                                .... .... .... .... .... .... .... .1.. = V5EX: Client requested version 5 extended netlogon response
                                                .... .... .... .... .... .... .... 0... = V5EP: IP address of server not requested
                                                .... .... .... .... .... .... ...1 .... = VCS: Client has asked for the closest site information
                                                .... ...0 .... .... .... .... .... .... = VNT4: Only full AD DS requested
                                                ...0 .... .... .... .... .... .... .... = VPDC: Primary Domain Controller not requested
                                                ..0. .... .... .... .... .... .... .... = VIP: IP details not requested (obsolete)
                                                .0.. .... .... .... .... .... .... .... = VL: Client is not the local machine
                                                0... .... .... .... .... .... .... .... = VGC: Global Catalog not requested
                attributes: 1 item
                    AttributeDescription: netlogon
        [Response In: 6]
Lightweight Directory Access Protocol
    LDAPMessage searchResDone(1) success [0 results]
        messageID: 1
        protocolOp: searchResDone (5)
            searchResDone
                resultCode: success (0)
                matchedDN: 
                errorMessage: 
        [Response To: 4]
        [Time: 0.000351000 seconds]
[22/Jun/2020:18:56:36.877558360 +0300] conn=19 fd=97 slot=97 connection from 192.168.122.59 to 192.168.122.132
[22/Jun/2020:18:56:36.877802860 +0300] conn=19 op=0 SRCH base="" scope=0 filter="(&(dnsdomain=ipa1.test)(ntver=\14))" attrs="netlogon"
[22/Jun/2020:18:56:36.877849630 +0300] conn=19 op=0 RESULT err=0 tag=101 nentries=0 etime=0.000215870
[22/Jun/2020:18:56:36.878162039 +0300] conn=19 op=1 UNBIND
[22/Jun/2020:18:56:36.878177869 +0300] conn=19 op=1 fd=97 closed - U1

@abbra if filter-schema-check allows (warn-invalid) unknown attribute, the matching rules can be inappropriate to handle the attribute value and fail to match an matching entry.

Metadata Update from @tbordaz:
- Custom field origin adjusted to None
- Custom field reviewstatus adjusted to None

3 years ago

@tbordaz there is no matching entry, this is purely virtual thing. A plugin receives parameters through the search request and builds own response. It looks like the plugin never gets to work at all.

[root@m1 ~]# dsconf IPA1-TEST plugin show ipa_cldap
dn: cn=ipa_cldap,cn=plugins,cn=config
cn: ipa_cldap
nsslapd-basedn: dc=ipa1,dc=test
nsslapd-plugin-depends-on-type: database
nsslapd-pluginDescription: MS/AD introperable CLDAP server
nsslapd-pluginEnabled: on
nsslapd-pluginId: CLDAP Server
nsslapd-pluginInitfunc: ipa_cldap_init
nsslapd-pluginPath: libipa_cldap
nsslapd-pluginType: postoperation
nsslapd-pluginVendor: FreeIPA project
nsslapd-pluginVersion: FreeIPA/3.0
objectClass: top
objectClass: nsSlapdPlugin
objectClass: extensibleObject

I traced a request and I don't see the plugin called in post operation:

[22/Jun/2020:19:49:43.210396052 +0300] conn=34 fd=99 slot=99 connection from 192.168.122.59 to 192.168.122.132
[22/Jun/2020:19:49:43.435547517 +0300] conn=34 op=0 SRCH base="" scope=0 filter="(&(dnsdomain=ipa1.test)(ntver=\14))" attrs="netlogon"
[22/Jun/2020:19:49:43.534647320 +0300] conn=34 op=0 RESULT err=0 tag=101 nentries=0 etime=0.287330063
[22/Jun/2020:19:49:43.587432501 +0300] conn=34 op=1 UNBIND
[22/Jun/2020:19:49:43.599270034 +0300] conn=35 fd=100 slot=100 connection from 192.168.122.59 to 192.168.122.132
[22/Jun/2020:19:49:43.635009251 +0300] conn=34 op=1 fd=99 closed - U1

and

[22/Jun/2020:19:49:43.423130096 +0300] - DEBUG - do_search - SRCH base="" scope=0 deref=0 sizelimit=0 timelimit=0 attrsonly=0 filter="(&(dnsdomain=ipa1.test)(ntver=\14))" attrs="netlogon"
[22/Jun/2020:19:49:43.424462524 +0300] - DEBUG - get_ldapmessage_controls_ext - => get_ldapmessage_controls
[22/Jun/2020:19:49:43.425844282 +0300] - DEBUG - get_ldapmessage_controls_ext - <= no controls
[22/Jun/2020:19:49:43.427318580 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.3)
[22/Jun/2020:19:49:43.428805628 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.430246246 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.12)
[22/Jun/2020:19:49:43.431582403 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.432884701 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.18)
[22/Jun/2020:19:49:43.434236710 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.435564777 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.436909705 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.438271003 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.439611611 +0300] - DEBUG - <-- pagedresults_is_timedout - <= false 2
[22/Jun/2020:19:49:43.440926619 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.442315957 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.443669726 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.445026393 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.446368841 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.447724069 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.449077167 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.450557025 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.451939113 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.453423441 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.454859928 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.456288586 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.457670364 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.459057443 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.460505020 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.461919378 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.463341046 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.464767634 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.466226111 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.467633939 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.469117737 +0300] - DEBUG - slapi_reslimit_get_integer_limit - => conn=0x0x7f0b3a0b29d0, handle=6
[22/Jun/2020:19:49:43.470516906 +0300] - DEBUG - slapi_reslimit_get_integer_limit - <= returning NO VALUE
[22/Jun/2020:19:49:43.472022624 +0300] - DEBUG - slapi_reslimit_get_integer_limit - => conn=0x0x7f0b3a0b29d0, handle=5
[22/Jun/2020:19:49:43.473462431 +0300] - DEBUG - slapi_reslimit_get_integer_limit - <= returning SUCCESS, value=5000
[22/Jun/2020:19:49:43.474824099 +0300] - DEBUG - compute_limits - => sizelimit=5000, timelimit=3600
[22/Jun/2020:19:49:43.476166757 +0300] - DEBUG - plugin_call_func - Calling plugin 'schema-compat-plugin-preop' #0 type 403
[22/Jun/2020:19:49:43.477683364 +0300] - DEBUG - plugin_call_func - Calling plugin 'Account Usability Plugin' #2 type 403
[22/Jun/2020:19:49:43.479124972 +0300] - DEBUG - account-usability-plugin - --> auc_pre_search
[22/Jun/2020:19:49:43.480508290 +0300] - DEBUG - account-usability-plugin - <-- auc_pre_op
[22/Jun/2020:19:49:43.481937269 +0300] - DEBUG - plugin_call_func - Calling plugin 'ACL preoperation' #3 type 403
[22/Jun/2020:19:49:43.483373186 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.12)
[22/Jun/2020:19:49:43.484768484 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.486146142 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.18)
[22/Jun/2020:19:49:43.487539190 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.488959788 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.12)
[22/Jun/2020:19:49:43.490362796 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.491752504 +0300] - DEBUG - slapi_control_present - => (looking for 2.16.840.1.113730.3.4.18)
[22/Jun/2020:19:49:43.493196042 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.494679459 +0300] - DEBUG - plugin_call_func - Calling plugin 'content-sync-preop-subplugin' #7 type 403
[22/Jun/2020:19:49:43.496066377 +0300] - DEBUG - slapi_control_present - => (looking for 1.3.6.1.4.1.4203.1.9.1.1)
[22/Jun/2020:19:49:43.497429606 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.498831614 +0300] - DEBUG - plugin_call_func - Calling plugin 'deref' #8 type 403
[22/Jun/2020:19:49:43.500205841 +0300] - DEBUG - deref-plugin - --> deref_pre_search
[22/Jun/2020:19:49:43.501615779 +0300] - DEBUG - deref-plugin - <-- deref_pre_search
[22/Jun/2020:19:49:43.503056767 +0300] - DEBUG - plugin_call_func - Calling plugin 'Multimaster replication preoperation plugin' #19 type 403
[22/Jun/2020:19:49:43.504567335 +0300] - DEBUG - pw_copy_entry_ext - Source pw_entry_extension is not set
[22/Jun/2020:19:49:43.505948092 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - =>
[22/Jun/2020:19:49:43.507331951 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - <=
[22/Jun/2020:19:49:43.508765229 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - AND
[22/Jun/2020:19:49:43.510139737 +0300] - DEBUG - vattr_test_filter_list_and - =>
[22/Jun/2020:19:49:43.511506144 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - =>
[22/Jun/2020:19:49:43.512925272 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - <=
[22/Jun/2020:19:49:43.514333871 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - EQUALITY
[22/Jun/2020:19:49:43.515804509 +0300] - DEBUG - test_ava_filter - =>
[22/Jun/2020:19:49:43.517213516 +0300] - DEBUG - test_ava_filter - <= -1
[22/Jun/2020:19:49:43.518615034 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - <= -1
[22/Jun/2020:19:49:43.520238342 +0300] - DEBUG - vattr_test_filter_list_and - <= -1
[22/Jun/2020:19:49:43.521768450 +0300] - DEBUG - slapi_vattr_filter_test_ext_internal - <= -1
[22/Jun/2020:19:49:43.523240537 +0300] - DEBUG - plugin_call_func - Calling plugin 'content-sync-postop-subplugin' #3 type 503
[22/Jun/2020:19:49:43.524721805 +0300] - DEBUG - send_ldap_result_ext - => 0::
[22/Jun/2020:19:49:43.526165643 +0300] - DEBUG - slapi_control_present - => (looking for 1.3.6.1.1.13.1)
[22/Jun/2020:19:49:43.527547201 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.528963338 +0300] - DEBUG - slapi_control_present - => (looking for 1.3.6.1.1.13.2)
[22/Jun/2020:19:49:43.530378316 +0300] - DEBUG - slapi_control_present - <= 0 (NO CONTROLS)
[22/Jun/2020:19:49:43.531816144 +0300] - DEBUG - plugin_call_func - Calling plugin 'content-sync-preop-subplugin' #7 type 412
[22/Jun/2020:19:49:43.533298272 +0300] - DEBUG - flush_ber - Wrote 14 bytes to socket 99
[22/Jun/2020:19:49:43.534699119 +0300] - DEBUG - send_ldap_result_ext - <= 0
[22/Jun/2020:19:49:43.536156478 +0300] - DEBUG - slapi_mapping_tree_free_all - mapping tree release backend : frontend-internal
[22/Jun/2020:19:49:43.541993329 +0300] - DEBUG - slapi_filter_free - type 0xA0
[22/Jun/2020:19:49:43.543316407 +0300] - DEBUG - slapi_filter_free - type 0xA3
[22/Jun/2020:19:49:43.544642826 +0300] - DEBUG - slapi_filter_free - type 0xA3
[22/Jun/2020:19:49:43.546048993 +0300] - DEBUG - connection_threadmain - conn 34 check more_data 0 thread_turbo_flag 0repl_conn_bef 0, repl_conn_now 0
[22/Jun/2020:19:49:43.547351901 +0300] - DEBUG - connection_table_dump_activity_to_errors_log - activity on 34r
[22/Jun/2020:19:49:43.548690069 +0300] - DEBUG - handle_pr_read_ready - read activity on 34
[22/Jun/2020:19:49:43.550013498 +0300] - DEBUG - add_work_q - =>
[22/Jun/2020:19:49:43.551287395 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.552633173 +0300] - DEBUG - <-- pagedresults_is_timedout - <= false 2
[22/Jun/2020:19:49:43.553906082 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.555215939 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.556511278 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.557778596 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.559096653 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.560382902 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.561676740 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.563001848 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.564293706 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.565574524 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.566864762 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.568147600 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.569528349 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.570825106 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.572111824 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.573433113 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.574715741 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.575989109 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.577339557 +0300] - DEBUG - pagedresults_is_timedout - =>
[22/Jun/2020:19:49:43.578647205 +0300] - DEBUG - pagedresults_is_timedout - <= false 1
[22/Jun/2020:19:49:43.579943073 +0300] - DEBUG - get_work_q - =>
[22/Jun/2020:19:49:43.581211951 +0300] - DEBUG - connection_read_operation - connection 34 read 7 bytes
[22/Jun/2020:19:49:43.582435599 +0300] - DEBUG - connection_threadmain - conn 34 read operation successfully - thread_turbo_flag 0 more_data 0 ops_initiated 2 refcnt 2 flags 0
[22/Jun/2020:19:49:43.583723277 +0300] - DEBUG - do_unbind - =>
[22/Jun/2020:19:49:43.584981485 +0300] - DEBUG - get_ldapmessage_controls_ext - => get_ldapmessage_controls
[22/Jun/2020:19:49:43.586177794 +0300] - DEBUG - get_ldapmessage_controls_ext - <= no controls
[22/Jun/2020:19:49:43.587454021 +0300] - DEBUG - pagedresults_cleanup - =>
[22/Jun/2020:19:49:43.588778080 +0300] - DEBUG - pagedresults_cleanup - <= 0

One thing I need to look up is why (according to the network trace) SSSD does the request over TCP, not UDP. Perhaps, that's the reason it doesn't work actually.

I'll come back once it is cleared.

Ok, looks like it is a bug in SSSD where it performs CLDAP request over TCP rather than UDP. I tried both off and process-safe when running CLDAP request over UDP and no problem appeared, I've got correct responses back.

I'll continue with SSSD bug investigation in their bugzilla. Sorry for the false report!

Metadata Update from @abbra:
- Issue close_status updated to: invalid
- Issue status updated to: Closed (was: Open)

3 years ago

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/4225

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata Update from @spichugi:
- Issue close_status updated to: wontfix (was: invalid)

3 years ago

Login to comment on this ticket.

Metadata
Attachments 1
Attached 3 years ago View Comment