Sunday, November 23, 2014

Troubleshooting Citrix NetScaler LDAP Authentication Issues

One of the changes I liked most about the NetScaler NS10.5 release was that the reliance on Java has finally been removed and replaced with HTML5.  I can’t count how many times I’ve been frustrated at a client’s office trying to make a simple change to their NetScaler but end up spending an hour getting Java to work.  With that said, it appears that one of the features that the old NetScalers provided, Create Authentication Server, no longer has the Retrieve Attributes feature to test your configuration:

image

Notice how the new 10.5 NetScaler’s Configure Authentication LDAP Server no longer has this option:

image

As simple as this Retrieve Attributes feature may seem, I found it extremely useful to quickly validate the configuration settings.  What I’ve noticed is that with this feature removed, I’ve been asked several times how would it be possible to troubleshoot simple errors such as typing in the wrong password for the service account.  The answer to this question is using the aaad.debug log as demonstrated in the following article:

How to Troubleshoot Authentication with aaad.debug
http://support.citrix.com/article/CTX114999

As an example, let’s say I made a mistake when typing in the password for the service account used by the NetScaler to perform LDAP lookups and when I try to sign in through the portal, I receive the following:

image

Incorrect credentials. Try again.

image

Being by launching the SSH client of your choice and connect to your NetScaler and type in shell to get into the Linux operating system:

image

Change to the /tmp directory where the aaad.debug log is stored:

image

Type in cat aaa.debug to display the contents of the debug file as items get logged:

image

Now reproduce the error by logging in again:

image

Viewing the SSH session will show that entries into the log are written to the aaad.debug file:

image

The following is the items written from the failed login:


root@ns# cat aaad.debug
Tue Nov 11 20:32:56 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[498]: main timer 1 firing...
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[784]: process_kernel_socket call to authenticate
user :terence-admin, vsid :9612
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2592]: start_cascade_auth starting cascade authentication
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[106]: start_ldap_auth Starting LDAP auth
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[129]: start_ldap_auth attempting to auth terence-admin @ 10.26.10.30
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[131]: start_ldap_auth LDAP referrals are OFF
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[132]: start_ldap_auth LDAP referral nesting depth 0
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[629]: continue_ldap_init Connecting to: 10.26.10.30:636
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2802]: register_timer setting timer 147
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2871]: unregister_timer releasing timer 147
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[697]: ns_ldap_set_up_socket Server certificate hostname = NULL
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[705]: ns_ldap_set_up_socket Setting timeouts for SSL/TLS.
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[738]: ns_ldap_set_up_socket Set cert verify level 0
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[755]: ns_ldap_set_up_socket setting up for SSL connection to : 10.26.10.30:636
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2802]: register_timer setting timer 148
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[180]: receive_ldap_bind_event receive ldap bind event

Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[356]: ns_ldap_check_result checking LDAP result.  Expecting 97 (LDAP_RES_BIND)
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[391]: ns_ldap_check_result ldap_result found expected result LDAP_RES_BIND
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[221]: ns_show_ldap_err_string LDAP error string: <<80090308: LdapErr: DSID-0C0903C8, comment: AcceptSecurityContext error, data 52e, v2580>>
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[401]: ns_ldap_check_result LDAP action failed (error 49): Invalid credentials
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[206]: receive_ldap_bind_event Got LDAP error.
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2871]: unregister_timer releasing timer 148
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2161]: send_reject_with_code Rejecting with error code 4001
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2188]: send_reject_with_code Not trying cascade again
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[2190]: send_reject_with_code sending reject to kernel for : terence-admin
Tue Nov 11 20:33:26 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[498]: main timer 1 firing...
Tue Nov 11 20:33:56 2014
/home/build/rs_105/usr.src/netscaler/aaad/naaad.c[498]: main timer 1 firing...

I find the SSH session windows often difficult to read so I usually copy and paste the text into Notepad to parse through it:

image

Carefully reviewing the log will reveal the following line that is of interest:

Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_common.c[401]: ns_ldap_check_result LDAP action failed (error 49): Invalid credentials
Tue Nov 11 20:33:07 2014
/home/build/rs_105/usr.src/netscaler/aaad/ldap_drv.c[206]: receive_ldap_bind_event Got LDAP error.

The portal login error should begin to work once the password is updated correctly in the Authentication LDAP Server configuration:

image

5 comments:

Grega Zoubek said...

Hi Terence,

nice blog ;). Just wanted to let you know that 'retrieve attributes' option was back with 10.5.52 release.

All the best!
Grega Zoubek
Citrix

Anonymous said...

Also a good idea to make sure you have your DNS configured correctly on the netscaler device.

Rich said...

I'm running 10.5.56, and only see the retrieve attributes for plaintext. As soon as I change it to ssl or tls, it goes away.

Julio H├ęctor AGUILAR RENTERIA said...

Hello, could you fix the error?

Michael said...

What if all the symptoms and aaad.debug report is/are identical, and the correct Bind Password is inserted, but it still doesn't work?