CAS, Spnego and the "pre Windows 2000 logon name"

Tue Jun 3 04:15:39 EDT 2008

>>>> What's your setting of principalWithDomainName (property of
>>>> JCIFSSpnegoAuthenticationHandler)?
>>>  
>> It's "true". That's why "MC\" appears in the user name.
>>> What's your setting of NTLMallowed (property of
>>> JCIFSSpnegoAuthenticationHandler)?
>>>  
>> It's "true". If I set to "false", the authentication doesn't work.
>
>Then you don't authenticate with Kerberos. NTLM is used. That leads to
>the name form NETBIOSDOMAIN/sAMAccountName.

How can I authenticate with Kerberos ? It seems that my client only send NTLM tokens. 

>>> If you want to allow SPNEGO with NTLM you could try to map the principal
>>> name to userPrincipalName like described here:
>>> http://www.ja-sig.org/wiki/display/CASUM/Attributes
>>>  
>> Thanks for the idea. I'm trying.
>
>Maybe set principalWithDomainName to false and search via LDAP for
>(sAMAccountName=%u).
> [...]
>You have to add the CredentialsToLDAPAttributePrincipalResolver.
> [...]
>Why do you want to change the login flow?

I followed your advice (I modified /WEB-INF/deployerConfigContext.xml) but it seems that the CredentialsToLDAPAttributePrincipalResolver isn't used. 

Here my logs : 
07:45:01,899 INFO  [[/tunnel-web]:646] Loading Spring root WebApplicationContext
07:45:04,858 INFO  [[/tunnel-web]:646] Loading WebApplicationContext for Spring FrameworkServlet 'SpringServlet'
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <jcifsServicePrincipal is set to HTTP/pronostix at VILLE-CHATEAUROUX.FR>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <jcifsServicePassword is set to *****>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <jcifsDomain is set to VILLE-CHATEAUROUX.FR>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <jcifsDomainController is set to CETYUNIX.VILLE-CHATEAUROUX.FR>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <kerberosDebug is set to : true>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <kerberosRealm is set to :VILLE-CHATEAUROUX.FR>
2008-06-03 07:45:06,975 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <kerberosKdc is set to : 172.16.11.1>
2008-06-03 07:45:06,976 WARN [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <found login config in system property, may overide : /usr/local/liferay/conf/jaas.config>
2008-06-03 07:45:06,976 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSConfig] - <configured login configuration path : /usr/local/liferay/webapps/cas/WEB-INF/login.conf>
2008-06-03 07:45:07,322 INFO [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <FormObjectClass not set.  Using default class of org.jasig.cas.authentication.principal.UsernamePasswordCredentials with formObjectName credentials and validator org.jasig.cas.validation.UsernamePasswordCredentialsValidator.>
3 juin 2008 07:45:07 org.apache.coyote.http11.Http11BaseProtocol start
INFO: DÃ©marrage de Coyote HTTP/1.1 sur http-8080
3 juin 2008 07:45:07 org.apache.coyote.http11.Http11BaseProtocol start
INFO: DÃ©marrage de Coyote HTTP/1.1 sur http-8443
3 juin 2008 07:45:07 org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
3 juin 2008 07:45:07 org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/22  config=null
3 juin 2008 07:45:07 org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
3 juin 2008 07:45:07 org.apache.catalina.startup.Catalina start
INFO: Server startup in 25228 ms
Loading jar:file:/usr/local/liferay/webapps/ROOT/WEB-INF/lib/portal-ejb.jar!/cache-single-vm.properties
2008-06-03 07:45:26,828 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - <Starting cleaning of expired tickets from ticket registry at [Tue Jun 03 07:45:26 GMT 2008]>
2008-06-03 07:45:26,829 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - <0 found to be removed.  Removing now.>
2008-06-03 07:45:26,829 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - <Finished cleaning of expired tickets from ticket registry at [Tue Jun 03 07:45:26 GMT 2008]>
2008-06-03 07:45:35,325 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' beginning execution>
2008-06-03 07:45:35,326 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Setting path for cookies to: /cas>
2008-06-03 07:45:35,330 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Placing service in FlowScope: http://pronostix:8080/c/portal/login>
2008-06-03 07:45:35,330 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' completed execution; result is 'success'>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' beginning execution>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Authorization header not found. Sending WWW-Authenticate header>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' completed execution; result is 'success'>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' beginning execution>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' completed execution; result is 'error'>
2008-06-03 07:45:35,351 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' beginning execution>
2008-06-03 07:45:35,353 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Executing setupForm>
2008-06-03 07:45:35,353 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new form object with name 'credentials'>
2008-06-03 07:45:35,353 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new instance of form object class [class org.jasig.cas.authentication.principal.UsernamePasswordCredentials]>
2008-06-03 07:45:35,354 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Putting form object of type [class org.jasig.cas.authentication.principal.UsernamePasswordCredentials] in scope Flow with name 'credentials'>
2008-06-03 07:45:35,354 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new form errors for object with name 'credentials'>
2008-06-03 07:45:35,359 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <No property editor registrar set, no custom editors to register>
2008-06-03 07:45:35,361 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Putting form errors instance in scope Flash>
2008-06-03 07:45:35,361 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' completed execution; result is 'success'>
2008-06-03 07:45:35,361 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' beginning execution>
2008-06-03 07:45:35,361 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' completed execution; result is 'success'>
2008-06-03 07:45:35,720 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' beginning execution>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Placing service in FlowScope: http://pronostix:8080/c/portal/login>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' completed execution; result is 'success'>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' beginning execution>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' completed execution; result is 'success'>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' beginning execution>
2008-06-03 07:45:35,721 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization header found with 56 bytes>
2008-06-03 07:45:35,722 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Obtained token: NTLMSSPï¿ï¿½(
>
2008-06-03 07:45:35,789 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler] - <Setting nextToken in credentials>
2008-06-03 07:45:35,789 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler] - <Principal is null, the processing of the SPNEGO Token failed>
2008-06-03 07:45:35,789 INFO [org.jasig.cas.authentication.AuthenticationManagerImpl] - <AuthenticationHandler: org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler failed to authenticate the user which provided the following credentials: Principal is null>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Obtained output token: NTLMSSP((0ï¿½ï¿½ï¿½pï¿½Aï¿½ï¿½JJXVILLE-CHATEAUROUX.FR(VILLE-CHATEAUROUX.FRJCIFS0_1_40>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Setting HTTP Status to 401>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' completed execution; result is 'error'>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' beginning execution>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Executing setupForm>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new form object with name 'credentials'>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new instance of form object class [class org.jasig.cas.authentication.principal.UsernamePasswordCredentials]>
2008-06-03 07:45:35,790 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Putting form object of type [class org.jasig.cas.authentication.principal.UsernamePasswordCredentials] in scope Flow with name 'credentials'>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Creating new form errors for object with name 'credentials'>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <No property editor registrar set, no custom editors to register>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Putting form errors instance in scope Flash>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' completed execution; result is 'success'>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' beginning execution>
2008-06-03 07:45:35,791 DEBUG [org.jasig.cas.web.flow.AuthenticationViaFormAction] - <Action 'AuthenticationViaFormAction' completed execution; result is 'success'>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' beginning execution>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Placing service in FlowScope: http://pronostix:8080/c/portal/login>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Action 'InitialFlowSetupAction' completed execution; result is 'success'>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' beginning execution>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] - <Action 'SpnegoNegociateCredentialsAction' completed execution; result is 'success'>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' beginning execution>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <SPNEGO Authorization header found with 212 bytes>
2008-06-03 07:45:35,809 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Obtained token: NTLMSSPnï¿½HL\ï¿½ï¿½(
MCCA_AUSSOHDV-04767ï¿½Wï¿½ï¿½ï¿½ï¿½LF*D/_ï¿½)ï¿½6ï¿½Dï¿½@ï¿½2Bqï¿½tï¿½^ï¿½ÉRÒ¹:Þï¿½<ï¿½m40Qï¿½Cï¿½>
2008-06-03 07:45:35,835 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler] - <nextToken is null>
2008-06-03 07:45:35,835 DEBUG [org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler] - <NTLM Credentials is valid for user [MC\CA_AUSSO]>
2008-06-03 07:45:35,835 INFO [org.jasig.cas.authentication.AuthenticationManagerImpl] - <AuthenticationHandler: org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler successfully authenticated the user which provided the following credentials: CA_AUSSO>
2008-06-03 07:45:35,835 DEBUG [org.jasig.cas.support.spnego.authentication.principal.SpnegoCredentialsToPrincipalResolver] - <Attempting to resolve a principal...>
2008-06-03 07:45:35,836 DEBUG [org.jasig.cas.support.spnego.authentication.principal.SpnegoCredentialsToPrincipalResolver] - <Creating SimplePrincipal for [CA_AUSSO]>
2008-06-03 07:45:35,839 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Unable to obtain the output token required.>
2008-06-03 07:45:35,839 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - <Action 'SpnegoCredentialsAction' completed execution; result is 'success'>
2008-06-03 07:45:35,839 DEBUG [org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - <Action 'SendTicketGrantingTicketAction' beginning execution>
2008-06-03 07:45:35,840 DEBUG [org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - <Action 'SendTicketGrantingTicketAction' completed execution; result is 'success'>
2008-06-03 07:45:35,840 DEBUG [org.jasig.cas.web.flow.GenerateServiceTicketAction] - <Action 'GenerateServiceTicketAction' beginning execution>
2008-06-03 07:45:35,841 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] - <Granted service ticket [ST-1-fKz2peN4SCbGdNRdTG4m-cas] for service [http://pronostix:8080/c/portal/login] for user [CA_AUSSO]>
2008-06-03 07:45:35,841 DEBUG [org.jasig.cas.web.flow.GenerateServiceTicketAction] - <Action 'GenerateServiceTicketAction' completed execution; result is 'success'>

Thanks for your help,

Céline