Re:[cas-user] Authentication Kerberos correct But RemoteUser is always Null

jean linlin Thu, 01 Jul 2010 07:43:47 -0700

Yes it well went through CAS Authentication .
There's a service Ticket generated by CAS .
We can see in the following log the call of AuthenticationFilter and
Cas20ProxyReceivingTicketValidationFilter but nothing about
HttpServletRequestWrapperFilter ?


Here is my log File ( the beginning of the log is the user recovery through
Kerberos ) 
    my username is 'Administrateur' :

2010-07-01 16:10:41,202 DEBUG
[org.jasig.cas.client.authentication.AuthenticationFilter] - no ticket and
no assertion found
2010-07-01 16:10:41,203 DEBUG
[org.jasig.cas.client.authentication.AuthenticationFilter] - Constructed
service url: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,203 DEBUG
[org.jasig.cas.client.authentication.AuthenticationFilter] - redirecting to
"https://xxxx:8443/cas_tom/login?service=https%3A%2F%2Fdebianportail.adportail.net%3A8443%2FPrjTestSihTom";
2010-07-01 16:10:41,354 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
'InitialFlowSetupAction' beginning execution
2010-07-01 16:10:41,354 DEBUG
[org.jasig.cas.web.support.CasArgumentExtractor] - Extractor generated
service for: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,354 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Placing service in
FlowScope: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,355 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
'InitialFlowSetupAction' completed execution; result is 'success'
2010-07-01 16:10:41,355 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] -
Action 'SpnegoNegociateCredentialsAction' beginning execution
2010-07-01 16:10:41,355 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] -
Authorization header not found. Sending WWW-Authenticate header
2010-07-01 16:10:41,356 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] -
Action 'SpnegoNegociateCredentialsAction' completed execution; result is
'success'
2010-07-01 16:10:41,356 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Action
'SpnegoCredentialsAction' beginning execution
2010-07-01 16:10:41,356 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Action
'SpnegoCredentialsAction' completed execution; result is 'error'
2010-07-01 16:10:41,356 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
'AuthenticationViaFormAction' beginning execution
2010-07-01 16:10:41,357 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Executing setupForm
2010-07-01 16:10:41,357 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new form
object with name 'credentials'
2010-07-01 16:10:41,357 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new instance
of form object class [class
org.jasig.cas.authentication.principal.UsernamePasswordCredentials]
2010-07-01 16:10:41,357 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'
2010-07-01 16:10:41,358 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new form
errors for object with name 'credentials'
2010-07-01 16:10:41,358 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - No property editor
registrar set, no custom editors to register
2010-07-01 16:10:41,358 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Putting form errors
instance in scope Flash
2010-07-01 16:10:41,358 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
'AuthenticationViaFormAction' completed execution; result is 'success'
2010-07-01 16:10:41,359 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
'AuthenticationViaFormAction' beginning execution
2010-07-01 16:10:41,359 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
'AuthenticationViaFormAction' completed execution; result is 'success'
2010-07-01 16:10:41,387 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
'InitialFlowSetupAction' beginning execution
2010-07-01 16:10:41,387 DEBUG
[org.jasig.cas.web.support.CasArgumentExtractor] - Extractor generated
service for: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,387 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Placing service in
FlowScope: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,387 DEBUG
[org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
'InitialFlowSetupAction' completed execution; result is 'success'
2010-07-01 16:10:41,388 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] -
Action 'SpnegoNegociateCredentialsAction' beginning execution
2010-07-01 16:10:41,388 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoNegociateCredentialsAction] -
Action 'SpnegoNegociateCredentialsAction' completed execution; result is
'success'
2010-07-01 16:10:41,388 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Action
'SpnegoCredentialsAction' beginning execution
2010-07-01 16:10:41,388 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - SPNEGO
Authorization header found with 1748 bytes
2010-07-01 16:10:41,394 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Obtained
token: `ï¿½+ï¿½ï¿½
0ï¿½   ï¿½$0" *ï¿½Hï¿½ï¿½        *ï¿½Hï¿½ï¿½
+ï¿½7
ï¿½ï¿½ï¿½ï¿½ï¿½`ï¿½ï¿½     *ï¿½Hï¿½ï¿½
nï¿½ï¿½0ï¿½Â ï¿½ï¿½     ï¿½ï¿½ï¿½aï¿½ï¿½0ï¿½Ü ï¿½
ADPORTAIL.NETï¿½.0,ï¿½ï¿½%0#HTTPdebianportail.adportail.netï¿½ï¿½ï¿½0ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½|ï¿½ï¿½TSï¿½ï¿½TÈ‰ï¿½ï¿½bWï¿½ï¿½s>ï¿½ï¿½2jï¿½yï¿½ï¿½Zrï¿½z"ï¿½ï¿½Yjï¿½W#ï¿½ï¿½
ï¿½Z
ï¿½ï¿½ï¿½ï¿½)veï¿½ï¿½>ï¿½ï¿½4cHï¿½ï¿½I8ï¿½ï¿½ï¿½
ï¿½yï¿½aï¿½ï¿½+ï¿½ï¿½$ï¿½ï¿�...@jpï¿½ï¿½{ï¿½)å“žqï¿½3Ä·ï¿½
ï¿½LO_ï¿½~~ï¿½[=Ý›ï¿½ï¿½ï¿½`eï¿½
ï¿½JFVnOï¿½]ï¿½ï¿½pï¿½ï¿½ï¿½ï¿½ï¿½6p.eï¿½ï¿½f8ï¿½ï¿½u}ï¿½Gï¿½ï¿½ï¿½+^qï¿½Hï¿½Ë´ï¿½cqTï¿½ï¿½ï¿½qï¿½ï¿½ï¿½ï¿½nï¿½.
ï¿½ï¿½%5Rï¿½ï¿½rQï¿½ Mï¿½ï¿½kï¿½_ï¿½0ï¿½ï¿½ï¿½
ï¿½ï¿½ï¿½\ï¿½ï¿½(ï¿½xN^ï¿½Uï¿½mï¿½ï¿½&?Rï¿½Å‚ï¿½Vzï¿½JPï¿½
7vï¿½%ï¿½Ì«ï¿½gØ‘ï¿½ï¿½ï¿½ ï¿½S2Dud
ï¿½ï¿½kï¿½ï¿½ï¿½fï¿½ï¿½ï¿½?ï¿½ï¿½}ï¿½?ï¿½ï¿½ï¿½gï¿½ï¿½ï¿½ï¿½)ï¿½ï¿½5\ï¿½-ï¿½}4ï¿½ï¿½ï¿½
    
2Ä³ï¿½ï¿½<ï¿½ï¿½V`ï¿½ï¿½ï¿½ï¿½ï¿½P;ï¿½ï¿½ï¿½ï¿½ï¿½-Mï¿½ï¿½
wï¿½:>ï¿½ï¿½nï¿½ï¿½ï¿½Rï¿½Ì¿_ï¿½:ï¿½+ ï¿½ï¿½N
ï¿...@ï¿½ï¿½[ï¿½nï¿½ï¿½ï¿½2ï¿½ï¿½ï¿½"ï¿½ï¿½iï¿½ï¿½Qnï¿½ï¿½YChï¿½+?ï¿½mloï¿½1)ï¿½tkï¿½ï¿½n8ï¿½b6Fï¿½
ï¿½ï¿½ï¿½Ë˜ï¿½ï¿½ï¿½'ï¿½ï¿½
Lï¿½9ï¿½ï¿½ï¿½ï¿½[ï¿½ï¿½ï¿½ï¿½Â’Dï¿½ï¿½ï¿½m4vÈžï¿½<eÃˆ>amï¿½Nk<&
.<Uï¿½ï¿½ï¿½ï¿½ï¿½)?,ï¿½ï¿½ï¿½)ï¿½ï¿½cz&ï¿½3ï¿½ï¿½ï¿½ï¿½ï¿½rTï¿½F!ï¿½
ï¿½Xï¿½+!ï¿½Rï¿½wï¿½G>ï¿½ï¿½<ï¿½ï¿½Ê¶

Khb99ï¿½_ï¿½ï¿½ï¿½ï¿½'ï¿½0ï¿½="ï¿½ï¿½g#nV*bfï¿½ï¿½*aï¿½ï¿½8fï¿½ï¿½ï¿½iGï¿½ï¿½6ï¿½XgIï¿½Iï¿½ï¿½ï¿½BYPï¿½~ï¿½ï¿½'ï¿½ï¿½Jï¿½Tï¿½Bï¿½c"ï¿½
4ï¿½gF?ï¿½ï¿½ï¿½cï¿½ï¿½ï¿½\ÏºAï¿½3Ä§ï¿½ï¿½ï¿½BiF5ï¿½ï¿½ï¿½A}ï¿½ï¿½-ï¿½ï¿½(ï¿½xï¿½
$3ï¿½ï¿½ì†„ï¿½Rï¿½AÜƒUBï¿½ï¿½Kï¿½ï¿½
0ï¿½ï¿½2ï¿½Û»ï¿½ï¿½Ó–h'uvï¿½sXç¡©ï¿½tMï¿½ï¿½1ï¿½ï¿½ï¿½ï¿½ï¿½3ï¿½+.L5
ï¿½ï¿½ï¿½å™›ï¿½'ï¿½]+hï¿½ï¿½ï¿½q_ï¿½ï¿½ï¿½ï¿½XEï¿½ï¿½YÎhï¿½5&vXwï¿½ï¿½
ï¿½ï¿½
ï¿½ï¿½ ï¿½Fï¿½ï¿½
ï¿½"rï¿½!Ì©ï¿½ï¿½XÝ˜Aï¿½ï¿½;ï¿½pÒƒKC]ï¿½ï¿½ï¿½ï¿½k=Gï¿½xPï¿½ï¿½ï¿½ï¿½ï¿½ï¿½9ï¿½ï¿½jlv]
,ï¿½ï¿½E,lï¿½Fï¿½ï¿½Llï¿½Xï¿½4ï¿½ï¿½k)ï¿½ï¿½ï¿½ï¿½0ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½ï¿½Wï¿½ï¿½ï¿½fVï¿½ï¿½ï¿½Ùˆï¿½jï¿½Cï¿½ï¿½ï¿½Zï¿½Eï¿½-ï¿½ï¿½ï¿½Yï¿½])ï¿½ï¿½ï¿½bï¿½ï¿½MDï¿½7uvÝ¶ï¿½2P6ï¿½ï¿½
mR=ï¿½s\ï¿½nï¿½
ï¿½ï¿½sï¿½'ï¿½Cï¿½m\ï¿½Oï¿½ï¿½eÃ‹ï¿½ï¿½]ï¿½ï¿½ï¿½ï¿½ç©ï¿½[;ï¿½ï¿½ï¿½Þï¿½ï¿½}Ã€Cï¿½ï¿½ï¿½ï¿½ï¿½iï¿½1ï¿½ï¿½]!h,
ï¿½Eï¿½mï¿½ï¿½ï¿½#ï¿½ï¿½ï¿½6`ï¿½:3ï¿½xï¿½ï¿½ï¿½YOï¿½ï¿½ï¿½;ï¿½
lpè²¬d=dï¿½ï¿½ï¿½ï¿½Yï¿½Iï¿½
2010-07-01 16:10:41,395 DEBUG
[org.jasig.cas.CentralAuthenticationServiceImpl] - Attempting to create
TicketGrantingTicket for Principal is null
2010-07-01 16:10:41,434 DEBUG
[org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler]
- Setting nextToken in credentials
2010-07-01 16:10:41,434 DEBUG
[org.jasig.cas.support.spnego.authentication.handler.support.JCIFSSpnegoAuthenticationHandler]
- Kerberos Credentials is valid for user [[email protected]]
2010-07-01 16:10:41,434 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: Administrateur
2010-07-01 16:10:41,434 DEBUG
[org.jasig.cas.support.spnego.authentication.principal.SpnegoCredentialsToPrincipalResolver]
- Attempting to resolve a principal...
2010-07-01 16:10:41,435 DEBUG
[org.jasig.cas.support.spnego.authentication.principal.SpnegoCredentialsToPrincipalResolver]
- Creating SimplePrincipal for [Administrateur]
2010-07-01 16:10:41,436 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Added ticket
[TGT-5-jWarrLq2HUDLsurKthTdzfVgbTzigFlCHC3xFcWmRbjK5SfcJD-cas_tom] to
registry.
2010-07-01 16:10:41,436 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Obtained
output token: ï¿½0}ï¿½
 ï¿½ *ï¿½Hï¿½ï¿½ï¿½ig`e        *ï¿½Hï¿½ï¿½
oV0Tï¿½ï¿½ï¿½H0Fï¿½ï¿½?=ï¿½wï¿½[ï¿½>ï¿½ï¿½NÔ˜tï¿½ï¿½ï¿½
ï¿½ï¿½ï¿½cï¿½jyï¿½*!?ï¿½g?ï¿½I=ï¿½ï¿½{ï¿½HlIï¿½Pï¿½%=Aï¿½ï¿½JQ|N
2010-07-01 16:10:41,436 DEBUG
[org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Action
'SpnegoCredentialsAction' completed execution; result is 'success'
2010-07-01 16:10:41,436 DEBUG
[org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - Action
'SendTicketGrantingTicketAction' beginning execution
2010-07-01 16:10:41,436 DEBUG
[org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - Added cookie
with name [CASTGC] and value
[TGT-5-jWarrLq2HUDLsurKthTdzfVgbTzigFlCHC3xFcWmRbjK5SfcJD-cas_tom]
2010-07-01 16:10:41,437 DEBUG
[org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - Action
'SendTicketGrantingTicketAction' completed execution; result is 'success'
2010-07-01 16:10:41,437 DEBUG
[org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
'GenerateServiceTicketAction' beginning execution
2010-07-01 16:10:41,437 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
retrieve ticket
[TGT-5-jWarrLq2HUDLsurKthTdzfVgbTzigFlCHC3xFcWmRbjK5SfcJD-cas_tom]
2010-07-01 16:10:41,437 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket
[TGT-5-jWarrLq2HUDLsurKthTdzfVgbTzigFlCHC3xFcWmRbjK5SfcJD-cas_tom] found in
registry.
2010-07-01 16:10:41,438 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Added ticket
[ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom] to registry.
2010-07-01 16:10:41,438 INFO
[org.jasig.cas.CentralAuthenticationServiceImpl] - Granted service ticket
[ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom] for service
[https://xxxx:8443/PrjTestSihTom] for user [Administrateur]
2010-07-01 16:10:41,438 DEBUG
[org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
'GenerateServiceTicketAction' completed execution; result is 'success'
2010-07-01 16:10:41,444 DEBUG
[org.jasig.cas.client.validation.Cas20ProxyReceivingTicketValidationFilter]
- Attempting to validate ticket: ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom
2010-07-01 16:10:41,445 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Placing URL
parameters in map.
2010-07-01 16:10:41,445 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Calling
template URL attribute map.
2010-07-01 16:10:41,446 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Loading
custom parameters from configuration.
2010-07-01 16:10:41,446 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Constructing
validation url:
https://xxxx:8443/cas_tom/serviceValidate?ticket=ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom&service=https%3A%2F%2Fdebianportail.adportail.net%3A8443%2FPrjTestSihTom
2010-07-01 16:10:41,446 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Retrieving
response from server.
2010-07-01 16:10:41,467 DEBUG
[org.jasig.cas.web.support.CasArgumentExtractor] - Extractor generated
service for: https://xxxx:8443/PrjTestSihTom
2010-07-01 16:10:41,469 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
retrieve ticket [ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom]
2010-07-01 16:10:41,469 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket
[ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom] found in registry.
2010-07-01 16:10:41,469 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket
[ST-6-PgQKyxGA7R4iXemQr9M6-cas_tom] from registry
2010-07-01 16:10:41,479 DEBUG
[org.jasig.cas.client.validation.Cas20ServiceTicketValidator] - Server
response: <cas:serviceResponse xmlns:cas='http://www.yale.edu/tp/cas'>
        <cas:authenticationSuccess>
                <cas:user>Administrateur</cas:user>


        </cas:authenticationSuccess>
</cas:serviceResponse>

2010-07-01 16:10:41,484 INFO
[org.jasig.cas.client.proxy.ProxyGrantingTicketStorageImpl] - No Proxy
Ticket found for 
2010-07-01 16:10:41,484 DEBUG
[org.jasig.cas.client.validation.Cas20ProxyReceivingTicketValidationFilter]
- Successfully authenticated user: Administrateur
2010-07-01 16:10:41,485 DEBUG
[org.jasig.cas.client.validation.Cas20ProxyReceivingTicketValidationFilter]
- Redirecting after successful ticket validation.



thanks in advance! 
-- 
View this message in context: 
http://jasig.275507.n4.nabble.com/Authentication-Kerberos-correct-But-RemoteUser-is-always-Null-tp2272739p2275264.html
Sent from the CAS Users mailing list archive at Nabble.com.

-- 
You are currently subscribed to [email protected] as: 
[email protected]
To unsubscribe, change settings or access archives, see 
http://www.ja-sig.org/wiki/display/JSG/cas-user

Re:[cas-user] Authentication Kerberos correct But RemoteUser is always Null

Reply via email to