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

    JBOSS Negotiate toolkit Secured servlet throws 403 Access de

    G F Newbie

      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
          G F Newbie

          Any Ideas?
          Is there another module I can use for silent sign on?
          Cheers!

          • 2. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces
            Jose Martinez-Avial Newbie

            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.

            • 3. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces
              G F Newbie

              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.

              • 4. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces
                G F Newbie

                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
                  G F Newbie

                  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
                    G F Newbie

                    Any ideas about the above error?
                    Thanks.

                    • 7. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces
                      Jose Martinez-Avial Newbie

                      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.

                      • 8. Re: JBOSS Negotiate toolkit Secured servlet throws 403 Acces
                        G F Newbie

                        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.