By William Sescu

After installing OUD some time ago, I was doing some tests to see how it performs, and as long as I do ldap searching on the command line it looks very good. I am running Unified Directory 11.1.2.3.170117 (latest PSU), just for the protocol and I use the OUD only for TNS resolving and nothing else. However, Oracle clients are not connecting with “ldapsearch”, they are using “sqlplus” and the TNS name is resolved automatically in background.

I do have the following ldap.ora and sqlnet.ora. Very simply and nothing special.

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] cat ldap.ora
DIRECTORY_SERVERS= (dbidg01:1389)
DEFAULT_ADMIN_CONTEXT = "dc=dbi,dc=com"
DIRECTORY_SERVER_TYPE = OID

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] cat sqlnet.ora
NAMES.DIRECTORY_PATH = (TNSNAMES,LDAP,EZCONNECT)

Here is a little quiz: How many LDAP search requests do you expect when you connect to a 12.2 databases with the following command?

sqlplus system/manager@dbit122_ldap

Only one, right? Oracle looks up the TNS name dbit122_ldap in the OUD and retrieves the connect string. As soon as Oracle has the connect details, OUD does not play any role anymore. In case you do a ldapsearch from the 12.2 Oracle Home, then this is exactly the case.

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] which ldapsearch
/u01/app/oracle/product/12.2.0/dbhome_1/bin/ldapsearch
oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] ldapsearch -v -h dbidg01 -p 1389 -b "cn=DBIT122_LDAP,cn=OracleContext,dc=dbi,dc=com" -s base "(objectclass=*)" "objectclass,orclNetDescString,orclNetDescName,orclVersion"
ldap_open( dbidg01, 1389 )
filter pattern: (objectclass=*)
returning: objectclass,orclNetDescString,orclNetDescName,orclVersion
filter is: ((objectclass=*))
cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com
1 matches

In the OUD access log, you can see it clearly. One connect, the bind, the search request and finally the disconnect. Exactly how it should be, and the etime is 1 millisecond. That’s the elapsed time to deliver the search request which is very fast.

[dbafmw@dbidg01 logs]$ tail -40f /u01/app/oracle/product/Middleware/11.1.2.3/asinst_1/OUD/logs/access
...
[06/Apr/2017:10:46:49 +0200] CONNECT conn=877 from=192.168.56.203:21971 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:10:46:49 +0200] BIND REQ conn=877 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:10:46:49 +0200] BIND RES conn=877 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:10:46:49 +0200] SEARCH REQ conn=877 op=1 msgID=2 base="cn=DBIT122_LDAP,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:10:46:49 +0200] SEARCH RES conn=877 op=1 msgID=2 result=0 nentries=1 etime=1
[06/Apr/2017:10:46:49 +0200] UNBIND REQ conn=877 op=2 msgID=3
[06/Apr/2017:10:46:49 +0200] DISCONNECT conn=877 reason="Client Disconnect"

Ok. Let’s do the first test with Oracle 10.2.0.5. I know, it is not supported, however, regarding LDAP searches it is a version  where everything is ok. My test is very simple, just a sqlplus connection and then an exit. Nothing else.

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT102] sqlplus -V

SQL*Plus: Release 10.2.0.5.0 - Production

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT102] sqlplus system/manager@dbit122_ldap

SQL*Plus: Release 10.2.0.5.0 - Production on Thu Apr 6 11:00:02 2017

Copyright (c) 1982, 2010, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

In the OUD access log I see, like expected only one search request.

[dbafmw@dbidg01 logs]$ tail -40f /u01/app/oracle/product/Middleware/11.1.2.3/asinst_1/OUD/logs/access
...
[06/Apr/2017:11:01:18 +0200] CONNECT conn=879 from=192.168.56.203:21974 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:01:18 +0200] BIND REQ conn=879 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:01:18 +0200] BIND RES conn=879 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:01:18 +0200] SEARCH REQ conn=879 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:01:18 +0200] SEARCH RES conn=879 op=1 msgID=2 result=0 nentries=1 etime=2
[06/Apr/2017:11:01:18 +0200] UNBIND REQ conn=879 op=2 msgID=3
[06/Apr/2017:11:01:18 +0200] DISCONNECT conn=879 reason="Client Disconnect"

Let’s to the same now with 11.2.0.4. This time with a fully supported version. Yes. It still is. 🙂

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT112] sqlplus -V

SQL*Plus: Release 11.2.0.4.0 Production

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT112] sqlplus system/manager@dbit122_ldap

SQL*Plus: Release 11.2.0.4.0 Production on Thu Apr 6 11:03:17 2017

Copyright (c) 1982, 2013, Oracle.  All rights reserved.


Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

Wowwwww … now I see already two search request on the OUD. To be honest, I haven’t expected that. One should be sufficient from my point of view.

[dbafmw@dbidg01 logs]$ tail -40f /u01/app/oracle/product/Middleware/11.1.2.3/asinst_1/OUD/logs/access
...
[06/Apr/2017:11:03:43 +0200] CONNECT conn=882 from=192.168.56.203:21979 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:03:43 +0200] BIND REQ conn=882 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:03:43 +0200] BIND RES conn=882 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:03:43 +0200] SEARCH REQ conn=882 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:03:43 +0200] SEARCH RES conn=882 op=1 msgID=2 result=0 nentries=1 etime=1
[06/Apr/2017:11:03:43 +0200] UNBIND REQ conn=882 op=2 msgID=3
[06/Apr/2017:11:03:43 +0200] DISCONNECT conn=882 reason="Client Disconnect"
[06/Apr/2017:11:03:43 +0200] CONNECT conn=883 from=192.168.56.203:21980 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:03:43 +0200] BIND REQ conn=883 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:03:43 +0200] BIND RES conn=883 op=0 msgID=1 result=0 authDN="" etime=1
[06/Apr/2017:11:03:43 +0200] SEARCH REQ conn=883 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:03:43 +0200] SEARCH RES conn=883 op=1 msgID=2 result=0 nentries=1 etime=2
[06/Apr/2017:11:03:43 +0200] UNBIND REQ conn=883 op=2 msgID=3
[06/Apr/2017:11:03:43 +0200] DISCONNECT conn=883 reason="Client Disconnect"

But when you think, it can’t get worse, then do the same simple test with a 12.1.0.2 Oracle client.

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT121] sqlplus -V

SQL*Plus: Release 12.1.0.2.0 Production

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT121] sqlplus system/manager@dbit122_ldap

SQL*Plus: Release 12.1.0.2.0 Production on Thu Apr 6 11:06:18 2017

Copyright (c) 1982, 2014, Oracle.  All rights reserved.

Last Successful login time: Thu Apr 06 2017 11:03:43 +02:00

Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

Incredible, it is issuing three ldap search requests against the OUD for a simple sqlplus connection.

[dbafmw@dbidg01 logs]$ tail -40f /u01/app/oracle/product/Middleware/11.1.2.3/asinst_1/OUD/logs/access
...
[06/Apr/2017:11:06:41 +0200] CONNECT conn=887 from=192.168.56.203:21986 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:06:41 +0200] BIND REQ conn=887 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:06:41 +0200] BIND RES conn=887 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:06:41 +0200] SEARCH REQ conn=887 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:06:41 +0200] SEARCH RES conn=887 op=1 msgID=2 result=0 nentries=1 etime=1
[06/Apr/2017:11:06:41 +0200] UNBIND REQ conn=887 op=2 msgID=3
[06/Apr/2017:11:06:41 +0200] DISCONNECT conn=887 reason="Client Disconnect"
[06/Apr/2017:11:06:41 +0200] CONNECT conn=888 from=192.168.56.203:21987 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:06:41 +0200] BIND REQ conn=888 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:06:41 +0200] BIND RES conn=888 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:06:41 +0200] SEARCH REQ conn=888 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:06:41 +0200] SEARCH RES conn=888 op=1 msgID=2 result=0 nentries=1 etime=2
[06/Apr/2017:11:06:41 +0200] UNBIND REQ conn=888 op=2 msgID=3
[06/Apr/2017:11:06:41 +0200] DISCONNECT conn=888 reason="Client Disconnect"
[06/Apr/2017:11:06:41 +0200] CONNECT conn=889 from=192.168.56.203:21988 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:06:41 +0200] BIND REQ conn=889 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:06:41 +0200] BIND RES conn=889 op=0 msgID=1 result=0 authDN="" etime=1
[06/Apr/2017:11:06:41 +0200] SEARCH REQ conn=889 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:06:41 +0200] SEARCH RES conn=889 op=1 msgID=2 result=0 nentries=1 etime=2
[06/Apr/2017:11:06:41 +0200] UNBIND REQ conn=889 op=2 msgID=3
[06/Apr/2017:11:06:41 +0200] DISCONNECT conn=889 reason="Client Disconnect"

The last test is now with a 12cR2 client. Will it increase now to 4?

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] sqlplus system/manager@dbit122_ldap

SQL*Plus: Release 12.2.0.1.0 Production on Thu Apr 6 11:09:08 2017

Copyright (c) 1982, 2016, Oracle.  All rights reserved.

Last Successful login time: Thu Apr 06 2017 11:06:41 +02:00

Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

No, it did not increase to 4. But with 12cR2 you will see like with 12cR1 also 3 search requests against the OUD.

[dbafmw@dbidg01 logs]$ tail -40f /u01/app/oracle/product/Middleware/11.1.2.3/asinst_1/OUD/logs/access
...
[06/Apr/2017:11:09:07 +0200] CONNECT conn=890 from=192.168.56.203:21990 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:09:07 +0200] BIND REQ conn=890 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:09:07 +0200] BIND RES conn=890 op=0 msgID=1 result=0 authDN="" etime=1
[06/Apr/2017:11:09:07 +0200] SEARCH REQ conn=890 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:09:07 +0200] SEARCH RES conn=890 op=1 msgID=2 result=0 nentries=1 etime=2
[06/Apr/2017:11:09:07 +0200] UNBIND REQ conn=890 op=2 msgID=3
[06/Apr/2017:11:09:07 +0200] DISCONNECT conn=890 reason="Client Disconnect"
[06/Apr/2017:11:09:07 +0200] CONNECT conn=891 from=192.168.56.203:21991 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:09:07 +0200] BIND REQ conn=891 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:09:07 +0200] BIND RES conn=891 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:09:07 +0200] SEARCH REQ conn=891 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:09:07 +0200] SEARCH RES conn=891 op=1 msgID=2 result=0 nentries=1 etime=1
[06/Apr/2017:11:09:07 +0200] UNBIND REQ conn=891 op=2 msgID=3
[06/Apr/2017:11:09:07 +0200] DISCONNECT conn=891 reason="Client Disconnect"
[06/Apr/2017:11:09:07 +0200] CONNECT conn=892 from=192.168.56.203:21992 to=192.168.56.201:1389 protocol=LDAP
[06/Apr/2017:11:09:07 +0200] BIND REQ conn=892 op=0 msgID=1 type=SIMPLE dn="" version=3
[06/Apr/2017:11:09:07 +0200] BIND RES conn=892 op=0 msgID=1 result=0 authDN="" etime=0
[06/Apr/2017:11:09:07 +0200] SEARCH REQ conn=892 op=1 msgID=2 base="cn=dbit122_ldap,cn=OracleContext,dc=dbi,dc=com" scope=base filter="(objectclass=*)" attrs="objectclass,orclNetDescString,orclNetDescName,orclVersion"
[06/Apr/2017:11:09:07 +0200] SEARCH RES conn=892 op=1 msgID=2 result=0 nentries=1 etime=1
[06/Apr/2017:11:09:07 +0200] UNBIND REQ conn=892 op=2 msgID=3
[06/Apr/2017:11:09:07 +0200] DISCONNECT conn=892 reason="Client Disconnect"

So what is the reason for this high increase in ldap searches. Instead of 1, it is doing 3 with 12cR1 and 12cR2, and 2 with 11gR2. That is 66% more than with Oracle 10gR2 clients. That’s enormous from my point view. Quite a huge extra load on your OUD server, when  you upgrade your Oracle clients.

To make it short, I have no answer. It might be related to the old Oracle Names code, which seems that it is still there. I have found errors in the client trace file regarding a A.SMD query. The A.SMD call is coming from the old Oracle Names server, where you could have done stuff like “NAMESCTL> QUERY DB920.oracle.com A.SMD”. But this is really a long time ago. My last Oracle Name server, I have seen in 2002.

oracle@dbidg02:/u01/app/oracle/network/trc/ [DBIT122] cat 12.2_client.trc | grep A.SMD
(4144394624) [04-APR-2017 14:38:18:633] nnfttran: Error querying DBIT122_LDAP of attribute A.SMD errcode 408
(4144394624) [04-APR-2017 14:38:18:642] nnfttran: Error querying DBIT122_LDAP of attribute A.SMD errcode 408
(4144394624) [04-APR-2017 14:38:18:646] nnfttran: Error querying DBIT122_LDAP of attribute A.SMD errcode 408

If I take a look at my 12cR2 adapters I have no Oracle Names compiled in. I don’t know if this is possible at all, with 12c.

oracle@dbidg03:/u01/app/oracle/network/admin/ [DBIT122] adapters | egrep -A 5 "Installed Oracle Net naming methods"
Installed Oracle Net naming methods are:

    Local Naming (tnsnames.ora)
    Oracle Directory Naming
    Oracle Host Naming

Conclusion

Ok. What should I say … take care if you upgrade your clients to more recent versions, in case you use OUD to resolve your names. It might generate some extra load on your OUD servers. More and more with every release since 10gR2. By the way … I have opened a SR at Oracle, because this seems to be a bug for me. I was very surprised, that I was the first one facing this issue. Will keep you posted as soon as I have results. 😉