Troubleshooting Kerberos KCD on NetScaler

Choosing a Service Principal Name

When using Kerberos KCD authentication,?? only a unique value for the Service Principal Name (SPN) is needed.?? It does not need to be the FQDN of the AAA, load balancer, or NetScaler Gateway on the NetScaler.?? This would be different from what we were passing Kerberos from front end (client ) to back end (server).?? This is not the case with KCD as user is not directly authenticating at NetScaler with Kerberos.

Examine the following screen shots for an example:

Choosing a Service Server name

The Server name for the service that is configured on the NetScaler is passed as it is entered.?? In the following example, the actual FQDN is used.?? If load balancing or content switching is not used, then name should pass as it is sent from the client.

Output of nskrb.debug (using name for server in service)

Authentication is successful

 root@SA-VPX1# cat /tmp/nskrb.debug Tue Jun  3 08:34:16 2014 nskrb.c[226]: ns_process_kcd_req username is CRLVal   Tue Jun  3 08:34:16 2014 nskrb.c[230]: ns_process_kcd_req realm is VLAB.CTX, realmlen is 9   Tue Jun  3 08:34:16 2014 nskrb.c[235]: ns_process_kcd_req user_realm is VLAB, user_realmlen is 5   Tue Jun  3 08:34:16 2014 nskrb.c[241]: ns_process_kcd_req svc is wi2.vlab.ctx   Tue Jun  3 08:34:16 2014 nskrb.c[246]: ns_process_kcd_req delegated_user len is 28 value is host/agee.vlab.ctx.VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[251]: ns_process_kcd_req password provided   Tue Jun  3 08:34:16 2014 nskrb.c[297]: ns_process_kcd_req tgt ticket cachename is /var/krb/tgt_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[298]: ns_process_kcd_req delegated cachename is /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[299]: ns_process_kcd_req tgs cachename is /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[559]: ns_kinit cache check failed   Tue Jun  3 08:34:16 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned 0   Tue Jun  3 08:34:16 2014 nskrb.c[908]: ns_kgetcred cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX does not contain ticket for host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[971]: ns_kgetcred krb5_get_creds returned 0, svcname host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX, impersonate str CRLVal@VLAB, deleg NULL outcache /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[999]: ns_kgetcred successfully written credentials to cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[338]: ns_process_kcd_req service name for s4u2proxy is HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[908]: ns_kgetcred cache file /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX does not contain ticket for HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[971]: ns_kgetcred krb5_get_creds returned 0, svcname HTTP/wi2.vlab.ctx@VLAB.CTX, impersonate str NULL, deleg /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX outcache /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[999]: ns_kgetcred successfully written credentials to cache file /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[1005]: ns_kgetcred ns_init_sec_context returned 0, outlen 1409   Tue Jun  3 08:34:16 2014 nskrb.c[359]: ns_process_kcd_req tkt_len is 1409, serialized creds len is 0   Tue Jun  3 08:34:16 2014 nskrb.c[226]: ns_process_kcd_req username is CRLVal   Tue Jun  3 08:34:16 2014 nskrb.c[230]: ns_process_kcd_req realm is VLAB.CTX, realmlen is 9   Tue Jun  3 08:34:16 2014 nskrb.c[235]: ns_process_kcd_req user_realm is VLAB, user_realmlen is 5   Tue Jun  3 08:34:16 2014 nskrb.c[241]: ns_process_kcd_req svc is wi2.vlab.ctx   Tue Jun  3 08:34:16 2014 nskrb.c[246]: ns_process_kcd_req delegated_user len is 28 value is host/agee.vlab.ctx.VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[251]: ns_process_kcd_req password provided   Tue Jun  3 08:34:16 2014 nskrb.c[297]: ns_process_kcd_req tgt ticket cachename is /var/krb/tgt_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[298]: ns_process_kcd_req delegated cachename is /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[299]: ns_process_kcd_req tgs cachename is /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[555]: ns_kinit got TGT in cache, kinit returning   Tue Jun  3 08:34:16 2014 nskrb.c[891]: ns_kgetcred kgetcred cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX  contains ticket for host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[338]: ns_process_kcd_req service name for s4u2proxy is HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[891]: ns_kgetcred kgetcred cache file /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX  contains ticket for HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[897]: ns_kgetcred ns_init_sec_context returned 0, outbuf len 1409 Tue Jun  3 08:34:16 2014 nskrb.c[359]: ns_process_kcd_req tkt_len is 1409, serialized creds len is 0   Tue Jun  3 08:34:16 2014 nskrb.c[226]: ns_process_kcd_req username is CRLVal   Tue Jun  3 08:34:16 2014 nskrb.c[230]: ns_process_kcd_req realm is VLAB.CTX, realmlen is 9   Tue Jun  3 08:34:16 2014 nskrb.c[235]: ns_process_kcd_req user_realm is VLAB, user_realmlen is 5   Tue Jun  3 08:34:16 2014 nskrb.c[241]: ns_process_kcd_req svc is wi2.vlab.ctx   Tue Jun  3 08:34:16 2014 nskrb.c[246]: ns_process_kcd_req delegated_user len is 28 value is host/agee.vlab.ctx.VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[251]: ns_process_kcd_req password provided   Tue Jun  3 08:34:16 2014 nskrb.c[297]: ns_process_kcd_req tgt ticket cachename is /var/krb/tgt_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[298]: ns_process_kcd_req delegated cachename is /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[299]: ns_process_kcd_req tgs cachename is /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX Tue Jun  3 08:34:16 2014 nskrb.c[555]: ns_kinit got TGT in cache, kinit returning   Tue Jun  3 08:34:16 2014 nskrb.c[891]: ns_kgetcred kgetcred cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX  contains ticket for host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[338]: ns_process_kcd_req service name for s4u2proxy is HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[891]: ns_kgetcred kgetcred cache file /var/krb/tgs_CRLVal_VLAB_wi2_VLAB.CTX  contains ticket for HTTP/wi2.vlab.ctx@VLAB.CTX   Tue Jun  3 08:34:16 2014 nskrb.c[897]: ns_kgetcred ns_init_sec_context returned 0, outbuf len 1409 Tue Jun  3 08:34:16 2014 nskrb.c[359]: ns_process_kcd_req tkt_len is 1409, serialized creds len is 0

Output of nskrb.debug (using IP for server in service)

Failure occurs

 Tue Jun  3 08:45:33 2014 nskrb.c[226]: ns_process_kcd_req username is CRLVal   Tue Jun  3 08:45:33 2014 nskrb.c[230]: ns_process_kcd_req realm is VLAB.CTX, realmlen is 9   Tue Jun  3 08:45:33 2014 nskrb.c[235]: ns_process_kcd_req user_realm is VLAB, user_realmlen is 5   Tue Jun  3 08:45:33 2014 nskrb.c[241]: ns_process_kcd_req svc is 192.168.2.27   Tue Jun  3 08:45:33 2014 nskrb.c[246]: ns_process_kcd_req delegated_user len is 28 value is host/agee.vlab.ctx.VLAB.CTX   Tue Jun  3 08:45:33 2014 nskrb.c[251]: ns_process_kcd_req password provided   Tue Jun  3 08:45:33 2014 nskrb.c[297]: ns_process_kcd_req tgt ticket cachename is /var/krb/tgt_agee_VLAB.CTX Tue Jun  3 08:45:33 2014 nskrb.c[298]: ns_process_kcd_req delegated cachename is /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX Tue Jun  3 08:45:33 2014 nskrb.c[299]: ns_process_kcd_req tgs cachename is /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX Tue Jun  3 08:45:33 2014 nskrb.c[563]: ns_kinit cache check failed   Tue Jun  3 08:45:34 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned 0   Tue Jun  3 08:45:34 2014 nskrb.c[911]: ns_kgetcred cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX does not exist   Tue Jun  3 08:45:34 2014 nskrb.c[971]: ns_kgetcred krb5_get_creds returned 0, svcname host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX, impersonate str CRLVal@VLAB, deleg NULL outcache /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX   Tue Jun  3 08:45:34 2014 nskrb.c[999]: ns_kgetcred successfully written credentials to cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX   Tue Jun  3 08:45:34 2014 nskrb.c[338]: ns_process_kcd_req service name for s4u2proxy is HTTP/192.168.2.27@VLAB.CTX   Tue Jun  3 08:45:34 2014 nskrb.c[911]: ns_kgetcred cache file /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX does not exist   Tue Jun  3 08:45:34 2014 nskrb.c[971]: ns_kgetcred krb5_get_creds returned -1765328371, svcname HTTP/192.168.2.27@VLAB.CTX, impersonate str NULL, deleg /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX outcache /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX   Tue Jun  3 08:45:34 2014 nskrb.c[973]: ns_kgetcred krb5_get_creds returned -1765328371   Tue Jun  3 08:45:34 2014 nskrb.c[342]: ns_process_kcd_req reason for failure is 1, retying s4u2proxy Tue Jun  3 08:45:34 2014 nskrb.c[559]: ns_kinit cache check failed   Tue Jun  3 08:45:34 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned -1765328378   Tue Jun  3 08:45:34 2014 nskrb.c[307]: ns_process_kcd_req reason for failure is 1, retying kinit Tue Jun  3 08:45:34 2014 nskrb.c[559]: ns_kinit cache check failed   Tue Jun  3 08:45:35 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned -1765328378   Tue Jun  3 08:45:35 2014 nskrb.c[310]: ns_process_kcd_req kinit sending reject to kernel because of error 1 Tue Jun  3 08:45:35 2014 nskrb.c[226]: ns_process_kcd_req username is CRLVal   Tue Jun  3 08:45:35 2014 nskrb.c[230]: ns_process_kcd_req realm is VLAB.CTX, realmlen is 9   Tue Jun  3 08:45:35 2014 nskrb.c[235]: ns_process_kcd_req user_realm is VLAB, user_realmlen is 5   Tue Jun  3 08:45:35 2014 nskrb.c[241]: ns_process_kcd_req svc is 192.168.2.27   Tue Jun  3 08:45:35 2014 nskrb.c[246]: ns_process_kcd_req delegated_user len is 28 value is host/agee.vlab.ctx.VLAB.CTX   Tue Jun  3 08:45:35 2014 nskrb.c[251]: ns_process_kcd_req password provided   Tue Jun  3 08:45:35 2014 nskrb.c[297]: ns_process_kcd_req tgt ticket cachename is /var/krb/tgt_agee_VLAB.CTX Tue Jun  3 08:45:35 2014 nskrb.c[298]: ns_process_kcd_req delegated cachename is /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX Tue Jun  3 08:45:35 2014 nskrb.c[299]: ns_process_kcd_req tgs cachename is /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX Tue Jun  3 08:45:35 2014 nskrb.c[555]: ns_kinit got TGT in cache, kinit returning   Tue Jun  3 08:45:35 2014 nskrb.c[891]: ns_kgetcred kgetcred cache file /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX  contains ticket for host/agee.vlab.ctx.VLAB.CTX@VLAB.CTX   Tue Jun  3 08:45:35 2014 nskrb.c[338]: ns_process_kcd_req service name for s4u2proxy is HTTP/192.168.2.27@VLAB.CTX   Tue Jun  3 08:45:35 2014 nskrb.c[911]: ns_kgetcred cache file /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX does not exist   Tue Jun  3 08:45:35 2014 nskrb.c[971]: ns_kgetcred krb5_get_creds returned -1765328371, svcname HTTP/192.168.2.27@VLAB.CTX, impersonate str NULL, deleg /var/krb/s4u_CRLVal_VLAB_agee_VLAB.CTX outcache /var/krb/tgs_CRLVal_VLAB_192_VLAB.CTX   Tue Jun  3 08:45:35 2014 nskrb.c[973]: ns_kgetcred krb5_get_creds returned -1765328371   Tue Jun  3 08:45:35 2014 nskrb.c[342]: ns_process_kcd_req reason for failure is 1, retying s4u2proxy Tue Jun  3 08:45:35 2014 nskrb.c[559]: ns_kinit cache check failed   Tue Jun  3 08:45:35 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned -1765328378   Tue Jun  3 08:45:35 2014 nskrb.c[307]: ns_process_kcd_req reason for failure is 1, retying kinit Tue Jun  3 08:45:35 2014 nskrb.c[559]: ns_kinit cache check failed   Tue Jun  3 08:45:35 2014 nskrb.c[682]: get_new_tickets krb5_get_init_creds_keyblock returned -1765328378   Tue Jun  3 08:45:35 2014 nskrb.c[310]: ns_process_kcd_req kinit sending reject to kernel because of error 1

Verify if the server is passing expected headers that will trigger NetScaler to attempt KCD

The following are examples of using CURL on NetScaler to request HTTPS Headers, or looking in a capture performed to see?? if?? the HTTP/1.1 401 response is received with the WWW-Authenticate: Negotiate (which results in attempt for KRB authentication) and WWW-Authenticate: NTLM (allow failback to NTML authentication) HTTP Headers.

Verify if there is a failure at SRV request or connection to when proper 401 response are received

NetScaler will attempt to perform a DNS query for SRV ?? _kerberos._tcp.DNSDomainName to find out what server is running Kerberos KDC service. If NetScaler is sending this through UPD, it can end up being truncated if it is too large, which results in failure. If SRV requests are not failing, then verify if Kerberos traffic is blocked.

The following is an excerpt from SRV Resource Records:
_kerberos._tcp.?? DnsDomainName
Allows a client to locate a server that is running the Kerberos KDC service for the domain that is named in?? DnsDomainName. The server is not necessarily a domain controller. All Windows?? 2000 Server–based domain controllers that are running an RFC?? 1510–compliant Kerberos KDC service register this SRV record.

The following?? example, displays 401 from server.?? Then NetScaler attempts to resolve SRV record. Response is truncated?? and NetScaler fails the resolution.?? If this occurs, you will not see an attempt from NetScaler to KRB (Port 88) as it is not able to resolve where to connect to. This can occur if you have directly added the DNS Servers as UDP.??

If this occurs and you do not witness NetScaler attempt to perform request in TCP Mode, you can add DNS on NetScaler as UDP_TCP; alternatively, you can add local SRV (see the following section) record on NetScale so it does not have to query.

See the following example?? on adding local SRV record on NetScaler. This can also be done to hardset which Kerberos KCD server you want NetScaler to attempt to connect to.
add dns srvRec _kerberos._tcp.vlab.ctx dc.vlab.ctx -priority 0 -weight 100 -port 88
add dns addRec dc.vlab.ctx 192.168.2.12

Using Virtual DNS Server on NetScaler, a retry in TCP Mode can be seen.

??

Example of successful KCD authentication (backend communication)

Frame ?? 23963?? : HTTP/1.1 401 is sent to NetScaler with expected HTTP Headers. NetScaler then performs name query for SRV record. KRB5 traffic from NetScaler to Kerberos KCD server is observed after SRV response.

Frame 24259 : GET is witnessed from NetScale that includes KRB authentication information.