Hi Roman Were able to successfully configure the SPNEGO authentication?
Best Regards Ritesh On Thursday, 15 October 2020 at 15:47:48 UTC+5:30 [email protected] wrote: > Hello, > > *CAS Version*: 5.1, > > *Deployment: * > 1. CAS server: By build a WAR overlay project which contains spnego > configurations. And deployed the cas.war on apache-tomcat-9.0.37. cas runs > on OS: Linux（Red Hat 7.5) (kerberos installed and configured). > 2. kdc(AD domain controller): windows server 2012. > 3. client: windows 10 Professional, joined the AD domain. > 4. nginx reverse proxy: nginx/1.16.1 (runs on Red Hat 7.5) > > *Problem description:* > First, without nginx, when I accessed cas server directly, I can see the > login success page directly without entering username or password. Or when > I accessed an application which had been remoulded to a cas client(as well > a kdc client) , I can access it directly without login. That is I realized > the spnego feature. > > But, considering hign availability, I need to deploy a cas cluster. Before > cluster deployment, I conducted a test with one nginx server and one cas > server, to test if some problems will appear when HTTP requests were > fowarded by nginx. Then, problems appeared. Spnego didn't work, I got the > login page. The architecture is like this: > client->nginx->cas server->kdc, nginx is a single node, cas server is also > a single node, kdc is also a single node. > > By combining the nginx log and the cas log, it looks like cas get a wrong > spnego token which is decoded from the authorization header. But I have no > idea that why cas get a wrong token. > > *cas log:* > I tuned the cas log level to debug, and the error log is: > > 2020-10-15 12:11:01,538 DEBUG > [org.springframework.webflow.engine.ActionState] - <Entering state > 'startSpnegoAuthenticate' of flow 'login'> > 2020-10-15 12:11:01,538 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Executing > [EvaluateAction@52a9f67a expression = negociateSpnego, resultExpression = > [null]]> > 2020-10-15 12:11:01,538 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Executing > org.apereo.cas.web.flow.SpnegoNegociateCredentialsAction@1eab5ae5> > 2020-10-15 12:11:01,538 DEBUG > [org.apereo.cas.web.flow.SpnegoNegociateCredentialsAction] - <Authorization > header [Negotiate > TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAKAO5CAAAADw==], User Agent > header [Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, > like Gecko) Chrome/85.0.4183.102 Safari/537.36]> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Finished > executing > org.apereo.cas.web.flow.SpnegoNegociateCredentialsAction@1eab5ae5; result = > success> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Finished > executing [EvaluateAction@52a9f67a expression = negociateSpnego, > resultExpression = [null]]; result = success> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.engine.Transition] - <Executing > [Transition@20916eb1 on = success, to = spnego]> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.engine.Transition] - <Exiting state > 'startSpnegoAuthenticate'> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.engine.ActionState] - <Entering state 'spnego' > of flow 'login'> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Executing > [EvaluateAction@643b792 expression = spnego, resultExpression = [null]]> > 2020-10-15 12:11:01,539 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Executing > org.apereo.cas.web.flow.SpnegoCredentialsAction@288b9d98> > 2020-10-15 12:11:01,540 DEBUG > [org.apereo.cas.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization > header located as [Negotiate > TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAKAO5CAAAADw==]> > 2020-10-15 12:11:01,541 DEBUG > [org.apereo.cas.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization > header found with [56] bytes> > 2020-10-15 12:11:01,543 DEBUG > [org.apereo.cas.web.flow.SpnegoCredentialsAction] - <Obtained token: > [NTLMSSP ?? B ?].Creating SPNEGO credential...> > 2020-10-15 12:11:04,047 DEBUG > [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] > - <Located client IP address as [172.28.5.156]> > 2020-10-15 12:11:04,048 DEBUG > [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] > - <User agent [Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 > (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36] is authorized to > proceed> > 2020-10-15 12:11:04,048 DEBUG > [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] > - <Adaptive authentication policy has authorized client [172.28.5.156] to > proceed.> > 2020-10-15 12:11:04,049 DEBUG [org.apereo.cas.web.support.WebUtils] - > <Evaluating request to determine if warning cookie should be generated> > 2020-10-15 12:11:04,050 DEBUG > [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] > > - <Located ticket-granting ticket [null] from the request context> > 2020-10-15 12:11:04,051 DEBUG > [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] > > - <Located service [null] from the request context> > 2020-10-15 12:11:04,052 DEBUG > [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] > > - <Provided value for [renew] request parameter is [null]> > 2020-10-15 12:11:04,052 DEBUG > [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] > > - <Request is not eligible to be issued service tickets just yet> > 2020-10-15 12:11:04,053 DEBUG [org.apereo.cas.web.support.WebUtils] - > <Evaluating request to determine if warning cookie should be generated> > 2020-10-15 12:11:04,070 DEBUG > [org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver] > > - <Authentication handlers used for this transaction are [Active > DirectoryJcifsSpnegoAuthenticationHandlerHttpBasedServiceCredentialsAuthenticationHandler]> > 2020-10-15 12:11:07,822 DEBUG > [org.apereo.cas.support.spnego.authentication.handler.support.JcifsSpnegoAuthenticationHandler] > > - <Processing SPNEGO authentication> > 2020-10-15 12:11:07,823 INFO > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <[JcifsSpnegoAuthenticationHandler] failed authenticating [unknown]> > 2020-10-15 12:11:07,828 DEBUG > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <[JcifsSpnegoAuthenticationHandler] exception details: [Error performing > NTLM authentication: java.net.UnknownHostException: CAS.TEST.COM #<1C>]> > 2020-10-15 12:11:07,829 INFO > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <[JcifsSpnegoAuthenticationHandler] failed authenticating [unknown]> > 2020-10-15 12:11:07,830 DEBUG > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <[JcifsSpnegoAuthenticationHandler] exception details: [Error performing > NTLM authentication: java.net.UnknownHostException: CAS.TEST.COM #<1C>]> > 2020-10-15 12:11:07,835 WARN > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <Authentication has failed. Credentials may be incorrect or CAS cannot find > authentication handler that supports [unknown] of type [SpnegoCredential], > which suggests a configuration problem.> > 2020-10-15 12:11:07,836 WARN > [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - > <Authentication has failed. Credentials may be incorrect or CAS cannot find > authentication handler that supports [unknown] of type [SpnegoCredential], > which suggests a configuration problem.> > > *nginx log:* > the relevant log of nginx: > > 2020/10/15 12:13:53 [debug] 22689#0: *103 http process request header line > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Host: > nginx.test.com:9991" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Connection: > keep-alive" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Authorization: > Negotiate TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAKAO5CAAAADw==" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: > "Upgrade-Insecure-Requests: 1" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "User-Agent: > Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) > Chrome/85.0.4183.102 Safari/537.36" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Accept: > text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Purpose: prefetch" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Accept-Encoding: > gzip, deflate" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header: "Accept-Language: > zh-CN,zh;q=0.9" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http header done > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 0 > 2020/10/15 12:13:53 [debug] 22689#0: *103 rewrite phase: 1 > 2020/10/15 12:13:53 [debug] 22689#0: *103 test location: "/" > 2020/10/15 12:13:53 [debug] 22689#0: *103 using configuration "/" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http cl:-1 max:1048576000 > 2020/10/15 12:13:53 [debug] 22689#0: *103 rewrite phase: 3 > 2020/10/15 12:13:53 [debug] 22689#0: *103 post rewrite phase: 4 > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 5 > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 6 > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 7 > 2020/10/15 12:13:53 [debug] 22689#0: *103 access phase: 8 > 2020/10/15 12:13:53 [debug] 22689#0: *103 access phase: 9 > 2020/10/15 12:13:53 [debug] 22689#0: *103 access phase: 10 > 2020/10/15 12:13:53 [debug] 22689#0: *103 post access phase: 11 > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 12 > 2020/10/15 12:13:53 [debug] 22689#0: *103 generic phase: 13 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http init upstream, client > timer: 0 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: > "X-Forwarded-For" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script var: "172.28.28.178" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "X-Real-IP" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script var: "172.28.28.178" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "Host" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script var: " > nginx.test.com:9991" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "Connection" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "close" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http script copy: "" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: > "Authorization: Negotiate > TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAKAO5CAAAADw==" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: > "Upgrade-Insecure-Requests: 1" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: "User-Agent: > Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) > Chrome/85.0.4183.102 Safari/537.36" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: "Accept: > text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: "Purpose: > prefetch" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: > "Accept-Encoding: gzip, deflate" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: > "Accept-Language: zh-CN,zh;q=0.9" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http proxy header: > "GET /cas/login HTTP/1.0 > > > X-Forwarded-For: 172.28.28.178 > > > X-Real-IP: 172.28.28.178 > > > Host: nginx.test.com:9991 > > > Connection: close > > > Authorization: Negotiate > TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAKAO5CAAAADw== > > > Upgrade-Insecure-Requests: 1 > > > User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 > (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36 > > > Accept: > text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 > > > Purpose: prefetch > > > Accept-Encoding: gzip, deflate > > > Accept-Language: zh-CN,zh;q=0.9 > > > > > > > " > 2020/10/15 12:13:53 [debug] 22689#0: *103 http cleanup add: > 00000000008B1F78 > 2020/10/15 12:13:53 [debug] 22689#0: *103 get rr peer, try: 1 > 2020/10/15 12:13:53 [debug] 22689#0: *103 stream socket 14 > 2020/10/15 12:13:53 [debug] 22689#0: *103 epoll add connection: fd:14 > ev:80002005 > 2020/10/15 12:13:53 [debug] 22689#0: *103 connect to 172.28.5.146:8080, > fd:14 #109 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream connect: -2 > 2020/10/15 12:13:53 [debug] 22689#0: *103 posix_memalign: > 00000000008680C0:128 @16 > 2020/10/15 12:13:53 [debug] 22689#0: *103 event timer add: 14: 60000: > 4502709212 <(450)%20270-9212> > 2020/10/15 12:13:53 [debug] 22689#0: *103 http finalize request: -4, > "/cas/login?" a:1, c:2 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http request count:2 blk:0 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http run request: "/cas/login?" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream check client, > write event:1, "/cas/login" > 2020/10/15 12:13:53 [debug] 22689#0: timer delta: 98 > 2020/10/15 12:13:53 [debug] 22689#0: worker cycle > 2020/10/15 12:13:53 [debug] 22689#0: epoll timer: 60000 > 2020/10/15 12:13:53 [debug] 22689#0: epoll: fd:14 ev:0004 > d:00007FA77C2E8790 > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream request: > "/cas/login?" > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream send request > handler > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream send request > 2020/10/15 12:13:53 [debug] 22689#0: *103 http upstream send request body > 2020/10/15 12:13:53 [debug] 22689#0: *103 chain writer buf fl:1 s:597 > 2020/10/15 12:13:53 [debug] 22689#0: *103 chain writer in: 00000000008B1FB8 > 2020/10/15 12:13:53 [debug] 22689#0: *103 writev: 597 of 597 > 2020/10/15 12:13:53 [debug] 22689#0: *103 chain writer out: > 0000000000000000 > 2020/10/15 12:13:53 [debug] 22689#0: *103 event timer del: 14: 4502709212 > <(450)%20270-9212> > 2020/10/15 12:13:53 [debug] 22689#0: *103 event timer add: 14: 3600000: > 4506249215 <(450)%20624-9215> > > *My analysis:* > The client obtained a service ticket from kdc already, and the client > sended the spnego token(i.e. the http authorization header) to nginx. Nginx > forwarded the request to cas server. So, Nginx forwaded the request that > carried the spnego token already, the authorization header was also > forwarded. The cas server also received the request which contains the > spnego token already. > But the spnego token that is obtained from kdc is wrong. > The correct spnego token is like this(When a client access cas server > directly,without nginx, the spnego token the cas server obtained is correct > ): > [image: right.png] > *and the correct authorization header is long enough:* > 2020-10-14 11:56:26,302 DEBUG > [org.springframework.webflow.execution.ActionExecutor] - <Executing > org.apereo.cas.web.flow.SpnegoCredentialsAction@381eab18> > 2020-10-14 11:56:26,302 DEBUG > [org.apereo.cas.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization > header located as [Negotiate > YIIGXgYGKwYBBQUCoIIGUjCCBk6gMDAuBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYKKwYBBAGCNwICHgYKKwYBBAGCNwICCqKCBhgEggYUYIIGEAYJKoZIhvcSAQICAQBuggX/MIIF+6ADAgEFoQMCAQ6iBwMFACAAAACjggRLYYIERzCCBEOgAwIBBaEKGwhURVNULkNPTaIfMB2gAwIBAqEWMBQbBEhUVFAbDGNhcy50ZXN0LmNvbaOCBA0wggQJoAMCARehAwIBBqKCA/sEggP3jLzYsT7ktodtwO886WRH/OfAZCy8Yz5SxoyWO4bC0mI+IV+lrFlKDu3wwxorPb6QGi1GKcSwAmaWIAodb4rcDrguWLtUe2yOSgX/O0lFKg1CKxLLLYUKTWG0yjdWtOUcUPsn9quZw6bvAuYnb+SHVzH/Zk0MxHyR7pO6RbFiHAyRUFfLjMRj1KOHFwPIaY7kSEQC4gPRGYxn6umg45k7BLVXhCP/dl6WGm44GT+dZSgNFhgWYH5QMEFIY9cbW3Ac4glq2SsdOcdMVIBjtTd5VbAz9O5Z5XwcjXbL/tqcDfBo6hr0NwN0KGsE1ODFi8tXpYYWzmzZjRM3FNZu4AeZUwRgoJPD8yBfgYSX/U+f2k5zwCmgHAvn1/gvL0p+qj75kV2FmK4vL6UaGSd19GOFq1J4nBZLUVMaCpBEHb1r9O9IddND/pmUcrw5OUS2x39DbgEEXXivNSD9oFx0fJrKKY+VKEcWMYKR73iBoXJle4sR1gpt0J4K5XKDyi5Htgdni+f4OVT02YzcRzNo/9Hjc67lQ7ZR8I/B9Yh84wGx0rNPkE8xeybN/fChPIr/ShMcQ0b7kG853uUY7wbzHjiKewk/Kxg+T8a4Sv+lLf5oJBD1vh05dNdrKTYA2365TsbU8t3GyKp9+86Hy4mB8kcrMYXvLnhcZ2nXxG23m+xROOgSUDsw/62XJ5ioATIXWNKStRC3W3OUtjxKNbX1N+lg7JKcBrIpJom2eWpYGb7RawFL4c5KGOFzFVeWL0isMfMnJ/0Ms769Yu0zQvn8zVHzbG3/DzUcS1VSiPZ9yX+PrVvV1gsny8ujCKE01al9p/8MLURtqkVzdDnKrENh+kV2Kr88YKHVEVLEDigDepdaZI3tbEFFEQ9ZLbecCXNcCqi+in4p3IOsDA27wdI+JV6FST5Y4/Lubbj11gSvbZDKc7OrttUNTkpDWu4tBEftx7N7k2qDAFD7UNRKptb6+Cd9x52IPZGm3PMqUl/MYydYEyQrtCQ/JGd1w9rHLkhgk+7WEyh0Hef+chE0O0v5kUpv8kGvX/udCU6K9Su4Ejr0saCgs/9lddK/MkavJrgAKwzL2jWeZTdqgI2Cg1KAj12SYBcb/URNRUDddd2HjDET9a8NReATNXcnL21HvBHTMA4FX7QheGRrM9JhJXh+5+7wSRdM0Y1zUQDYJrwdiCFCoN7Ot3qf97kXRAc1Vj24a5a5dIXVLNRy8hzykIEohoeGYkVTsaUCAmMl4Ev0zdk7VwlNg6igQH1pv5G0mKYUo9/mq69L7CO3dwNqUhMLSIn8Axj+VItxxf8Msv6dzcTga2eFLa64H2jIFNxDWj0ujGah9OZCfq9qH6SCAZUwggGRoAMCAReiggGIBIIBhBXCMBUR/B4e3VitNUAbo5p6Yy6GxOPdyITHLVNml7v0ckXLCcW4iCxHTuC17lvWRbbYIW7h8GQ27zubgTuaZJK7AOKqRuIUnlymUKTEDwy4TWS0ctTVk1lEdzrQM3f9k1VjIL06lsvvHkxCv9sTSKttyoQDjM9UP4qQnfrrAvEiniJmv/TovT65scZRaKfjan0kdR51PjN1uBPfSIgIlDxtOP2mpLTjrbZA2Jr0YP0uJ1gnSycgwkwTnQYGiGRcHns9YwZr+yICyuIemQ+RM6Jb4/X3uI/MgkeuM+Xqv9r6HXjbugqrUGc+s9ufbaG3PUCFJ+cC4zO/DN8DAQ4RSkUhu/uQgS+6OXf9DqKczRIqNrdiFfFNbFtoulZdvH9XYUl6Lm0IXVImDGvxgBccJpQbwu9GZbLo0C8V9tWJwdU0YsQp+SyZe7+9SBYvRHXzYTURXUJrUmxtFt6mmsiYu6zjh4c+mBwfPv8wdVaKNa/wtGb3vZ1EwerkcPFbY9Aa1vHK7oI=]> > 2020-10-14 11:56:26,303 DEBUG > [org.apereo.cas.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization > header found with [2180] bytes> > > Can anyone suggest what might be the issue? Or if a cas server configured > spnego supports cluster deployment? > > Thanks And Regards, > Roman Brown > -- - Website: https://apereo.github.io/cas - Gitter Chatroom: https://gitter.im/apereo/cas - List Guidelines: https://goo.gl/1VRrw7 - Contributions: https://goo.gl/mh7qDG --- You received this message because you are subscribed to the Google Groups "CAS Community" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/0aaf0a3d-81e4-440e-90dd-ed6e54281868n%40apereo.org.
