Welcome Serena Central users! CLICK HERE
The migration of the Serena Central community is currently underway. Be sure to read THIS MESSAGE to get your new login set up to access your account.
porteg Absent Member.
Absent Member.
485 views

Random LDAPs Failures

I have two edir servers handling LDAPs authentication. Sometime before me, a pearl script was setup on our NetScaler to probe these LDAP servers to verify logins. If the script fails, an alert is sent to our SEIM which in turn send out a page stating that the LDAP server is down. Below is an ndstrace of a few down events. I this random event issue has been going on for a few months with no resolution. any help is much appreciated.

New TLS connection 0xcce7500 from 172.24.0.14:61555, monitor = 0xe5770700, index = 15
[2018/04/05 7:22:05.166] Monitor 0xe5770700 initiating TLS handshake on connection 0xcce7500
[2018/04/05 7:22:05.167] (172.24.0.14:61555)(0x0000:0x00) DoTLSHandshake on connection 0xcce7500
[2018/04/05 7:22:05.170] BIO ctrl called with unknown cmd 7
[2018/04/05 7:22:05.170] (172.24.0.14:61555)(0x0000:0x00) Completed TLS handshake on connection 0xcce7500
[2018/04/05 7:22:05.171] (172.24.0.14:61555)(0x0016:0x60) DoBind on connection 0xcce7500
[2018/04/05 7:22:05.171] (172.24.0.14:61555)(0x0016:0x60) Bind name:cn=FootPrintsBND,ou=Users,ou=Person,o=IDM, version:3, authentication:simple
[2018/04/05 7:22:06.939] New TLS connection 0xcce6e00 from 172.24.0.11:32027, monitor = 0xe5770700, index = 16
[2018/04/05 7:22:06.939] Monitor 0xe5770700 initiating TLS handshake on connection 0xcce6e00
[2018/04/05 7:22:40.500] New TLS connection 0xfe59c00 from 172.24.0.11:60335, monitor = 0xe5770700, index = 17
[2018/04/05 7:22:45.760] New TLS connection 0xfe59880 from 172.24.0.11:61771, monitor = 0xe5770700, index = 18
[2018/04/05 7:22:51.20] New TLS connection 0xfa77880 from 172.24.0.11:61208, monitor = 0xe5770700, index = 19
[2018/04/05 7:22:55.707] (172.24.0.14:47961)(0x0000:0x00) TLS read failure 5 on connection 0xf867500, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xf867500 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:62827)(0x0000:0x00) TLS read failure 5 on connection 0xeae7c00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xeae7c00 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:47111)(0x0000:0x00) TLS read failure 5 on connection 0xebbf500, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xebbf500 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:6775)(0x0000:0x00) TLS read failure 5 on connection 0xfb41c00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xfb41c00 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:2929)(0x0000:0x00) TLS read failure 5 on connection 0xeae6700, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xeae6700 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.11:36622)(0x0000:0x00) TLS read failure 5 on connection 0xf3f0380, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xf3f0380 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] Monitor 0xe5770700 initiating TLS handshake on connection 0xfe59880
[2018/04/05 7:22:55.707] (172.24.0.14:40601)(0x0000:0x00) TLS read failure 5 on connection 0xecbf880, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xecbf880 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:55162)(0x0000:0x00) TLS read failure 5 on connection 0xebbe380, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xebbe380 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:7217)(0x0000:0x00) TLS read failure 5 on connection 0xebbe000, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xebbe000 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] Monitor 0xe5770700 initiating TLS handshake on connection 0xfa77880
[2018/04/05 7:22:55.707] (172.24.0.14:63350)(0x0000:0x00) TLS read failure 5 on connection 0xebbfc00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xebbfc00 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:61555)(0x0000:0x00) TLS read failure 5 on connection 0xcce7500, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xcce7500 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.11:55441)(0x0000:0x00) TLS read failure 5 on connection 0xe98d500, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xe98d500 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] (172.24.0.14:36058)(0x0000:0x00) TLS read failure 5 on connection 0xecc5880, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xecc5880 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.707] Monitor 0xe5770700 initiating TLS handshake on connection 0xfe59c00
[2018/04/05 7:22:55.707] (172.24.0.14:10671)(0x0000:0x00) TLS read failure 5 on connection 0xeae6380, setting err = -5875. Error stack:
[2018/04/05 7:22:55.707] Monitor 0xe5770700 found connection 0xeae6380 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.708] (172.24.0.14:9185)(0x0000:0x00) TLS read failure 5 on connection 0xebbee00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.708] Monitor 0xe5770700 found connection 0xebbee00 socket failure, err = -5875, 0 of 0 bytes read
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xeae6700
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xeae6380
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xebbfc00
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xebbe000
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xebbf500
[2018/04/05 7:22:55.708] Monitor 0xe5770700 initiating close for connection 0xeae7c00
[2018/04/05 7:22:55.708] (172.24.0.11:32027)(0x0000:0x00) DoTLSHandshake on connection 0xcce6e00
[2018/04/05 7:22:55.708] (172.24.0.11:32027)(0x0000:0x00) TLS accept failure 5 on connection 0xcce6e00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.708] (172.24.0.11:32027)(0x0000:0x00) TLS handshake failed on connection 0xcce6e00, err = -5875
[2018/04/05 7:22:55.708] BIO ctrl called with unknown cmd 7
[2018/04/05 7:22:55.708] Server closing connection 0xcce6e00, socket error = -5875
[2018/04/05 7:22:55.708] Connection 0xcce6e00 closed
[2018/04/05 7:22:55.708] (172.24.0.11:61771)(0x0000:0x00) DoTLSHandshake on connection 0xfe59880
[2018/04/05 7:22:55.708] (172.24.0.11:61208)(0x0000:0x00) DoTLSHandshake on connection 0xfa77880
[2018/04/05 7:22:55.709] (172.24.0.11:60335)(0x0000:0x00) DoTLSHandshake on connection 0xfe59c00
[2018/04/05 7:22:55.709] (172.24.0.11:60335)(0x0000:0x00) TLS accept failure 5 on connection 0xfe59c00, setting err = -5875. Error stack:
[2018/04/05 7:22:55.709] (172.24.0.11:60335)(0x0000:0x00) TLS handshake failed on connection 0xfe59c00, err = -5875
[2018/04/05 7:22:55.709] BIO ctrl called with unknown cmd 7
[2018/04/05 7:22:55.709] Server closing connection 0xfe59c00, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xfe59c00 closed
[2018/04/05 7:22:55.709] Server closing connection 0xeae6700, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xeae6700 closed
[2018/04/05 7:22:55.709] Server closing connection 0xeae6380, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xeae6380 closed
[2018/04/05 7:22:55.709] Server closing connection 0xebbfc00, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xebbfc00 closed
[2018/04/05 7:22:55.709] Server closing connection 0xebbe000, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xebbe000 closed
[2018/04/05 7:22:55.709] Server closing connection 0xebbf500, socket error = -5875
[2018/04/05 7:22:55.709] Connection 0xebbf500 closed
[2018/04/05 7:22:55.709] Server closing connection 0xeae7c00, socket error = -5875
[2018/04/05 7:22:55.710] Connection 0xeae7c00 closed
[2018/04/05 7:22:55.713] BIO ctrl called with unknown cmd 7
[2018/04/05 7:22:55.713] (172.24.0.11:61208)(0x0000:0x00) Completed TLS handshake on connection 0xfa77880
[2018/04/05 7:22:55.716] BIO ctrl called with unknown cmd 7
[2018/04/05 7:22:55.716] (172.24.0.11:61771)(0x0000:0x00) Completed TLS handshake on connection 0xfe59880
[2018/04/05 7:22:55.716] (172.24.0.11:61208)(0x000d:0x60) DoBind on connection 0xfa77880
[2018/04/05 7:22:55.716] (172.24.0.11:61208)(0x000d:0x60) Bind name:cn=ldapsmonitor,ou=Users,ou=Person,o=IDM, version:3, authentication:simple
[2018/04/05 7:22:55.724] (172.24.0.11:61771)(0x000d:0x60) DoBind on connection 0xfe59880
[2018/04/05 7:22:55.724] (172.24.0.11:61771)(0x000d:0x60) Bind name:cn=ldapsmonitor,ou=Users,ou=Person,o=IDM, version:3, authentication:simple
[2018/04/05 7:22:55.813] Server closing connection 0xcce7500, socket error = -5875
[2018/04/05 7:22:55.813] Connection 0xcce7500 closed
[2018/04/05 7:22:55.813] (172.24.0.11:61208)(0x000d:0x60) Sending operation result 0:"":"" to connection 0xfa77880
[2018/04/05 7:22:55.814] Server closing connection 0xecc5880, socket error = -5875
[2018/04/05 7:22:55.814] Connection 0xecc5880 closed
[2018/04/05 7:22:55.815] (172.24.0.11:61771)(0x000d:0x60) Sending operation result 0:"":"" to connection 0xfe59880
[2018/04/05 7:22:55.815] Server closing connection 0xecbf880, socket error = -5875
[2018/04/05 7:22:55.816] Connection 0xecbf880 closed
[2018/04/05 7:22:55.816] (172.24.0.11:61208)(0x000e:0x63) DoSearch on connection 0xfa77880
[2018/04/05 7:22:55.816] (172.24.0.11:61208)(0x000e:0x63) Search request:
base: "ou=Users,ou=Person,o=IDM"
scope:2 dereference:2 sizelimit:0 timelimit:0 attrsonly:0
filter: "(cn=idmservice)"
no attributes
[2018/04/05 7:22:55.816] (172.24.0.11:61208)(0x000e:0x63) Empty attribute list implies all user attributes
[2018/04/05 7:22:55.819] (172.24.0.11:61208)(0x000e:0x63) Sending search result entry "cn=idmservice,ou=Users,ou=Person,o=IDM" to connection 0xfa77880
[2018/04/05 7:22:55.819] (172.24.0.11:61208)(0x000e:0x63) Sending operation result 0:"":"" to connection 0xfa77880
[2018/04/05 7:22:55.820] Server closing connection 0xebbe380, socket error = -5875
[2018/04/05 7:22:55.820] Connection 0xebbe380 closed
[2018/04/05 7:22:55.821] Server closing connection 0xf3f0380, socket error = -5875
[2018/04/05 7:22:55.821] Connection 0xf3f0380 closed
[2018/04/05 7:22:55.821] Server closing connection 0xebbee00, socket error = -5875
[2018/04/05 7:22:55.821] Connection 0xebbee00 closed
[2018/04/05 7:22:55.822] Server closing connection 0xe98d500, socket error = -5875
[2018/04/05 7:22:55.822] Connection 0xe98d500 closed
[2018/04/05 7:22:55.823] Server closing connection 0xfb41c00, socket error = -5875
[2018/04/05 7:22:55.823] Connection 0xfb41c00 closed
[2018/04/05 7:22:55.824] Server closing connection 0xf867500, socket error = -5875
[2018/04/05 7:22:55.824] Connection 0xf867500 closed
[2018/04/05 7:22:55.824] Monitor 0xe5770700 found connection 0xfa77880 ending TLS session
[2018/04/05 7:22:55.824] (172.24.0.11:61771)(0x000e:0x63) DoSearch on connection 0xfe59880
[2018/04/05 7:22:55.824] (172.24.0.11:61771)(0x000e:0x63) Search request:
base: "ou=Users,ou=Person,o=IDM"
scope:2 dereference:2 sizelimit:0 timelimit:0 attrsonly:0
filter: "(cn=idmservice)"
no attributes
[2018/04/05 7:22:55.825] (172.24.0.11:61771)(0x000e:0x63) Empty attribute list implies all user attributes
[2018/04/05 7:22:55.827] (172.24.0.11:61771)(0x000e:0x63) Sending search result entry "cn=idmservice,ou=Users,ou=Person,o=IDM" to connection 0xfe59880
[2018/04/05 7:22:55.827] (172.24.0.11:61771)(0x000e:0x63) Sending operation result 0:"":"" to connection 0xfe59880
[2018/04/05 7:22:55.827] (172.24.0.11:61208)(0x000f:0x42) DoUnbind on connection 0xfa77880
[2018/04/05 7:22:55.827] (172.24.0.11:61208)(0x0000:0x00) Preempting operation 0x0:0x0 on connection 0xfa77880 before processing because connection is closing
[2018/04/05 7:22:55.829] Connection 0xfa77880 closed
[2018/04/05 7:22:55.830] (172.24.0.11:61771)(0x000f:0x42) DoUnbind on connection 0xfe59880
[2018/04/05 7:22:55.830] Connection 0xfe59880 closed
[2018/04/05 7:23:24.580] New TLS connection 0xeae6700 from 172.24.0.11:61281, monitor = 0xe5770700, index = 1
[2018/04/05 7:23:24.581] Monitor 0xe5770700 initiating TLS handshake on connection 0xeae6700
[2018/04/05 7:23:24.581] (172.24.0.11:61281)(0x0000:0x00) DoTLSHandshake on connection 0xeae6700
[2018/04/05 7:23:24.584] BIO ctrl called with unknown cmd 7
[2018/04/05 7:23:24.584] (172.24.0.11:61281)(0x0000:0x00) Completed TLS handshake on connection 0xeae6700
Labels (1)
0 Likes
3 Replies
Knowledge Partner Knowledge Partner
Knowledge Partner

Re: Random LDAPs Failures

When I test an LDAP connection from a Perl script, though using a
cleartext connection, it looks like this:


3905906432 LDAP: [2018/04/05 10:54:27.950] New cleartext connection
0xfa59880 from 137.65.222.159:54735, monitor = 0xd6f6d700, index = 3
3902748416 LDAP: [2018/04/05 10:54:27.951]
(137.65.222.159:54735)(0x0001:0x60) DoBind on connection 0xfa59880
3902748416 LDAP: [2018/04/05 10:54:27.951]
(137.65.222.159:54735)(0x0001:0x60) Bind name:cn=admin,dc=sa,dc=system,
version:3, authentication:simple
3902748416 LDAP: [2018/04/05 10:54:27.955]
(137.65.222.159:54735)(0x0001:0x60) Sending operation result 0:"":"" to
connection 0xfa59880
3418560256 LDAP: [2018/04/05 10:54:28.86]
(137.65.222.159:54735)(0x0002:0x42) DoUnbind on connection 0xfa59880
3418560256 LDAP: [2018/04/05 10:54:28.87] Connection 0xfa59880 closed


In your case you have TLS bits as well, but nothing that prevents the
application (LDAP) authentication from happening, so everything in this
trace looks like a success. Based on that I would guess that something is
wrong with your script causing it to see a false positive (failure that is
not there). Care to post your script logic ot try to duplicate things?
Assuming your script provides some for the load balancer, could you share
output from your script which is presumably returned when something is
detected as going wrong?

--
Good luck.

If you find this post helpful and are logged into the web interface,
show your appreciation and click on the star below.

If you want to send me a private message, please let me know in the
forum as I do not use the web interface often.
0 Likes
porteg Absent Member.
Absent Member.

Re: Random LDAPs Failures

Well figured this out. Turned out out AIX team had done server updates, the server in question is a VM and was left in snapshot mode. Once that was changed issue went away. Thanks for the assistance!!!
0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

Re: Random LDAPs Failures

Sounds good; thank-you for sharing your results.


--
Good luck.

If you find this post helpful and are logged into the web interface,
show your appreciation and click on the star below.

If you want to send me a private message, please let me know in the
forum as I do not use the web interface often.
0 Likes
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.