Rebind as anonymous after

[madeiba]

Hi,

As per documentation, start_tls can be executed before or after a bind operation :

start_tls: establishes a secure connection, can be executed before or after the bind operation.

But I found that the search results are different if i call start_tls before or after the bind operation.
I'm working with OpenLDAP 2.5 (Debian 12 default repos) and ldap3 version 2.9.1 (also Debian 12 default repos).

The script:

from ldap3 import Server, Connection, LEVEL, NONE

server = Server('ldap://ldap1.unixland.org:389', get_info=NONE, use_ssl=False)
c1 = Connection(server, user='cn=manager,dc=test,dc=com', password='xxxxxx', raise_exceptions=True)
c1.bind()
c1.start_tls()
c1.search(search_base = 'dc=test,dc=com', search_filter = '(objectClass=*)', search_scope = LEVEL, attributes = None)
print (c1.response)

c2 = Connection(server, user='cn=manager,dc=test,dc=com', password='xxxxxx', raise_exceptions=True)
c2.start_tls()
c2.bind()
c2.search(search_base = 'dc=test,dc=com', search_filter = '(objectClass=*)', search_scope = LEVEL, attributes = None)
print (c2.response)

I build a Server and two connections. One of the connections calls bind() and then calls start_tls(), and the other connection calls start_tls() and then bind(). After that, both connections execute the same search.
I was expecting the same result on both search operations, but I found different results:

nacho@xerte:~ $ python3 conldap3.py 
[{'raw_dn': b'ou=groups,dc=test,dc=com', 'dn': 'ou=groups,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=people,dc=test,dc=com', 'dn': 'ou=people,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}]
[{'raw_dn': b'ou=tres,dc=test,dc=com', 'dn': 'ou=tres,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=admins,dc=test,dc=com', 'dn': 'ou=admins,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=cuatro,dc=test,dc=com', 'dn': 'ou=cuatro,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=groups,dc=test,dc=com', 'dn': 'ou=groups,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=people,dc=test,dc=com', 'dn': 'ou=people,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}, {'raw_dn': b'ou=policies,dc=test,dc=com', 'dn': 'ou=policies,dc=test,dc=com', 'raw_attributes': {}, 'attributes': {}, 'type': 'searchResEntry'}]

nacho@xerte:~ $ 

This script generates the next log entries in OpenLDAP server:

local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 fd=21 ACCEPT from IP=192.168.201.1:60641 (IP=172.17.0.2:389)
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=0 BIND dn="cn=manager,dc=test,dc=com" method=128
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=0 BIND dn="cn=manager,dc=test,dc=com" mech=SIMPLE bind_ssf=0 ssf=0
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=0 RESULT tag=97 err=0 qtime=0.000022 etime=0.000580 text=
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=1 EXT oid=1.3.6.1.4.1.1466.20037
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=1 STARTTLS
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=1 AUTHZ anonymous mech=starttls ssf=0
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=1 RESULT oid= err=0 qtime=0.000018 etime=0.000251 text=
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 fd=21 TLS established tls_ssf=256 ssf=256 tls_proto=TLS1.3 tls_cipher=AES-256-GCM
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=2 SRCH base="dc=test,dc=com" scope=1 deref=3 filter="(objectClass=*)"
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=2 SRCH attr=1.1
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1185 op=2 SEARCH RESULT tag=101 err=0 qtime=0.000070 etime=0.000707 nentries=2 text=
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1186 fd=22 ACCEPT from IP=192.168.201.1:56791 (IP=172.17.0.2:389)
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1186 op=0 EXT oid=1.3.6.1.4.1.1466.20037
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1186 op=0 STARTTLS
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1186 op=0 RESULT oid= err=0 qtime=0.000027 etime=0.000174 text=
local4.debug: Mar 19 23:47:47 slapd[514]: conn=1186 fd=22 TLS established tls_ssf=256 ssf=256 tls_proto=TLS1.3 tls_cipher=AES-256-GCM
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=1 BIND dn="cn=manager,dc=test,dc=com" method=128
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=1 BIND dn="cn=manager,dc=test,dc=com" mech=SIMPLE bind_ssf=0 ssf=256
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=1 RESULT tag=97 err=0 qtime=0.000047 etime=0.000908 text=
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=2 SRCH base="dc=test,dc=com" scope=1 deref=3 filter="(objectClass=*)"
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=2 SRCH attr=1.1
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 op=2 SEARCH RESULT tag=101 err=0 qtime=0.000034 etime=0.000387 nentries=6 text=
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1186 fd=22 closed (connection lost)
local4.debug: Mar 19 23:47:48 slapd[514]: conn=1185 fd=21 closed (connection lost)

After the STARTTLS operation with c1 connection there is a AUTHZ anonymous authentication.
The question is ¿was that expected?
Before the STARTTLS there is a successfull BIND operation with cn=Manager on c1 connection.
Perhaps I'm simply wrong, but I think the documentation is not clear regarding this issue.

Regards