8 Replies Latest reply on Jul 1, 2009 8:49 AM by dufferdo25

JBOSS Negotiate toolkit Secured servlet throws 403 Access de

dufferdo25 May 27, 2009 12:06 PM

Hello all,
I am running jboss-portal 2.7.1 on debian 4.

I am trying to implement silent sign-on using JBOSS Negotiate using the user guide.
2.0.3.GA

I have an Active Directory 2003 dc.

I can successfully run the basic negotiation servlet(the response is similar to what guide shows as a successful response).
I can successfully run the Security Domain Test servlet(the response is similar to what guide shows as a successful response).

When I run the Secured servlet the page returns a 403 error: Access to the requested resource has been denied.(standard ie 403 error)

I have enabled all means of logging as shown in the guide.

If I watch stdout it appears that the Secured servlet is successful as there are no errors and I get the following line (which seems to point at success):
10:52:37,268 INFO [STDOUT] >>> Config reset default kdc MYDOMAIN.COM
10:52:37,268 INFO [STDOUT] replay cache for test01@MYDOMAIN.COM is null.
10:52:37,269 INFO [STDOUT] object 0: 1243439496000/419
10:52:37,269 INFO [STDOUT] object 0: 1243439496000/419
10:52:37,270 INFO [STDOUT] >>> KrbApReq: authenticate succeed.
10:52:37,271 INFO [STDOUT] Krb5Context setting peerSeqNumber to: 71953492
10:52:37,273 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
10:52:37,274 INFO [STDOUT] Krb5Context setting mySeqNumber to: 1055164829
10:52:37,275 INFO [STDOUT] [Krb5LoginModule]: Entering logout
10:52:37,275 INFO [STDOUT] [Krb5LoginModule]: logged out Subject

test01 is a valid AD user.

Any ideas as to why the 403 as opposed to the expected output?

Thanks in advance!

1. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jun 11, 2009 3:07 PM (in response to dufferdo25)

Any Ideas?
Is there another module I can use for silent sign on?
Cheers!
Actions
2. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

jlmagc Jun 16, 2009 4:58 PM (in response to dufferdo25)

Have you tried to use the logs? I think you will get more useful information. You just need to put the following in the log4j.xml file

Please try and let us know if it shows any error.
Actions
3. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jun 17, 2009 2:03 PM (in response to dufferdo25)

Thanks for the response not sure what happened but it doesnt show what you suggested I add to the log4j file. BTW do you mean the jboss-log4j.xml file?
Thanks.
Actions

4. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jun 18, 2009 10:36 AM (in response to dufferdo25)

Here is a dump of console whilst I access Secured servlet

14:16:19,722 INFO [STDOUT] Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt true ticketCache is null isInitiator true KeyTab is /home/admin/jportal.host.keytab refreshKrb5Config is false principal is host/jportal@BASE.MYCO.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
14:16:19,739 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,740 INFO [STDOUT] >>> KeyTabInputStream, readName(): host
14:16:19,740 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,741 INFO [STDOUT] >>> KeyTab: load() entry length: 69; type: 23
14:16:19,741 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,742 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,742 INFO [STDOUT] >>> KeyTab: load() entry length: 55; type: 3
14:16:19,743 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,743 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,743 INFO [STDOUT] >>> KeyTab: load() entry length: 55; type: 1
14:16:19,744 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,744 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,745 INFO [STDOUT] >>> KeyTab: load() entry length: 63; type: 23
14:16:19,746 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,746 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,746 INFO [STDOUT] >>> KeyTab: load() entry length: 71; type: 16
14:16:19,747 INFO [STDOUT] >>> KeyTabInputStream, readName(): BASE.MYCO.COM
14:16:19,747 INFO [STDOUT] >>> KeyTabInputStream, readName(): jportal
14:16:19,747 INFO [STDOUT] >>> KeyTab: load() entry length: 63; type: 17
14:16:19,883 INFO [STDOUT] Added key: 23version: 3
14:16:19,884 INFO [STDOUT] Ordering keys wrt default_tkt_enctypes list
14:16:19,885 INFO [STDOUT] Using builtin default etypes for default_tkt_enctypes
14:16:19,885 INFO [STDOUT] default etypes for default_tkt_enctypes:
14:16:19,886 INFO [STDOUT] 3
14:16:19,886 INFO [STDOUT] 1
14:16:19,887 INFO [STDOUT] 23
14:16:19,887 INFO [STDOUT] 16
14:16:19,888 INFO [STDOUT] 17
14:16:19,888 INFO [STDOUT] .
14:16:19,889 INFO [STDOUT] principal's key obtained from the keytab
14:16:19,889 INFO [STDOUT] Acquire TGT using AS Exchange
14:16:19,891 INFO [STDOUT] Using builtin default etypes for default_tkt_enctypes
14:16:19,892 INFO [STDOUT] default etypes for default_tkt_enctypes:
14:16:19,892 INFO [STDOUT] 3
14:16:19,893 INFO [STDOUT] 1
14:16:19,893 INFO [STDOUT] 23
14:16:19,893 INFO [STDOUT] 16
14:16:19,894 INFO [STDOUT] 17
14:16:19,894 INFO [STDOUT] .
14:16:19,895 INFO [STDOUT] >>> KrbAsReq calling createMessage
14:16:19,896 INFO [STDOUT] >>> KrbAsReq in createMessage
14:16:19,898 INFO [STDOUT] >>> KrbKdcReq send: kdc=dc.base.myco.com UDP:88, timeout=30000, number of retries =3, #bytes=162
14:16:19,902 INFO [STDOUT] >>> KDCCommunication: kdc=dc.base.myco.com UDP:88, timeout=30000,Attempt =1, #bytes=162
14:16:19,904 INFO [STDOUT] >>> KrbKdcReq send: #bytes read=645
14:16:19,905 INFO [STDOUT] >>> KrbKdcReq send: #bytes read=645
14:16:19,907 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
14:16:20,057 INFO [STDOUT] >>> KrbAsRep cons in KrbAsReq.getReply host/jportal
14:16:20,058 INFO [STDOUT] principal is host/jportal@BASE.MYCO.COM
14:16:20,058 INFO [STDOUT] EncryptionKey: keyType=23 keyBytes (hex dump)=0000: 25 6D AD 1A 24 E1 4D C2 77 B3 7C 54 67 45 EA AA %m..$.M.E..TgE..
14:16:20,061 INFO [STDOUT] Added server's keyKerberos Principal host/jportal@BASE.MYCO.COMKey Version 3key EncryptionKey: keyType=23 keyBytes (hex dump)=
0000: 25 6D AD 1A 24 E1 4D C2 77 B3 7C 54 67 45 EA AA %m..$.M.E..TgE..
14:16:20,061 INFO [STDOUT] [Krb5LoginModule] added Krb5Principal host/jportal@BASE.MYCO.COM to Subject
14:16:20,061 INFO [STDOUT] Commit Succeeded
14:16:20,072 INFO [STDOUT] [Krb5LoginModule]: Entering logout
14:16:20,072 INFO [STDOUT] [Krb5LoginModule]: logged out Subject
14:16:20,129 INFO [STDOUT] Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt true ticketCache is null isInitiator true KeyTab is /home/admin/jportal.host.keytab refreshKrb5Config is false principal is host/jportal@BASE.MYCO.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
14:16:20,130 INFO [STDOUT] KeyTab instance already exists
14:16:20,130 INFO [STDOUT] Added key: 23version: 3
14:16:20,131 INFO [STDOUT] Ordering keys wrt default_tkt_enctypes list
14:16:20,131 INFO [STDOUT] Using builtin default etypes for default_tkt_enctypes
14:16:20,132 INFO [STDOUT] default etypes for default_tkt_enctypes:
14:16:20,132 INFO [STDOUT] 3
14:16:20,133 INFO [STDOUT] 1
14:16:20,133 INFO [STDOUT] 23
14:16:20,134 INFO [STDOUT] 16
14:16:20,134 INFO [STDOUT] 17
14:16:20,135 INFO [STDOUT] .
14:16:20,135 INFO [STDOUT] principal's key obtained from the keytab
14:16:20,136 INFO [STDOUT] Acquire TGT using AS Exchange
14:16:20,136 INFO [STDOUT] Using builtin default etypes for default_tkt_enctypes
14:16:20,137 INFO [STDOUT] default etypes for default_tkt_enctypes:
14:16:20,137 INFO [STDOUT] 3
14:16:20,138 INFO [STDOUT] 1
14:16:20,139 INFO [STDOUT] 23
14:16:20,139 INFO [STDOUT] 16
14:16:20,140 INFO [STDOUT] 17
14:16:20,140 INFO [STDOUT] .
14:16:20,141 INFO [STDOUT] >>> KrbAsReq calling createMessage
14:16:20,141 INFO [STDOUT] >>> KrbAsReq in createMessage
14:16:20,142 INFO [STDOUT] >>> KrbKdcReq send: kdc=dc.base.myco.com UDP:88, timeout=30000, number of retries =3, #bytes=162
14:16:20,143 INFO [STDOUT] >>> KDCCommunication: kdc=dc.base.myco.com UDP:88, timeout=30000,Attempt =1, #bytes=162
14:16:20,145 INFO [STDOUT] >>> KrbKdcReq send: #bytes read=645
14:16:20,145 INFO [STDOUT] >>> KrbKdcReq send: #bytes read=645
14:16:20,146 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
14:16:20,148 INFO [STDOUT] >>> KrbAsRep cons in KrbAsReq.getReply host/jportal
14:16:20,148 INFO [STDOUT] principal is host/jportal@BASE.MYCO.COM
14:16:20,149 INFO [STDOUT] EncryptionKey: keyType=23 keyBytes (hex dump)=0000: 25 6D AD 1A 24 E1 4D C2 77 B3 7C 54 67 45 EA AA %m..$.M.E..TgE..
14:16:20,151 INFO [STDOUT] Added server's keyKerberos Principal host/jportal@BASE.MYCO.COMKey Version 3key EncryptionKey: keyType=23 keyBytes (hex dump)=
0000: 25 6D AD 1A 24 E1 4D C2 77 B3 7C 54 67 45 EA AA %m..$.M.E..TgE..
14:16:20,151 INFO [STDOUT] [Krb5LoginModule] added Krb5Principal host/jportal@BASE.MYCO.COM to Subject
14:16:20,152 INFO [STDOUT] Commit Succeeded
14:16:20,165 INFO [STDOUT] Found key for host/jportal@BASE.MYCO.COM(23)
14:16:20,167 INFO [STDOUT] Entered Krb5Context.acceptSecContext with state=STATE_NEW
14:16:20,169 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
14:16:20,172 INFO [STDOUT] Using builtin default etypes for permitted_enctypes
14:16:20,173 INFO [STDOUT] default etypes for permitted_enctypes:
14:16:20,173 INFO [STDOUT] 3
14:16:20,174 INFO [STDOUT] 1
14:16:20,174 INFO [STDOUT] 23
14:16:20,175 INFO [STDOUT] 16
14:16:20,175 INFO [STDOUT] 17
14:16:20,176 INFO [STDOUT] .
14:16:20,176 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
14:16:20,178 INFO [STDOUT] >>> Config reset default kdc BASE.MYCO.COM
14:16:20,179 INFO [STDOUT] replay cache for dufus@BASE.MYCO.COM is null.
14:16:20,180 INFO [STDOUT] object 0: 1245334529003/3463
14:16:20,180 INFO [STDOUT] object 0: 1245334529003/3463
14:16:20,181 INFO [STDOUT] >>> KrbApReq: authenticate succeed.
14:16:20,182 INFO [STDOUT] Krb5Context setting peerSeqNumber to: 752264326
14:16:20,184 INFO [STDOUT] >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
14:16:20,186 INFO [STDOUT] Krb5Context setting mySeqNumber to: 467205704
14:16:20,187 INFO [STDOUT] [Krb5LoginModule]: Entering logout
14:16:20,187 INFO [STDOUT] [Krb5LoginModule]: logged out Subject

As you can see there arent any errors. As I said earlier, I get success on the first 2 servlets but I get the generic" HTTP Status 403 - Access to the requested resource has been denied"
dufus is the user name and he belongs to the User group in AD.
jportal is the service account that I user for the principal.
jportal is also the name of the host that jboss is running on.
dc is the name of my AD DC.
Thanks again!

5. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jun 18, 2009 1:32 PM (in response to dufferdo25)

OK TRACE reveals an error :
javax.security.auth.login.LoginException: Continuation Required.

Here is the server.log output of the pertinent error and surrounding TRACE stmts.

2009-06-18 16:58:32,512 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Logged in 'host' LoginConte
xt
2009-06-18 16:58:32,518 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Result - false
2009-06-18 16:58:32,518 INFO [STDOUT] (http-0.0.0.0-8080-1) [Krb5LoginModule]: Entering logout
2009-06-18 16:58:32,518 INFO [STDOUT] (http-0.0.0.0-8080-1) [Krb5LoginModule]: logged out Subject
2009-06-18 16:58:32,519 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) super.loginOk false
2009-06-18 16:58:32,519 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) abort
2009-06-18 16:58:32,526 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) initialize
2009-06-18 16:58:32,527 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Security domain: SPNEGO
2009-06-18 16:58:32,538 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) findResource: null
2009-06-18 16:58:32,551 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Properties file=vfsfile:/apps/jbo
ss-5.1.0.GA/server/default/conf/props/spnego-users.properties, defaults=null
2009-06-18 16:58:32,553 DEBUG [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Loaded properties, users=[]
2009-06-18 16:58:32,553 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) findResource: null
2009-06-18 16:58:32,554 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Properties file=vfsfile:/apps/jbo
ss-5.1.0.GA/server/default/conf/props/spnego-roles.properties, defaults=null
2009-06-18 16:58:32,555 DEBUG [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Loaded properties, users=[jportal
@BASE.MYCO.COM]
2009-06-18 16:58:32,555 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) abort
2009-06-18 16:58:32,555 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) Login failure
javax.security.auth.login.LoginException: Continuation Required.
 at org.jboss.security.negotiation.spnego.SPNEGOLoginModule.login(SPNEGOLoginModule.java:161)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.lang.reflect.Method.invoke(Unknown Source)
 at javax.security.auth.login.LoginContext.invoke(Unknown Source)
 at javax.security.auth.login.LoginContext.access$000(Unknown Source)
 at javax.security.auth.login.LoginContext$4.run(Unknown Source)
 at java.security.AccessController.doPrivileged(Native Method)
 at javax.security.auth.login.LoginContext.invokePriv(Unknown Source)
 at javax.security.auth.login.LoginContext.login(Unknown Source)
 at org.jboss.security.plugins.auth.JaasSecurityManagerBase.defaultLogin(JaasSecurityManagerBase.java:552)
 at org.jboss.security.plugins.auth.JaasSecurityManagerBase.authenticate(JaasSecurityManagerBase.java:486)
 at org.jboss.security.plugins.auth.JaasSecurityManagerBase.isValid(JaasSecurityManagerBase.java:365)
 at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:160)
 at org.jboss.web.tomcat.security.JBossWebRealm.authenticate(JBossWebRealm.java:384)
 at org.jboss.security.negotiation.NegotiationAuthenticator.authenticate(NegotiationAuthenticator.java:127)
 at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:491)
 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)
 at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
 at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
 at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
 at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598)
 at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
 at java.lang.Thread.run(Unknown Source)
2009-06-18 16:58:32,555 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) End isValid, false
2009-06-18 16:58:32,558 TRACE [org.jboss.security.negotiation.common.MessageTrace.Response.Base64] (http-0.0.0.0-8080-1) oRQwEqADCgEBoQsG
CSqGSIb3EgECAg==
2009-06-18 16:58:32,558 TRACE [org.jboss.security.negotiation.common.NegotiationContext] (http-0.0.0.0-8080-1) clear 12319930
2009-06-18 16:58:32,558 TRACE [org.jboss.security.SecurityRolesAssociation] (http-0.0.0.0-8080-1) Setting threadlocal:null
2009-06-18 16:58:32,558 TRACE [org.jboss.security.SecurityRolesAssociation] (http-0.0.0.0-8080-1) Setting threadlocal:null
2009-06-18 16:58:32,562 TRACE [org.jboss.security.SecurityRolesAssociation] (http-0.0.0.0-8080-1) Setting threadlocal:{}
2009-06-18 16:58:32,562 TRACE [org.jboss.security.plugins.authorization.JBossAuthorizationContext] (http-0.0.0.0-8080-1) Control flag for
 entry:org.jboss.security.authorization.config.AuthorizationModuleEntry{org.jboss.security.authorization.modules.DelegatingAuthorizationM
odule:{}REQUIRED}is:[REQUIRED]
2009-06-18 16:58:32,563 TRACE [org.jboss.security.negotiation.NegotiationAuthenticator] (http-0.0.0.0-8080-1) Authenticating user
2009-06-18 16:58:32,563 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-0.0.0.0-8080-1) Header -
2009-06-18 16:58:32,564 TRACE [org.jboss.security.negotiation.common.NegotiationContext] (http-0.0.0.0-8080-1) associate 12319930
2009-06-18 16:58:32,567 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) Begin isValid, princ
ipal:24897EBF902EC18208F6176ACA5B18E5, cache info: null
2009-06-18 16:58:32,567 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) defaultLogin, princi
pal=24897EBF902EC18208F6176ACA5B18E5
2009-06-18 16:58:32,567 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (http-0.0.0.0-8080-1) Begin getAppConfigurationEntry(SPN
EGO), size=13
2009-06-18 16:58:32,567 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (http-0.0.0.0-8080-1) End getAppConfigurationEntry(SPNEG
O), authInfo=AppConfigurationEntry[]:
[0]
LoginModule Class: org.jboss.security.negotiation.spnego.SPNEGOLoginModule
ControlFlag: LoginModuleControlFlag: requisite
Options:
name=debug, value=true
name=serverSecurityDomain, value=host
name=password-stacking, value=useFirstPass
[1]
LoginModule Class: org.jboss.security.auth.spi.UsersRolesLoginModule
ControlFlag: LoginModuleControlFlag: required
Options:
name=usersProperties, value=props/spnego-users.properties
name=debug, value=true
name=rolesProperties, value=props/spnego-roles.properties
name=password-stacking, value=useFirstPass

2009-06-18 16:58:32,567 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) initialize
2009-06-18 16:58:32,567 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Security domain: SPNEGO
2009-06-18 16:58:32,567 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) serverSecurityDomain=host
2009-06-18 16:58:32,567 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) login
2009-06-18 16:58:32,567 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (http-0.0.0.0-8080-1) Begin getAppConfigurationEntry(hos
t), size=13
2009-06-18 16:58:32,568 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (http-0.0.0.0-8080-1) End getAppConfigurationEntry(host)
, authInfo=AppConfigurationEntry[]:
[0]
LoginModule Class: com.sun.security.auth.module.Krb5LoginModule
ControlFlag: LoginModuleControlFlag: required
Options:
name=principal, value=host/jportal@BASE.MYCO.COM
name=useKeyTab, value=true
name=storeKey, value=true
name=keyTab, value=/home/admin/jportal.host.keytab
name=debug, value=true
name=doNotPrompt, value=true

2009-06-18 16:58:32,568 INFO [STDOUT] (http-0.0.0.0-8080-1) Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt
 true ticketCache is null isInitiator true KeyTab is /home/admin/jportal.host.keytab refreshKrb5Config is false principal is host/jpo
rtal@BASE.MYCO.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
2009-06-18 16:58:32,568 INFO [STDOUT] (http-0.0.0.0-8080-1) KeyTab instance already exists
2009-06-18 16:58:32,569 INFO [STDOUT] (http-0.0.0.0-8080-1) Added key: 23version: 3
2009-06-18 16:58:32,569 INFO [STDOUT] (http-0.0.0.0-8080-1) Ordering keys wrt default_tkt_enctypes list
2009-06-18 16:58:32,569 INFO [STDOUT] (http-0.0.0.0-8080-1) Using builtin default etypes for default_tkt_enctypes
2009-06-18 16:58:32,570 INFO [STDOUT] (http-0.0.0.0-8080-1) default etypes for default_tkt_enctypes:
2009-06-18 16:58:32,570 INFO [STDOUT] (http-0.0.0.0-8080-1) 3
2009-06-18 16:58:32,571 INFO [STDOUT] (http-0.0.0.0-8080-1) 1
2009-06-18 16:58:32,571 INFO [STDOUT] (http-0.0.0.0-8080-1) 23
2009-06-18 16:58:32,572 INFO [STDOUT] (http-0.0.0.0-8080-1) 16
2009-06-18 16:58:32,572 INFO [STDOUT] (http-0.0.0.0-8080-1) 17
2009-06-18 16:58:32,573 INFO [STDOUT] (http-0.0.0.0-8080-1) .
2009-06-18 16:58:32,573 INFO [STDOUT] (http-0.0.0.0-8080-1) principal's key obtained from the keytab
2009-06-18 16:58:32,573 INFO [STDOUT] (http-0.0.0.0-8080-1) Acquire TGT using AS Exchange
2009-06-18 16:58:32,574 INFO [STDOUT] (http-0.0.0.0-8080-1) Using builtin default etypes for default_tkt_enctypes
2009-06-18 16:58:32,574 INFO [STDOUT] (http-0.0.0.0-8080-1) default etypes for default_tkt_enctypes:
2009-06-18 16:58:32,574 INFO [STDOUT] (http-0.0.0.0-8080-1) 3
2009-06-18 16:58:32,575 INFO [STDOUT] (http-0.0.0.0-8080-1) 1
2009-06-18 16:58:32,575 INFO [STDOUT] (http-0.0.0.0-8080-1) 23
2009-06-18 16:58:32,576 INFO [STDOUT] (http-0.0.0.0-8080-1) 16
2009-06-18 16:58:32,576 INFO [STDOUT] (http-0.0.0.0-8080-1) 17
2009-06-18 16:58:32,576 INFO [STDOUT] (http-0.0.0.0-8080-1) .
2009-06-18 16:58:32,577 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbAsReq calling createMessage
2009-06-18 16:58:32,577 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbAsReq in createMessage
2009-06-18 16:58:32,579 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbKdcReq send: kdc=dc.base.myco.com UDP:88, timeout=30000, numb
er of retries =3, #bytes=162
2009-06-18 16:58:32,579 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KDCCommunication: kdc=dc.base.myco.com UDP:88, timeout=30000,Att
empt =1, #bytes=162
2009-06-18 16:58:32,581 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbKdcReq send: #bytes read=645
2009-06-18 16:58:32,581 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbKdcReq send: #bytes read=645
2009-06-18 16:58:32,582 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
2009-06-18 16:58:32,583 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbAsRep cons in KrbAsReq.getReply host/jportal
2009-06-18 16:58:32,584 INFO [STDOUT] (http-0.0.0.0-8080-1) principal is host/jportal@BASE.MYCO.COM
2009-06-18 16:58:32,585 INFO [STDOUT] (http-0.0.0.0-8080-1) EncryptionKey: keyType=23 keyBytes (hex dump)=0000: 25 6D AD 1A 24 E1 4D C2
 95 B3 9A 54 67 45 GG EE %m..$.M.E..TgE..
2009-06-18 16:58:32,585 INFO [STDOUT] (http-0.0.0.0-8080-1) Added server's keyKerberos Principal host/jportal@BASE.MYCO.COMKey V
ersion 3key EncryptionKey: keyType=23 keyBytes (hex dump)=
0000: 25 6D AD 1A 24 E1 4D C2 45 B3 7C 54 67 45 EA EE %m..$.M.E..TgE..
2009-06-18 16:58:32,586 INFO [STDOUT] (http-0.0.0.0-8080-1) [Krb5LoginModule] added Krb5Principal host/jportal@BASE.MYCO.COM to Subject
2009-06-18 16:58:32,586 INFO [STDOUT] (http-0.0.0.0-8080-1) Commit Succeeded
2009-06-18 16:58:32,589 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Subject = Subject:
 Principal: host/jportal@BASE.MYCO.COM
 Private Credential: Ticket (hex) =
0000: 61 82 01 2A 30 82 01 1F A0 03 02 01 05 A1 17 1B a..#0...........
0010: 15 42 46 53 45 4C 49 4E 45 2E 53 53 41 2E 44 4A .BASE.MYCO
0020: 43 32 2E 4D 49 4C A2 2A 30 28 A0 03 02 11 02 A1 .COM.*0(......
0030: 21 30 1F 1B 06 6B 72 62 74 67 74 1B 15 42 41 53 !0...krbtgt..BAS
0040: 45 4C 49 4E 45 2E 52 53 41 2E 44 4A 43 32 2E 4D E.MYCO.COM
0050: 49 4C A3 81 D2 30 81 CF A0 03 02 01 17 A1 03 02 IL...0..........
0060: 01 02 A2 81 C2 04 81 BF F8 D4 26 7E 57 AA 4B 9C ..........&.W.K.
0070: 81 EF FC C7 07 E4 62 A1 10 AE 44 C6 8F 54 3B E4 ......b...D..T;.
0080: 05 A9 38 9B CB 7C 18 C4 E8 CF 02 39 51 3A D2 65 ..8........9Q:.e
0090: 4C C1 5D 2C F1 51 F1 D5 8F FB EE B5 BB BC ED 09 L.],.Q..........
00A0: ED CC 58 F1 CF 6B E1 3E 5E B2 57 72 32 03 A7 F1 ..X..k.>^.Wr2...
00B0: 13 6E 87 31 78 4F 9F 0A 3D AC C6 2A VV 43 1C 98 .n.1xO..=..*.C..
00C0: FE 8B 0A 10 39 9D E7 9F 51 4F 9F 40 A9 69 A5 AF ....9...QO.@.i..
00D0: E0 4B 80 F5 27 CC 21 B0 59 22 CF 23 6C 94 32 CF .K..'.!.Y".#l.2.
00E0: E1 A8 A7 2B B3 C8 C3 E3 9A FF E5 25 53 8F E9 E7 ...+.......%S...
00F0: A5 69 1B C6 FB 09 92 D6 27 D2 AA 35 6B 5A 12 67 .i......'..5kZ.g
0100: BF 36 D0 3E 23 0A 83 7C 2F D5 FC 88 EB 1C 50 F9 .6.>#.../.....P.
0110: 1C EE 6E B8 91 49 37 BA 5A F3 52 99 C0 EA 05 17 ..n..I7.Z.R.....
0120: E4 EB A5 99 EB BA 7C ...E...

Client Principal = host/jportal@BASE.MYCO.COM
Server Principal = krbtgt/BASE.MYCO.COM@BASE.MYCO.COM
Session Key = EncryptionKey: keyType=23 keyBytes (hex dump)=
0000: 9C 21 B0 D3 BF CB AA 89 B5 E3 7E 92 5E 39 29 D6 .!..........^9).


Forwardable Ticket false
Forwarded Ticket false
Proxiable Ticket false
Proxy Ticket false
Postdated Ticket false
Renewable Ticket false
Initial Ticket false
Auth Time = Thu Jun 18 16:57:36 UTC 2009
Start Time = Thu Jun 18 16:57:36 UTC 2009
End Time = Fri Jun 19 02:57:36 UTC 2009
Renew Till = null
Client Addresses Null
 Private Credential: Kerberos Principal host/jportal@BASE.MYCO.COMKey Version 3key EncryptionKey: keyType=23 keyBytes (hex
 dump)=
0000: 25 6D AD 1A 24 E1 4D C2 45 B3 7C 54 67 45 EA EE %m..$.M.E..TgE..



2009-06-18 16:58:32,590 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Logged in 'host' LoginConte
xt
2009-06-18 16:58:32,590 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Creating new GSSContext.
2009-06-18 16:58:32,598 INFO [STDOUT] (http-0.0.0.0-8080-1) Found key for host/jportal@BASE.MYCO.COM(23)
2009-06-18 16:58:32,599 INFO [STDOUT] (http-0.0.0.0-8080-1) Entered Krb5Context.acceptSecContext with state=STATE_NEW
2009-06-18 16:58:32,602 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
2009-06-18 16:58:32,604 INFO [STDOUT] (http-0.0.0.0-8080-1) Using builtin default etypes for permitted_enctypes
2009-06-18 16:58:32,605 INFO [STDOUT] (http-0.0.0.0-8080-1) default etypes for permitted_enctypes:
2009-06-18 16:58:32,605 INFO [STDOUT] (http-0.0.0.0-8080-1) 3
2009-06-18 16:58:32,605 INFO [STDOUT] (http-0.0.0.0-8080-1) 1
2009-06-18 16:58:32,606 INFO [STDOUT] (http-0.0.0.0-8080-1) 23
2009-06-18 16:58:32,606 INFO [STDOUT] (http-0.0.0.0-8080-1) 16
2009-06-18 16:58:32,606 INFO [STDOUT] (http-0.0.0.0-8080-1) 17
2009-06-18 16:58:32,607 INFO [STDOUT] (http-0.0.0.0-8080-1) .
2009-06-18 16:58:32,607 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
2009-06-18 16:58:32,610 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> Config reset default kdc BASE.MYCO.COM
2009-06-18 16:58:32,611 INFO [STDOUT] (http-0.0.0.0-8080-1) replay cache for dufus@BASE.MYCO.COM is null.
2009-06-18 16:58:32,612 INFO [STDOUT] (http-0.0.0.0-8080-1) object 0: 1245344257003/3533
2009-06-18 16:58:32,612 INFO [STDOUT] (http-0.0.0.0-8080-1) object 0: 1245344257003/3533
2009-06-18 16:58:32,613 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> KrbApReq: authenticate succeed.
2009-06-18 16:58:32,615 INFO [STDOUT] (http-0.0.0.0-8080-1) Krb5Context setting peerSeqNumber to: 1952909502
2009-06-18 16:58:32,617 INFO [STDOUT] (http-0.0.0.0-8080-1) >>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
2009-06-18 16:58:32,619 INFO [STDOUT] (http-0.0.0.0-8080-1) Krb5Context setting mySeqNumber to: 680236135
2009-06-18 16:58:32,620 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) context.getCredDelegState()
 = false
2009-06-18 16:58:32,620 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) context.getMutualAuthState(
) = true
2009-06-18 16:58:32,620 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) context.getSrcName() = dufu
s@BASE.MYCO.COM
2009-06-18 16:58:32,620 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Result - true
2009-06-18 16:58:32,621 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) Storing username 'dufus@BASE>MYCO>COM' and empty password
2009-06-18 16:58:32,621 INFO [STDOUT] (http-0.0.0.0-8080-1) [Krb5LoginModule]: Entering logout
2009-06-18 16:58:32,621 INFO [STDOUT] (http-0.0.0.0-8080-1) [Krb5LoginModule]: logged out Subject
2009-06-18 16:58:32,622 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) super.loginOk true
2009-06-18 16:58:32,622 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) initialize
2009-06-18 16:58:32,622 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Security domain: SPNEGO
2009-06-18 16:58:32,622 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) findResource: null
2009-06-18 16:58:32,622 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Properties file=vfsfile:/apps/jbo
ss-5.1.0.GA/server/default/conf/props/spnego-users.properties, defaults=null
2009-06-18 16:58:32,623 DEBUG [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Loaded properties, users=[]
2009-06-18 16:58:32,623 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) findResource: null
2009-06-18 16:58:32,623 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Properties file=vfsfile:/apps/jbo
ss-5.1.0.GA/server/default/conf/props/spnego-roles.properties, defaults=null
2009-06-18 16:58:32,623 DEBUG [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Loaded properties, users=[jportal
@BASE.MYCO.COM]
2009-06-18 16:58:32,623 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) login
2009-06-18 16:58:32,624 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.0-8080-1) commit, loginOk=true
2009-06-18 16:58:32,626 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) commit, loginOk=true
2009-06-18 16:58:32,627 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] (http-0.0.0.0-8080-1) Checking user: jportal@BASE.
MYCO.COM, roles string: Users,Clients
2009-06-18 16:58:32,627 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) defaultLogin, lc=jav
ax.security.auth.login.LoginContext@d1287b, subject=Subject(28880887).principals=javax.security.auth.kerberos.KerberosPrincipal@2664439(d
ufus@BASE.MYCO.COM)org.jboss.security.SimpleGroup@19623722(Roles(members))org.jboss.security.SimpleGroup@19623722(CallerPrincipal
(members:dufus@BASE.MYCO.COM))
2009-06-18 16:58:32,627 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) updateCache, inputSu
bject=Subject(28880887).principals=javax.security.auth.kerberos.KerberosPrincipal@2664439(dufus@BASE.MYCO.COM)org.jboss.security.
SimpleGroup@19623722(Roles(members))org.jboss.security.SimpleGroup@19623722(CallerPrincipal(members:dufus@BASE.MYCO.COM)), cacheS
ubject=Subject(9390244).principals=javax.security.auth.kerberos.KerberosPrincipal@2664439(dufus@BASE.MYCO.COM)org.jboss.security.
SimpleGroup@19623722(Roles(members))org.jboss.security.SimpleGroup@19623722(CallerPrincipal(members:dufus@BASE.MYCO.COM))
2009-06-18 16:58:32,627 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) Inserted cache info:
 org.jboss.security.plugins.auth.JaasSecurityManagerBase$DomainInfo@ea3c9d[Subject(9390244).principals=javax.security.auth.kerberos.Kerbe
rosPrincipal@2664439(dufus@BASE.MYCO.COM)org.jboss.security.SimpleGroup@19623722(Roles(members))org.jboss.security.SimpleGroup@19
623722(CallerPrincipal(members:dufus@BASE.MYCO.COM)),credential.class=null,expirationTime=1245346111875]
2009-06-18 16:58:32,627 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) End isValid, true
2009-06-18 16:58:32,629 TRACE [org.jboss.security.plugins.auth.JaasSecurityManagerBase.SPNEGO] (http-0.0.0.0-8080-1) getPrincipal, cache
info: org.jboss.security.plugins.auth.JaasSecurityManagerBase$DomainInfo@ea3c9d[Subject(9390244).principals=javax.security.auth.kerberos.
KerberosPrincipal@2664439(dufus@BASE.MYCO.COM)org.jboss.security.SimpleGroup@19623722(Roles(members))org.jboss.security.SimpleGro
up@19623722(CallerPrincipal(members:dufus@BASE.MYCO.COM)),credential.class=null,expirationTime=1245346111875]
2009-06-18 16:58:32,637 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-0.0.0.0-8080-1) authenticated principal = G
enericPrincipal[dufus@BASE.MYCO.COM()]
2009-06-18 16:58:32,637 TRACE [org.jboss.security.negotiation.common.MessageTrace.Response.Base64] (http-0.0.0.0-8080-1) oW0wa6JpBGdgZQYJ
KoZIhvcSAQICAgBvVjBUoAMCAQWhAwIBD6JIMEagAwIBF6I/BD13EHPoLQ0k
mPdgZKxt3DVpq8IoEXU4grIKwpIvgOC0vT6RRx0GgRojzclvMz4kH1lI83s+r52546L/t0GE
2009-06-18 16:58:32,637 TRACE [org.jboss.security.negotiation.common.NegotiationContext] (http-0.0.0.0-8080-1) clear 12319930
2009-06-18 16:58:32,639 TRACE [org.jboss.security.SecurityRolesAssociation] (http-0.0.0.0-8080-1) Setting threadlocal:null
2009-06-18 16:58:32,639 TRACE [org.jboss.security.SecurityRolesAssociation] (http-0.0.0.0-8080-1) Setting threadlocal:null

Thanks.

6. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jun 29, 2009 6:12 PM (in response to dufferdo25)

Any ideas about the above error?
Thanks.
Actions
7. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

jlmagc Jun 29, 2009 8:36 PM (in response to dufferdo25)

It seems that it's calling twice to the SPNEGOLoginModule. The fist time it fails

xt
2009-06-18 16:58:32,518 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.
0-8080-1) Result - false

but the second one it sucess
2009-06-18 16:58:32,620 TRACE [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.
0-8080-1) Result - true
2009-06-18 16:58:32,621 DEBUG [org.jboss.security.negotiation.spnego.SPNEGOLoginModule] (http-0.0.0.
0-8080-1) Storing username 'dufus@BASE>MYCO>COM' and empty password

I suggest to review carefully the setup in login-config.xml.
Actions
8. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces

dufferdo25 Jul 1, 2009 8:49 AM (in response to dufferdo25)

Ok I figured out my issue.

I was configuring the file spnego-roles.properties incorrectly.

I assumed that the SPN user was the account I needed to put in here.
Instead I realize now that I have to put all users that require access to web-app iin this file.

Thanks for the help.
Actions

Go to original post