cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
BookmarkSubscribeRSS Feed

SAS Viya 3.5 Kerberos Troubleshooting

Started ‎03-31-2020 by
Modified ‎03-31-2020 by
Views 11,285

Issues with the setup of Kerberos authentication can easily stall an implementation of SAS Viya. Since often Kerberos authentication is required for the end-users to be able to access data. Without access to data the entire implementation goes no-where until the authentication issues are resolved. Equally, for some end-users who don’t use a password to authenticate, issues with Kerberos prevent them from even accessing the SAS Viya environment. In this blog we’ll examine some ways you can troubleshoot Kerberos authentication. Specifically, we’ll demonstrate the different areas you should examine and how you can obtain logging and other information.

 

As I have described in numerous previous posts Kerberos can be used to authenticate to the major components in the SAS Viya environment. Understanding the desired authentication flow and then being able to identify where in that flow things are going astray is the first and most important troubleshooting step.

 

In the rest of this blog we’ll consider the use-case of Kerberos delegation. This is where an end-user authenticates initially using Kerberos and we expect those Kerberos credentials to be delegated through the environment to launch server processes. This could either be a SAS Cloud Analytic Server session or a SAS Compute Server session. A useful client application for testing this scenario is SAS Studio 5.2 (Enterprise). We can then confirm that Kerberos is used to correctly launch the SAS Compute Server session and from within that session launch a SAS Cloud Analytic Server session.

 

SR_SASDelegationOverview_1.png

 

Select any image to see a larger version.
Mobile users: To view the images, select the "Full" version at the bottom of the page.

 

So, we’ll be looking at the central flow in the overview diagram above and examining what we can do at each stage to see what is happening.


 

Checking the Client

The first place we want to start is with the client connection. We need to confirm that Kerberos is being used to authenticate to the SAS Viya Web applications. You need to confirm the browser is correctly configured as detailed in the documentation. Then when you connect to the SAS Viya Web applications in the browser, the service ticket for HTTP should be cached on the client. The ticket cache on Windows can be inspected using the klist command. An example of the expected HTTP Service ticket is given here:

 

#6>     Client: end-user @ CUSTOMER.COM
        Server: HTTP/sasviya.customer.com @ CUSTOMER.COM
        KerbTicket Encryption Type: AES-256-CTS-HMAC-SHA1-96
        Ticket Flags 0x40a50000 -> forwardable renewable pre_authent ok_as_delegate name_canonicalize
        Start Time: 03/17/2020 11:56:01 (local)
        End Time:   03/17/2020 21:56:01 (local)
        Renew Time: 03/24/2020 11:56:01 (local)
        Session Key Type: AES-256-CTS-HMAC-SHA1-96
        Cache Flags: 0
        Kdc Called: 192.168.94.252


 

If the ticket is cached on the client, then we know that the browser has correctly responded to the HTTP-401 message provided by SAS Logon Manager to trigger Kerberos authentication. If we are expecting to perform unconstrained Kerberos delegation then we need to confirm that ok_as_delegate is included in the ticket flags, as shown above. If this is missing, then either the HTTP principal is not trusted for delegation or we are setup for constrained delegation.

 

If there is no ticket cached on the client, then we know something is either wrong in the browser configuration or in the setup for SAS Logon Manager. We can look at browser debugging to determine further what is happening. If we look at the developer tools provided with the browsers, we can look at the network trace of the connection to the SAS Viya Web applications. We expect to see a HTTP-401 response from the request to SASLogon/oauth/authorize and in the request headers we should see the Authorization header. If the HTTP-401 response is not present, then SAS Logon Manager is not correctly configured for Kerberos authentication.

 

If the Authorization header starts "Negotiate TlRM…" then the browser has used NTLM rather than Kerberos. A Kerberos Authorization header will start "Negotiate YII…". The use of NTLM instead of Kerberos points to problems with the Service Principal Name (SPN) for the HTTP principal. Normally, this will be because the hostname used to access the SAS Viya Web applications is an alias and resolves to a different hostname. With Firefox you can enable additional debug logging to confirm what SPN is used, complete the following to enable this logging:

 

  1. Close all instances of Firefox
  2. In a command prompt set the values for the NSPR_LOG_* variables
    • set NSPR_LOG_MODULES=negotiateauth:5
    • set NSPR_LOG_FILE=C:\temp\moz.log
  3. Restart Firefox from that shell and revisit the SAS Viya Web applications
  4. Check the C:\temp\moz.log file for error messages with the nsNegotiateAuth in the message


 

Checking SAS Viya Web Applications

If everything looks correct on the client, then the next step is to look at the SAS Viya Web applications. Here we’ll examine both SAS Logon Manager for accepting the Kerberos authentication and other microservices for delegating the Kerberos authentication onto either SAS Launcher Server or SAS Cloud Analytic Services.

 

First with SAS Logon Manager there are several things we can check. The configuration of SAS Logon Manager should be double-checked to confirm there are no issues in the configuration settings. The setting for the location of the Kerberos keytab file must be a URI. This means that it must begin "FILE://" and then include the full path to the Kerberos keytab file. For example, on Linux this would be:

 

FILE:///opt/sas/http.keytab

 

While on Windows this would be:

 

FILE://C:/ProgramData/SAS/http.keytab

 

Make sure there are no additional characters in this path including spaces at the end of the definition.

Another configuration value to check is the value of impersonate. This must be set to true for Kerberos Constrained Delegation but must be set to false for unconstrained delegation. Finally, the configuration for sas.logon.kerberos must be applied to all services for Kerberos Constrained Delegation. This means that the Services field must be set to Global, as shown here:

 

SR_sas.logon.kerberos_Services_2.png

 

The Kerberos keytab file should be useable to obtain a Ticket-Granting Ticket (TGT) from the KDC. Remember with Active Directory only the User Principal Name (UPN) can be used to obtain a TGT. So, if the UPN = SPN on Linux the following command can be used to validate the Kerberos keytab:

 

kinit -Vkt /opt/sas/http.keytab HTTP/sasviya.customer.com

 

and you should see:

 

Using default cache: /tmp/krb5cc_2000
Using principal: HTTP/sasviya.customer.com
Using keytab: /opt/sas/http.keytab
Authenticated to Kerberos v5

 

If the UPN ≠ SPN then the command would be:

 

kinit -Vkt /opt/sas/http.keytab sasviya@CUSTOMER.COM

 

This will confirm that the keytab contains the current long-term key for the HTTP principal. For Kerberos Constrained Delegation this must be successful as obtaining a TGT for the service is a key part of the S4U2SELF request.

 

Next with SAS Logon Manager additional dynamic logging can be enabled to provide details of the authentication events occurring. This will provide details of both the external authentication using Kerberos as well as the internal group look-up from the Identities microservice. To dynamically enable this logging information, complete the following:

 

  1. In SAS Environment Manager select Configuration → Definitions → logging.level
  2. Select New Configuration
  3. For Services select SAS Logon Manager
  4. For level select DEBUG
  5. For name enter com.sas.logon.authentication


Remember after collecting the information you require to set the level to WARN as this will produce a large amount of logging information. The example below shows a successful authentication using Kerberos.

 

2020-03-17 05:24:05.070 DEBUG 7499 --- [1-auto-1-exec-8] c.s.l.a.m.WebAuthenticationManager : service [30eb5616cf0f0507] Starting external authentication
for:org.springframework.security.kerberos.authentication.KerberosServiceRequestToken@6163d75a: 
Principal: com.sas.logon.user.ExternalUser@ff2c9643: 
Username: end-user; 
Password: [PROTECTED]; 
Enabled: true; 
AccountNonExpired: true; 
credentialsNonExpired: true; 
AccountNonLocked: true; N
ot granted any authorities; 
Credentials: [PROTECTED]; 
Authenticated: true; 
Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 10.96.7.3; SessionId: 6f0ff16e-baa2-48ee-99e3-13614e2310aa; Not granted any authorities

 

This logging information will not necessarily show errors with Kerberos authentication, but it will show the principal obtained for the end-user and then the group look-up for that end-user. As such it can be useful to confirm that the correct end-user is being picked up and that the group look-up from Identities is returning the expected results. Which can be used to confirm the end-user is in specific custom groups such as CASHostAccountRequired.

 

If Kerberos unconstrained delegation is being used, then SAS Logon Manager will be storing the delegated Kerberos credentials with the Credentials microservice. These delegated credentials will then be used to authenticate to either SAS Launcher Server or SAS Cloud Analytic Services. Additional debug logging can be enabled to confirm the storage of these delegated credentials. To enable this dynamic logging, complete the following steps:

 

  1. In Environment Manager select Configuration → Definitions → logging.level
  2. Select New Configuration
  3. For Services select SAS Logon Manager
  4. For level select DEBUG
  5. For name enter com.sas.credentials.jgss

 

Remember after collecting the information you require to set the level to WARN as this will produce sensitive information in the SAS Logon Manager log file. The example below shows SAS Logon Manager successfully storing a delegated Kerberos credential.

 

2020-03-17 12:14:00.451 DEBUG 54484 --- [o-auto-1-exec-2] c.s.c.jgss.GSSCredentialServiceCache     
: service [e73169b212a28a7c] Making PUT request to /credentials/domains/kerberos/users/end-user with content:
 {"creationTimeStamp":null,"modifiedTimeStamp":null,"createdBy":null,"modifiedBy":null,"version":1,"domainId":"kerberos","identityType":"user","identityId":"end-user","domainType":"GSSCredential","properties":{"expires":"1574823360"},"secrets":{"GSSCredential":"rO0ABXNyACtqYXZheC5zZWN1cml0eS5hdXRoLmtlcmJlcm9zLktlcmJlcm9zVGlja2V0ZqGBbXB3w7sCAAtbAAxhc24xRW5jb2Rpbmd0AAJbQkwACGF1dGhUaW1ldAAQTGphdmEvdXRpbC9EYXRlO0wABmNsaWVudHQAMExqYXZheC9zZWN1cml0eS9hdXRoL2tlcmJlcm9zL0tlcmJlcm9zUHJpbmNpcGFsO1sAD2NsaWVudEFkZHJlc3Nlc3QAF1tMamF2YS9uZXQvSW5ldEFkZHJlc3M7TAAHZW5kVGltZXEAfgACWwAFZmxhZ3N0AAJbWkwABXByb3h5dAAtTGphdmF4L3NlY3VyaXR5L2F1dGgva2VyYmVyb3MvS2VyYmVyb3NUaWNrZXQ7TAAJcmVuZXdUaWxscQB+AAJMAAZzZXJ2ZXJxAH4AA0wACnNlc3Npb25LZXl0ACZMamF2YXgvc2VjdXJpdHkvYXV0aC9rZXJiZXJvcy9LZXlJbXBsO0wACXN0YXJ0VGltZXEAfgACeHB1cgACW0Ks8xf4BghU4AIAAHhwAAAEZ2GCBGMwggRfoAMCAQWhDhsMUkFDRS5TQVMuQ09NoiEwH6ADAgECoRgwFhsGa3JidGd0GwxSQUNFLlNBUy5DT02jggQjMIIEH6ADAgESoQMCAQKiggQRBIIEDaLhW6KdP90htxJJ+mufMr9hEJGrS8S3L7FM63LbSCbonj3aEgIFPQqmlKsPD9WYNwo3vKpXc5ZxXLQLGrcZ3G13T6MRpNeKld3Lf+RSep88n3XeStrMMhuyYUfzanXLJiU13SQ70l7Kn7R6HbY6hqrF73z79joFelM6HhAu3L8P/C2/h2e4pNo/SFPXaGH/Ax0uZ1yKMK6X82JNh1FwvcRCq++AuqYvm0gMKGdYklWjC4hitrGQmYbmo3uVqKImhc3EaXFBh5GBulJ8Pit19vscvDNdX85++sEkMENhYr4PTema8S+iUSZf3kpqIxdOdsXVLoN47fPQKmiR69v18Fjj7MHJoa05Q5buJMHPsFJ8irwGtG1OZlNRD7plQeExmFvvtWJsoV9Cz16QY4F7vKbzshGrloOkkVhWakPEzJiAq9UUbE4IorVmypCTbXRim2/0oy/27E3R2rQeSqY/LIuWAGo7uYeHmYqpKEOGkDsrDqOyeVcHgCTZsXatP/pprzNtn9YKqTBmbulW83Aq2E0ajVXIe2RIEp63urEYtfK6+wktQu55QGeWvfvzjmzUljeiDzFOYo0lXSNVXdpZPxMUzJCq7dSmuMON+BFrSMhTf1U/4ANQbKdcMiHDTInH+m3eZLKIpifRgF8ybtxltLVKV/abiaqULmG3Mvnls+cJZ1Pqu5t9hRXNyMW1UZtGxrb1rGzTyjrR7GQr2tW0uq3z/zpTlPGyqtD2+7MtMlixQQ0HyVWfiTmvAx4OykVlGf8BGL0KwJYNW0Q+liLrAgY12ErK3lW/+2Iz7iYXfT5Quk7ATa2UeqnKFWlUInS9wVK8Bog7ClxO2Hdp8zJDqIYjvV4QjKgPMqXEBl8n26YXFzu8+LUSIdvHA1DSrSs3Rh4f611NZKZ4n+8taI1CRHHEhcebzUy74jNVJj5AMXvE5K6FL2VLMuJK5ToVVkmKqctArnqXFkBKI/9NgnDv6+IUGAmpVTznw9WKXOvLmDxjKPThXrVWRVhIbmhDQ0+Rv4XVYoA6ktltgRqGGVO0adaUJFCaTvBOcVL1hrqSp/y5IiDMOWEjXUksVc+PrrkqL5Km7sje8ex2ndZMoV4HjMVz7vL2/Q2GpZn+8Mc9C0FqEkQSNz20SpG6oLdm9o2/jFV1ia+tW3XeWfWLMES4B53lpd8d3lMA0hENm18EAITp+9bgMEixEIyOjnmOqBeqOOXumT1rwU8ry4kDeOh4yqqM0dIbRBM15SfgqFnvj2BCaQ2BCZr6IJzIg4mFzWmkeruQd6WDpvSwc2I7Orn5OD+tGExaydgGIdYmRpu2p/bdrrTLjSi4pKKyMcGzTbA6RareyqKKCjXq+uN1CrZSmbx99z3VitoVYGfkJuaMcHNyAC5qYXZheC5zZWN1cml0eS5hdXRoLmtlcmJlcm9zLktlcmJlcm9zUHJpbmNpcGFsmad9XQ8eMykDAAB4cHVxAH4ACQAAABkwF6ADAgEBoRAwDhsMZ2Vsdml5YWFkbWludXEAfgAJAAAADhsMUkFDRS5TQVMuQ09NeHBzcgAOamF2YS51dGlsLkRhdGVoaoEBS1l0GQMAAHhwdwgAAAFuqsl56Hh1cgACW1pXjyA5FLhd4gIAAHhwAAAAIAABAQAAAAAAAQABAAAAAAEAAAAAAAAAAAAAAAAAAAAAcHNxAH4AD3cIAAABbsywrOh4c3EAfgALdXEAfgAJAAAAITAfoAMCAQKhGDAWGwZrcmJ0Z3QbDFJBQ0UuU0FTLkNPTXVxAH4ACQAAAA4bDFJBQ0UuU0FTLkNPTXhzcgAkamF2YXguc2VjdXJpdHkuYXV0aC5rZXJiZXJvcy5LZXlJbXBskoOG6DyvS9cDAAB4cHVxAH4ACQAAACswKaADAgESoSIEIMA29Y3x4PoDcJJZ4x31AYstKtaeQrOQz52HEUeI3gVGeHNxAH4AD3cIAAABbqikKOh4"},"links":[]}
2020-03-17 12:14:00.588 DEBUG 54484 --- [o-auto-1-exec-2] c.s.c.jgss.GSSCredentialServiceCache     
: service [e73169b212a28a7c] PUT request to /credentials/domains/kerberos/users/end-user returned 200 OK


With Kerberos Constrained Delegation SAS Logon Manager does not store a delegated credential and so nothing will be logged.

Finally, for SAS Logon Manager in some cases looking at the low-level Kerberos debugging can be helpful. This is only helpful if you have already looked at the other logging and are trying to understand what is happening at the lowest Kerberos level. Enabling this level of logging requires a restart of SAS Logon Manager. To view the low-level Kerberos debug messages, you can complete the following:

 

  1. In SAS Environment Manager select Configuration → All services → SAS Logon Manager
  2. Select Edit for the jvm properties
  3. Select Add property, and enter the following:
    1. Name = java_option_debug1
    2. Value = -Dsun.security.krb5.debug=true
    3. Select Save
  4. Select Add property, and enter the following:
    1. Name = java_option_debug2
    2. Value = -Dsun.security.jgss.debug=true
  5. Select Save twice and restart SAS Logon Manager


 With unconstrained Kerberos delegation a successful authentication will output:

 

Search Subject for SPNEGO ACCEPT cred (<<DEF>>, sun.security.jgss.spnego.SpNegoCredElement)
Search Subject for Kerberos V5 ACCEPT cred (<<DEF>>, sun.security.jgss.krb5.Krb5AcceptCredential)
Found KeyTab c:\temp\http-SUKSAR-WIN.keytab for HTTP/sasviya.customer.com@CUSTOMER.COM
Found KeyTab c:\temp\http-SUKSAR-WIN.keytab for HTTP/sasviya.customer.com@CUSTOMER.COM
Entered Krb5Context.acceptSecContext with state=STATE_NEW
Looking for keys for: HTTP/sasviya.customer.com@CUSTOMER.COM
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for HTTP/sasviya.customer.com@CUSTOMER.COM
Found unsupported keytype (1) for HTTP/sasviya.customer.com@CUSTOMER.COM
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
Using builtin default etypes for permitted_enctypes
default etypes for permitted_enctypes: 18 17 16 23.
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
MemoryCache: add 1574788440/000075/84EA15E863EAF09740DC973220E68E3B/end-user@CUSTOMER.COM to end-user@CUSTOMER.COM|HTTP/sasviya.customer.com@CUSTOMER.COM
>>> KrbApReq: authenticate succeed.
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
>>>Delegated Creds have pname=end-user@CUSTOMER.COM sname=krbtgt/CUSTOMER.COM@CUSTOMER.COM authtime=null starttime=20191126165601Z endtime=20191127025601ZrenewTill=20191203165601Z
Krb5Context setting peerSeqNumber to: 1691579139
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
Krb5Context setting mySeqNumber to: 478450500
Created Subject with the following
principals=[]
public creds=[]
private creds=[Ticket (hex) = 
0000: 61 82 04 63 30 82 04 5F   A0 03 02 01 05 A1 0E 1B  a..c0.._........
0010: 0C 52 41 43 45 2E 53 41   53 2E 43 4F 4D A2 21 30  .CUSTOMER.COM.!0
0020: 1F A0 03 02 01 02 A1 18   30 16 1B 06 6B 72 62 74  ........0...krbt
0030: 67 74 1B 0C 52 41 43 45   2E 53 41 53 2E 43 4F 4D  gt..CUSTOMER.COM
0040: A3 82 04 23 30 82 04 1F   A0 03 02 01 12 A1 03 02  ...#0...........
0050: 01 02 A2 82 04 11 04 82   04 0D A2 E1 5B A2 9D 3F  ............[..?
0060: DD 21 B7 12 49 FA 6B 9F   32 BF 61 10 91 AB 4B C4  .!..I.k.2.a...K.
0070: B7 2F B1 4C EB 72 DB 48   26 E8 9E 3D DA 12 02 05  ./.L.r.H&..=....
0080: 3D 0A A6 94 AB 0F 0F D5   98 37 0A 37 BC AA 57 73  =........7.7..Ws
0090: 96 71 5C B4 0B 1A B7 19   DC 6D 77 4F A3 11 A4 D7  .q\......mwO....
00A0: 8A 95 DD CB 7F E4 52 7A   9F 3C 9F 75 DE 4A DA CC  ......Rz.<.u.J..
00B0: 32 1B B2 61 47 F3 6A 75   CB 26 25 35 DD 24 3B D2  2..aG.ju.&%5.$;.
00C0: 5E CA 9F B4 7A 1D B6 3A   86 AA C5 EF 7C FB F6 3A  ^...z..:.......:
00D0: 05 7A 53 3A 1E 10 2E DC   BF 0F FC 2D BF 87 67 B8  .zS:.......-..g.
00E0: A4 DA 3F 48 53 D7 68 61   FF 03 1D 2E 67 5C 8A 30  ..?HS.ha....g\.0
00F0: AE 97 F3 62 4D 87 51 70   BD C4 42 AB EF 80 BA A6  ...bM.Qp..B.....
0100: 2F 9B 48 0C 28 67 58 92   55 A3 0B 88 62 B6 B1 90  /.H.(gX.U...b...
0110: 99 86 E6 A3 7B 95 A8 A2   26 85 CD C4 69 71 41 87  ........&...iqA.
0120: 91 81 BA 52 7C 3E 2B 75   F6 FB 1C BC 33 5D 5F CE  ...R.>+u....3]_.
0130: 7E FA C1 24 30 43 61 62   BE 0F 4D E9 9A F1 2F A2  ...$0Cab..M.../.
0140: 51 26 5F DE 4A 6A 23 17   4E 76 C5 D5 2E 83 78 ED  Q&_.Jj#.Nv....x.
0150: F3 D0 2A 68 91 EB DB F5   F0 58 E3 EC C1 C9 A1 AD  ..*h.....X......
0160: 39 43 96 EE 24 C1 CF B0   52 7C 8A BC 06 B4 6D 4E  9C..$...R.....mN
0170: 66 53 51 0F BA 65 41 E1   31 98 5B EF B5 62 6C A1  fSQ..eA.1.[..bl.
0180: 5F 42 CF 5E 90 63 81 7B   BC A6 F3 B2 11 AB 96 83  _B.^.c..........
0190: A4 91 58 56 6A 43 C4 CC   98 80 AB D5 14 6C 4E 08  ..XVjC.......lN.
01A0: A2 B5 66 CA 90 93 6D 74   62 9B 6F F4 A3 2F F6 EC  ..f...mtb.o../..
01B0: 4D D1 DA B4 1E 4A A6 3F   2C 8B 96 00 6A 3B B9 87  M....J.?,...j;..
01C0: 87 99 8A A9 28 43 86 90   3B 2B 0E A3 B2 79 57 07  ....(C..;+...yW.
01D0: 80 24 D9 B1 76 AD 3F FA   69 AF 33 6D 9F D6 0A A9  .$..v.?.i.3m....
01E0: 30 66 6E E9 56 F3 70 2A   D8 4D 1A 8D 55 C8 7B 64  0fn.V.p*.M..U..d
01F0: 48 12 9E B7 BA B1 18 B5   F2 BA FB 09 2D 42 EE 79  H...........-B.y
0200: 40 67 96 BD FB F3 8E 6C   D4 96 37 A2 0F 31 4E 62  @g.....l..7..1Nb
0210: 8D 25 5D 23 55 5D DA 59   3F 13 14 CC 90 AA ED D4  .%]#U].Y?.......
0220: A6 B8 C3 8D F8 11 6B 48   C8 53 7F 55 3F E0 03 50  ......kH.S.U?..P
0230: 6C A7 5C 32 21 C3 4C 89   C7 FA 6D DE 64 B2 88 A6  l.\2!.L...m.d...
0240: 27 D1 80 5F 32 6E DC 65   B4 B5 4A 57 F6 9B 89 AA  '.._2n.e..JW....
0250: 94 2E 61 B7 32 F9 E5 B3   E7 09 67 53 EA BB 9B 7D  ..a.2.....gS....
0260: 85 15 CD C8 C5 B5 51 9B   46 C6 B6 F5 AC 6C D3 CA  ......Q.F....l..
0270: 3A D1 EC 64 2B DA D5 B4   BA AD F3 FF 3A 53 94 F1  :..d+.......:S..
0280: B2 AA D0 F6 FB B3 2D 32   58 B1 41 0D 07 C9 55 9F  ......-2X.A...U.
0290: 89 39 AF 03 1E 0E CA 45   65 19 FF 01 18 BD 0A C0  .9.....Ee.......
02A0: 96 0D 5B 44 3E 96 22 EB   02 06 35 D8 4A CA DE 55  ..[D>."...5.J..U
02B0: BF FB 62 33 EE 26 17 7D   3E 50 BA 4E C0 4D AD 94  ..b3.&..>P.N.M..
02C0: 7A A9 CA 15 69 54 22 74   BD C1 52 BC 06 88 3B 0A  z...iT"t..R...;.
02D0: 5C 4E D8 77 69 F3 32 43   A8 86 23 BD 5E 10 8C A8  \N.wi.2C..#.^...
02E0: 0F 32 A5 C4 06 5F 27 DB   A6 17 17 3B BC F8 B5 12  .2..._'....;....
02F0: 21 DB C7 03 50 D2 AD 2B   37 46 1E 1F EB 5D 4D 64  !...P..+7F...]Md
0300: A6 78 9F EF 2D 68 8D 42   44 71 C4 85 C7 9B CD 4C  .x..-h.BDq.....L
0310: BB E2 33 55 26 3E 40 31   7B C4 E4 AE 85 2F 65 4B  ..3U&>@1...../eK
0320: 32 E2 4A E5 3A 15 56 49   8A A9 CB 40 AE 7A 97 16  2.J.:.VI...@.z..
0330: 40 4A 23 FF 4D 82 70 EF   EB E2 14 18 09 A9 55 3C  @J#.M.p.......U<
0340: E7 C3 D5 8A 5C EB CB 98   3C 63 28 F4 E1 5E B5 56  ....\...<c(..^.V
0350: 45 58 48 6E 68 43 43 4F   91 BF 85 D5 62 80 3A 92  EXHnhCCO....b.:.
0360: D9 6D 81 1A 86 19 53 B4   69 D6 94 24 50 9A 4E F0  .m....S.i..$P.N.
0370: 4E 71 52 F5 86 BA 92 A7   FC B9 22 20 CC 39 61 23  NqR......." .9a#
0380: 5D 49 2C 55 CF 8F AE B9   2A 2F 92 A6 EE C8 DE F1  ]I,U....*/......
0390: EC 76 9D D6 4C A1 5E 07   8C C5 73 EE F2 F6 FD 0D  .v..L.^...s.....
03A0: 86 A5 99 FE F0 C7 3D 0B   41 6A 12 44 12 37 3D B4  ......=.Aj.D.7=.
03B0: 4A 91 BA A0 B7 66 F6 8D   BF 8C 55 75 89 AF AD 5B  J....f....Uu...[
03C0: 75 DE 59 F5 8B 30 44 B8   07 9D E5 A5 DF 1D DE 53  u.Y..0D........S
03D0: 00 D2 11 0D 9B 5F 04 00   84 E9 FB D6 E0 30 48 B1  ....._.......0H.
03E0: 10 8C 8E 8E 79 8E A8 17   AA 38 E5 EE 99 3D 6B C1  ....y....8...=k.
03F0: 4F 2B CB 89 03 78 E8 78   CA AA 8C D1 D2 1B 44 13  O+...x.x......D.
0400: 35 E5 27 E0 A8 59 EF 8F   60 42 69 0D 81 09 9A FA  5.'..Y..`Bi.....
0410: 20 9C C8 83 89 85 CD 69   A4 7A BB 90 77 A5 83 A6   ......i.z..w...
0420: F4 B0 73 62 3B 3A B9 F9   38 3F AD 18 4C 5A C9 D8  ..sb;:..8?..LZ..
0430: 06 21 D6 26 46 9B B6 A7   F6 DD AE B4 CB 8D 28 B8  .!.&F.........(.
0440: A4 A2 B2 31 C1 B3 4D B0   3A 45 AA DE CA A2 8A 0A  ...1..M.:E......
0450: 35 EA FA E3 75 0A B6 52   99 BC 7D F7 3D D5 8A DA  5...u..R....=...
0460: 15 60 67 E4 26 E6 8C                               .`g.&..

Client Principal = end-user@CUSTOMER.COM
Server Principal = krbtgt/CUSTOMER.COM@CUSTOMER.COM
Session Key = EncryptionKey: keyType=18 keyBytes (hex dump)=
0000: C0 36 F5 8D F1 E0 FA 03   70 92 59 E3 1D F5 01 8B  .6......p.Y.....
0010: 2D 2A D6 9E 42 B3 90 CF   9D 87 11 47 88 DE 05 46  -*..B......G...F


Forwardable Ticket true
Forwarded Ticket true
Proxiable Ticket false
Proxy Ticket false
Postdated Ticket false
Renewable Ticket true
Initial Ticket true
Auth Time = null
Start Time = Tue Mar 17 11:56:01 EST 2019
End Time = Tue Mar 17 21:56:01 EST 2019
Renew Till = Tue Mar 27 11:56:01 EST 2019
Client Addresses  Null ]


 

Note: If you don’t see any "Added key" lines then this points to an issue with the Kerberos keytab; either the path or the file permissions.

 

While with Kerberos Constrained Delegation a successful authentication will output:

 

>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
Using builtin default etypes for permitted_enctypes 18
default etypes for permitted_enctypes: 18 17 16 23.
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
MemoryCache: add 1579260742/000453/71E1457E408261686642ADFED91978D1/end-user@CUSTOMER.COM to end-user@CUSTOMER.COM|HTTP/sasviya.customer.com@CUSTOMER.COM
>>> KrbApReq: authenticate succeed.
Krb5Context setting peerSeqNumber to: 1150464000
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
Krb5Context setting mySeqNumber to: 710375542
>>> Constrained deleg from GSSCaller{UNKNOWN}


One case where this low level of debugging can be useful is where the encryption type of the Kerberos keytab does not match the encryption type of the service ticket.

 

Once you have confirmed what is happening with SAS Logon Manager you can look at the microservices making a connection to either SAS Cloud Analytic Services or SAS Launcher Server. This applies for both constrained and unconstrained delegation. For the SAS Compute Server this would be the SAS Launcher Service, while for SAS Cloud Analytic Services this is most often the CAS Management Service. We can use additional logging on these services to see what credentials are used to authenticate the end-user. To dynamically enable this logging information, complete the following:

 

  1. In SAS Environment Manager select Configuration → Definitions → logging.level
  2. Select New Configuration
  3. For Services select either Launcher service and/or CAS Management service
  4. For level select DEBUG
  5. For name enter com.sas.credentials.jgss


Remember after collecting the information you require to set the level to WARN. This will log information to either <configuration directory>/var/log/launcher/default/ or <configuration directory>/var/log/cas-administration/default.

 

For Kerberos Constrained Delegation we will see the S4U2self request to obtain credentials for the end-user using impersonation. The HTTP principal is used for the S4U2self request. Then we see that the impersonated credentials for the end-user are obtained and the remaining lifetime for these credentials.

 

2020-03-17 07:05:54.062 DEBUG 27414 --- [1-auto-1-exec-1] c.s.c.jgss.GSSCredentialServiceCache     : end-user1 [c4331dc1bc967168] Attempting to get credentials for end-user@CUSTOMER.COM through impersonation
Debug is  true storeKey true useTicketCache false useKeyTab true doNotPrompt true ticketCache is null isInitiator true 
KeyTab is ///opt/sas/http.keytab refreshKrb5Config is false 
principal is HTTP/sasviya.gellab.net tryFirstPass is false useFirstPass is false storePass is false clearPass is false
principal is HTTP/sasviya.customer.com@CUSTOMER.COM
Will use keytab
Commit Succeeded
2020-03-17 07:05:54.071 DEBUG 27414 --- [1-auto-1-exec-1] c.s.c.jgss.GSSCredentialServiceCache     
: end-user [c4331dc1bc967168] Got impersonated credentials for end-user@CUSTOMER.COM with remaining lifetime of 35999 secs


While for unconstrained delegation we will see the Launcher service or CAS Management service fetch the delegated credentials from the Credentials microservice:

 

2020-03-17 05:47:03.445 DEBUG 31668 --- [o-auto-1-exec-2] c.s.c.jgss.GSSCredentialServiceCache     
: end-user(1c8d6d5b) [b686920c423d42f0] Making GET request to /credentials/domains/kerberos/secrets
2020-03-17 05:47:03.591 DEBUG 31668 --- [o-auto-1-exec-2] c.s.c.jgss.GSSCredentialServiceCache     
: end-user(1c8d6d5b) [b686920c423d42f0] GET request to /credentials/domains/kerberos/secrets returned 200 OK


Through these logging options we can easily see if there are issues obtaining the delegated credentials, which are then used to connect to SAS Cloud Analytic Services or the SAS Launcher Server.

 

Checking SAS Viya Runtimes

Finally, we can look at either the SAS Cloud Analytic Services Controller or SAS Launcher & Compute Servers. On Linux, in addition to looking at the microservice that launches the connection, the ticket cache can be inspected. This can be done once the session has been launched. The ticket cache will be generated in /tmp with the name tkt<rand>. This will be on either the host running the SAS Compute Server or the SAS Cloud Analytic Services controller. The following command run either as root or with sudo access, to view other users’ files, will display the content of the ticket cache:

 

ls -tr /tmp/tkt*|tail -1 |xargs klist -c

 

Below shows an example ticket cache for the SAS Compute Server. You can see the principal name of the end-user is given as the Default principal. For Kerberos Constrained Delegation it is important to confirm that the Service Principal for the first ticket matches the client for the krbtgt or Ticket-Granting Ticket. This shows that the ticket is obtained through Kerberos Constrained Delegation.

 

Ticket cache: FILE:/tmp/tktfo85Jf
Default principal: end-user@CUSTOMER.COM

Valid starting       Expires              Service principal
03/17/2020 07:05:54  03/17/2020 17:05:54  sas-launcher/sasviya.customer.com@CUSTOMER.COM
03/17/2020 07:05:54  03/17/2020 17:05:54  krbtgt/CUSTOMER.COM@CUSTOMER.COM
        for client sas-launcher/sasviya.customer.com@CUSTOMER.COM, renew until 03/24/2020 07:05:54


Finally, the SAS Cloud Analytic Services Controller log file can be checked, and the ticket cache created by the CAS Controller verified. The CAS Controller log file should show successful authentication with Kerberos and messages regarding the ticket cache, that CAS is unable to renew:

 

2020-03-17T07:52:11,505 INFO  [00001289] MAIN NoUser MAIN [tkident.c:1323] - 
User end-user successfully authenticated using the Kerberos authentication provider.
2020-03-17T07:52:11,720 WARN  [00000007] 14651 end-user 186 [tkidentgss.c:257] - 
Kerberos failure in function krb5_get_credentials: Matching credential not found (filename: /tmp/tktG0QL4f) (96C73A8D).
2020-03-17T07:52:11,720 WARN  [00000007] 14651 end-user1 186 [tkidentgss.c:2570] - 
Kerberos ticket in cache /tmp/tktG0QL4f cannot be renewed.


If the newer version of the MIT Kerberos library is used, then CAS is able to determine that the delegated ticket is constrained. Then the successful authentication message is changed to "User %U.*s has authenticated using constrained kerberos." Also, CAS does not attempt to renew such constrained delegation tickets. This in turn prevents the messages regarding the inability to renew the ticket, being written to the log.

 

Also, a dynamic logger can be enabled for SAS Cloud Analytic Services to obtain more information on the Kerberos authentication handshake with SAS Logon Manager. The dynamic logger "App.cas.tkcal" can be used to show the flow of the authentication between SAS Cloud Analytic Services and SAS Logon Manager.

 

To edit the loggers for SAS Cloud Analytic Services, complete the following:

 

  1. Log into SAS Environment Manager with a user who is a member of SAS Administrators and opt into the SASAdministrators group
  2. Select Servers
  3. Right click on the SAS Cloud Analytic Services server, normally cas-shared-default, and select Assume the Superuser role
  4. Right click on the SAS Cloud Analytic Services server and select Settings
  5. Select the Logging tab
  6. Select the pen icon to edit the logging configuration
    1. You can now add and delete individual loggers
    2. Add Name = App.cas.tkcal and select level = Trace
    3. Select Save
  7. Select Close

 

This logger will remain set for the lifetime of the SAS Cloud Analytic Services process. You can either restart the SAS Cloud Analytic Services process or repeat the process above to remove the additional logger. You should be aware that "App.cas.tkcal" will produce a large amount of logging information. You should only have this enabled while you are troubleshooting.

For example, an end-user connecting to SAS Cloud Analytic Services from SAS Studio 5.2 (Enterprise) using Kerberos for authentication would produce the following logging information:

 

>2020-03-17T09:44:22,407 INFO  [00000004] MAIN NoUser MAIN [tkcalsock.c:936] - New client connection accepted on port 5570. Client IP address and port are [10.96.3.151]:38216. Connection number 405. TLS is required.
2020-03-17T09:44:22,408 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:305] - Allowing oauth only launches
2020-03-17T09:44:22,408 TRACE [00000581] MAIN NoUser MAIN [tkcalsident.c:384] - Entering server authentication
2020-03-17T09:44:22,427 TRACE [00000581] MAIN NoUser MAIN [tkcalsident.c:436] - Client did not supply a user agent string.
2020-03-17T09:44:22,427 INFO  [00000581] MAIN NoUser MAIN [tkcalsident.c:439] - Client version long is 'V.03.05M0P11062019'.
2020-03-17T09:44:22,427 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:464] - Locale set to 'en_US'
2020-03-17T09:44:22,427 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:472] - Received request length 1549
2020-03-17T09:44:22,427 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:484] - The client provided credentials of type: token.
2020-03-17T09:44:22,427 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:581] - OAuth token received
2020-03-17T09:44:22,431 INFO  [00000581] MAIN NoUser MAIN [tkidentoauth.c:737] - OAuth user end-user requested host launch.
2020-03-17T09:44:22,541 INFO  [00000581] MAIN NoUser MAIN [tkident.c:1323] - User end-user successfully authenticated using the OAuth authentication provider.
2020-03-17T09:44:22,541 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:634] - OAuth with Kerberos ticket to be fetched
2020-03-17T09:44:22,541 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:873] - Switching to kerberos handshake
2020-03-17T09:44:22,541 TRACE [00000581] MAIN NoUser MAIN [tkcalsident.c:384] - Entering server authentication
2020-03-17T09:44:22,550 TRACE [00000581] MAIN NoUser MAIN [tkcalsident.c:469] - Next pass through authentication loop
2020-03-17T09:44:22,550 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:472] - Received request length 2853
2020-03-17T09:44:22,550 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:484] - The client provided credentials of type: token.
2020-03-17T09:44:22,550 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:547] - Kerberos token received
2020-03-17T09:44:22,554 INFO  [00000581] MAIN NoUser MAIN [tkidentgss.c:976] - User end-user@customer.com has authenticated using kerberos.
2020-03-17T09:44:22,555 INFO  [00000581] MAIN NoUser MAIN [tkident.c:1323] - User end-user successfully authenticated using the Kerberos authentication provider.
2020-03-17T09:44:22,555 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:863] - Server returning kerberos handshake blob
2020-03-17T09:44:22,555 TRACE [00000581] MAIN NoUser MAIN [tkcalsident.c:915] - Sending final kerberos handshake blob
2020-03-17T09:44:22,555 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:926] - Clean authentication loop exit
2020-03-17T09:44:22,555 DEBUG [00000581] MAIN NoUser MAIN [tkcalsident.c:978] - Authenticated: name=end-user, dom=, uniqueId=end-user isHostToken=1, isAnonymous=0, isProcessOwner=0
2020-03-17T09:44:22,555 INFO  [00000581] MAIN NoUser MAIN [tkcsesinst.c:748] - Successfully created session 79216955-a823-0e4f-a6f1-585c8cb56ede.
2020-03-17T09:44:22,568 INFO  [00000581] MAIN end-user 77 [casgeneral.c:4823] - Launched session controller. Process ID is 17618.
2020-03-17T09:44:22,610 INFO  [00000007] 17618 end-user MAIN [cas.c:2310] - Starting Cloud Analytic Services driver, host=cas01.customer.com, id=0, role=session controller.
2020-03-17T09:44:22,612 INFO  [00000007] 17618 end-user MAIN [tkcsesinst.c:748] - Successfully created session 79216955-a823-0e4f-a6f1-585c8cb56ede.
2020-03-17T09:44:22,617 INFO  [00000007] 17618 end-user 77 [tkhttpserver.c:1353] - Starting HTTP server 'cas01.customer.com', minPort=0 maxPort=0
2020-03-17T09:44:22,617 INFO  [00000007] 17618 end-user 77 [tkhttpserver.c:1438] - HTTP Server 'cas01.customer.com' listening on port 46193.
2020-03-17T09:44:22,632 INFO  [00000007] 17618 end-user 77 [cashttp.c:1936] - HTTP server is authenticating connections.
2020-03-17T09:44:22,632 INFO  [00000007] 17618 end-user 77 [cashttp.c:1983] - HTTP server listening on HTTPS port 46193.
2020-03-17T09:44:22,700 WARN  [00000007] 17618 end-user 77 [tkidentgss.c:2065] - Kerberos ticket in cache /tmp/tktB7SpMN will expire on Tue Mar 17 19:42:50 2020, and can no longer be renewed.
2020-03-17T09:44:22,753 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:4448] - ++ action sessionProp.setFmtSearch / fmtLibNames={'SASSuppliedFormats'};
2020-03-17T09:44:22,759 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:6397] -  -- 'sessionProp.setFmtSearch' SUCCESSFUL.
2020-03-17T09:44:22,773 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:4448] - ++ action sessionProp.getSessOpt / name='caslib';
2020-03-17T09:44:22,774 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:6397] -  -- 'sessionProp.getSessOpt' SUCCESSFUL.
2020-03-17T09:44:22,775 TRACE [00000007] 17618 end-user 77 [tkcalproto.c:77] - Sending response severity:0 tag:2 flags:0 {1 results}
2020-03-17T09:44:22,776 TRACE [00000007] 17618 end-user 77 [tkcalproto.c:77] - Sending response severity:0 tag:3 flags:0 {0 results}
2020-03-17T09:44:22,789 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:4448] - ++ action sessionProp.getSessOpt / name='nWorkers';
2020-03-17T09:44:22,791 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:6397] -  -- 'sessionProp.getSessOpt' SUCCESSFUL.
2020-03-17T09:44:22,792 TRACE [00000007] 17618 end-user 77 [tkcalproto.c:77] - Sending response severity:0 tag:2 flags:0 {1 results}
2020-03-17T09:44:22,792 TRACE [00000007] 17618 end-user 77 [tkcalproto.c:77] - Sending response severity:0 tag:3 flags:0 {0 results}
2020-03-17T09:44:22,811 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:4448] - ++ action session.sessionName / name='MYSESSION';
2020-03-17T09:44:22,814 INFO  [00000007] 17618 end-user 77 [tkcasaimp.c:6397] -  -- 'session.sessionName' SUCCESSFUL.


 

Other Use-Cases

So far, we have only considered the simple use-case of Kerberos delegation within the SAS Viya environment. However, Kerberos delegation can also be used to authenticate from a SAS 9.4 environment to the SAS Viya environment. SAS Foundation sessions in SAS 9.4 can make direct connections to SAS Cloud Analytic Services, and with SAS Viya 3.5 SAS Enterprise Guide 8.2 can make direct connections to the SAS Object Spawner in SAS Viya.

 

When end-users directly connect to SAS Cloud Analytic Services, they will still require an internal OAuth token generated by SAS Logon Manager in SAS Viya. This means the process steps are reversed, for this direct connection. The CAS controller must first accept and authenticate the Kerberos connection from SAS 9.4. Then the CAS controller must use the delegated credentials to authenticate to SAS Logon Manager. The most common problem with this use-case is the authentication to SAS Logon Manager, resulting in the following error in the SAS 9.4 Foundation session:

 

ERROR: Connection failed. Server returned: SAS Logon Manager authentication failed: Access denied.

 

For example, if the SPN for the HTTP principal is not registered correctly we will see the following the CAS Controller log for the connection attempt:

 

2020-03-17T10:12:13,199 INFO  [00000960] MAIN NoUser MAIN [tkcidentgss.c:108] - Kerberos authentication failure in function gss_init_sec_context: Unspecified GSS failure.  Minor code may provide more information.
2020-03-17T10:12:13,200 INFO  [00000960] MAIN NoUser MAIN [tkcidentgss.c:147] - Additional information: Server not found in Kerberos database.
2020-03-17T10:12:22,723 ERROR [00000960] MAIN NoUser MAIN [tkmtrbMethods.c:2048] - SubmitRequestWithFiles: uri='https://sasviya.customer.com:443/SASLogon/oauth/authorize?client_id=sas.tkmtrb&response_type=token', correlator='X-SAS-Correlator: 6322F2BA-544B-5748-942E-6AE66F8EFEEA;'.
2020-03-17T10:12:22,723 ERROR [00000960] MAIN NoUser MAIN [tkmtrbMethods.c:2051] - SubmitRequestWithFiles: status=8dbff828 httpStatus=401 'Unauthorized'.
2020-03-17T10:12:22,726 ERROR [00000960] MAIN NoUser MAIN [tkmtrbMethods.c:2076] - HTTP error returned from service.
2020-03-17T10:12:22,727 ERROR [00000960] MAIN NoUser MAIN [tkmtrbAuth.c:1329] - Logon requires a username.
2020-03-17T10:12:22,727 ERROR [00000960] MAIN NoUser MAIN [tkidentmid.c:719] - Kerberos user 'end-user' failed mid-tier authentication.
2020-03-17T10:12:22,727 ERROR [00000960] MAIN NoUser MAIN [tkidentmid.c:721] - Access denied.


To obtain further information on the authentication of the end-user by the SAS Cloud Analytic Services Controller, two different dynamic loggers can be enabled. The first dynamic logger "Audit.Authentication" will provide details on the CAS Controller processing the Kerberos authentication, operating system lookup, and authentication to SAS Logon Manager. For Kerberos and the operating system lookup you will see messages such as:

 

2020-03-17T12:57:54,070 TRACE [00005059] MAIN NoUser MAIN [tkident.c:620] - IdentThreadAuthenticateUser: 3
2020-03-17T12:57:54,070 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:750] - IdentGSSAuthenticate
2020-03-17T12:57:54,070 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:770] - In GSSAPI initial call
2020-03-17T12:57:54,070 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:789] - Input buffer size: 2797
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:915] - Response buffer size: 152
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:193] - Security context completed: 0x1B3
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:195] -     GSS_C_DELEG_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:197] -     GSS_C_MUTUAL_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:203] -     GSS_C_CONF_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:205] -     GSS_C_INTEG_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:209] -     GSS_C_PROT_READY_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:211] -     GSS_C_TRANS_FLAG
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:486] - gss_inquire_cred_by_oid not available
2020-03-17T12:57:54,072 INFO  [00005059] MAIN NoUser MAIN [tkidentgss.c:976] - User end-user@CUSTOMER.COM has authenticated using kerberos.
2020-03-17T12:57:54,072 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:1083] - User found: 1094001468:1094002622
2020-03-17T12:57:54,072 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:353] - Using linux getgrouplist routine: end-user
2020-03-17T12:57:54,072 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:98] - Getting groups for user end-user
2020-03-17T12:57:54,073 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:244] - 1: grp_sas (1094002622)
2020-03-17T12:57:54,073 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:244] - 2: AD viya users (1094001467)
2020-03-17T12:57:54,075 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:244] - 3: domain users (1094000513)
2020-03-17T12:57:54,075 TRACE [00005059] MAIN NoUser MAIN [tkidentgrp.c:244] - 4: AD cas host launch (1094001845)
2020-03-17T12:57:54,075 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:1154] - Client user name is end-user
2020-03-17T12:57:54,075 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:1157] - REALM will be stripped
2020-03-17T12:57:54,075 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:563] - Delegated client principal name: end-user@CUSTOMER.COM, lifetime: 32893 seconds
2020-03-17T12:57:54,075 DEBUG [00005059] MAIN NoUser MAIN [tkidentgss.c:652] - Cred cache file: /tmp/tktIz2JSR
2020-03-17T12:57:54,076 INFO  [00005059] MAIN NoUser MAIN [tkident.c:1323] - User end-user successfully authenticated using the Kerberos authentication provider.


 While for the SAS Logon Manager authentication you will see:

 

2020-03-17T12:57:54,076 DEBUG [00005059] MAIN NoUser MAIN [tkidentmid.c:557] - Username provided end-user
2020-03-17T12:57:54,076 TRACE [00005059] MAIN NoUser MAIN [tkident.c:3293] - No such token element 1 exists for token type 3.
2020-03-17T12:57:54,148 TRACE [00005059] MAIN NoUser MAIN [tkcidentgss.c:434] - Created spn: HTTP@sasviya.customer.com
2020-03-17T12:57:54,149 TRACE [00005059] MAIN NoUser MAIN [tkcidentgss.c:490] - Initial call to initialize context
2020-03-17T12:57:54,149 TRACE [00005059] MAIN NoUser MAIN [tkcidentgss.c:551] - Passed SPN 'HTTP@sasviya.customer.com'
2020-03-17T12:57:54,149 DEBUG [00005059] MAIN NoUser MAIN [tkcidentgss.c:623] - Using delegated credentials for init call
2020-03-17T12:57:54,155 DEBUG [00005059] MAIN NoUser MAIN [tkcidentgss.c:694] - Continue returned
2020-03-17T12:57:54,155 DEBUG [00005059] MAIN NoUser MAIN [tkcidentgss.c:701] - Output buffer size: 2796
2020-03-17T12:57:54,396 TRACE [00005059] MAIN NoUser MAIN [tkidring.c:721] - IdRingEnc
2020-03-17T12:57:54,396 TRACE [00005059] MAIN NoUser MAIN [tkidring.c:1075] - IdRingGetCipher: 4
2020-03-17T12:57:54,399 TRACE [00005059] MAIN NoUser MAIN [tkidring.c:1326] - IdRingFreeCipher
2020-03-17T12:57:54,399 DEBUG [00005059] MAIN NoUser MAIN [tkidentmid.c:704] - Kerberos user 'end-user' converted to OAUTH token.
2020-03-17T12:57:54,399 TRACE [00005059] MAIN NoUser MAIN [tkident.c:620] - IdentThreadAuthenticateUser: 6
2020-03-17T12:57:54,399 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:139] - oauthAuthenticate(): Validating token.
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:166] - Oauth token origin: kerberos
2020-03-17T12:57:54,400 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:170] - Kerberos claim found in oauth token
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:190] - Oauth token ext_id: end-user@CUSTOMER.COM
2020-03-17T12:57:54,400 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:279] - User request: end-user
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:289] - Oauth token zid: uaa
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:380] - Groups from scope claim
2020-03-17T12:57:54,400 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:616] - 4 token group memberships
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:888] - oauthAuthenticate(): entire ident tok length: 1465
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:889] - oauthAuthenticate(): oauth tok length: 1281
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkidentoauth.c:890] - oauthAuthenticate(): u/p item length: 152
2020-03-17T12:57:54,400 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:903] - oauthAuthenticate(): Token validated.
2020-03-17T12:57:54,400 DEBUG [00005059] MAIN NoUser MAIN [tkidentoauth.c:914] - userpass/kerb oauth token validated
2020-03-17T12:57:54,400 INFO  [00005059] MAIN NoUser MAIN [tkident.c:1323] - User end-user successfully authenticated using the OAuth authentication provider.
2020-03-17T12:57:54,400 TRACE [00005059] MAIN NoUser MAIN [tkident.c:256] - Destroying user token


 The second dynamic logger is "App.tk.mtrb". Setting "App.tk.mtrb" to trace will provide even more details on the authentication to SAS Logon Manager. This will provide details on building the HTTP request to SAS Logon Manager and the messages sent back and forth between the CAS Controller and SAS Logon Manager.

 

All dynamic loggers can be enabled using SAS Environment Manager without needing to restart SAS Cloud Analytic Services. To edit the loggers for SAS Cloud Analytic Services, complete the following:

 

  1. Log into SAS Environment Manager with a user who is a member of SAS Administrators and opt into the SASAdministrators group
  2. Select Servers
  3. Right click on the SAS Cloud Analytic Services server, normally cas-shared-default, and select Assume the Superuser role
  4. Right click on the SAS Cloud Analytic Services server and select Settings
  5. Select the Logging tab
  6. Select the pen icon to edit the logging configuration
    1. You can now add and delete individual loggers
    2. For example, add Name = App.tk.mtrb and select level = Trace
    3. Or add Name = Audit.Authentication and select level = Trace
    4. Select Save
  7. Select Close


 These loggers will remain set for the lifetime of the SAS Cloud Analytic Services process. You can either restart the SAS Cloud Analytic Services process or repeat the process above to remove the additional logger. You should be aware that both "Audit.Authentication" and "App.tk.mtrb" will produce a large amount of logging information. You should only have these enabled while you are troubleshooting.

 

Conclusion

Kerberos authentication is a popular choice for many customers who want strong authentication. When everything is working correctly it provides a seamless authentication flow for the end-users into, through, and out from the SAS Viya environment. However, when there are issues it can be difficult to pin-point the areas where problems occur. Hopefully, this blog as provided you with details of how you can debug Kerberos authentication with SAS Viya.

Comments
MichaelShealy
‎08-26-2020 08:36 AM
‎08-26-2020 08:36 AM

Hey Stuart,

 

This is a really really good post...used it yesterday to help diagnose auth issues at a client running a new Viya 3.5 install over Windows.  Quick question:  with the NSPR_LOG updates on Firefox, do only errors get written to that log?  Or should it be chatty about the entire process?  We didn't end up with anything written in our moz log yesterday, though we figured out the problem using other steps.

 

Thanks as always for all the good Kerberos info!

 

Michael

 

0 Likes
StuartRogers
‎08-27-2020 07:09 AM
‎08-27-2020 07:09 AM

Hello Michael,

Sorry to hear the debugging options didn't work - but great news that you resolved the issue.  I've had a look into this and found the following...

 

So it looks like at some point Firefox has stopped using the NSPR options for debugging.  From Firefox 52 you can now do this dynamically using about:networking, documentation available here: https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging

 

Go to about:networking, then select Logging.  Change the log file to the location you want and set the Log Modules to "timestamp,negotiateauth:5".  Then hit the "Start Logging" button and in a new tab visit the site you want to debug.  The log will only be written when you come back and hit the "Stop Logging" button.  Closing Firefox will undo the changes you've made and you'll be back to the default logging options.

 

Thank you for your time.

 

Stuart

0 Likes
Version history
Last update:
‎03-31-2020 12:21 PM
Updated by:
SAS Employee
Contributors

sas-innovate-2024.png

Don't miss out on SAS Innovate - Register now for the FREE Livestream!

Can't make it to Vegas? No problem! Watch our general sessions LIVE or on-demand starting April 17th. Hear from SAS execs, best-selling author Adam Grant, Hot Ones host Sean Evans, top tech journalist Kara Swisher, AI expert Cassie Kozyrkov, and the mind-blowing dance crew iLuminate! Plus, get access to over 20 breakout sessions.

 

Register now!

Free course: Data Literacy Essentials

Data Literacy is for all, even absolute beginners. Jump on board with this free e-learning  and boost your career prospects.

Get Started

Article Labels
Article Tags