1 Reply Latest reply on Nov 12, 2009 1:34 PM by Kelly Dolan

    JBoss Negotiation - cannot even get basic negotiation to wor

    Kelly Dolan Newbie

      I need to integrate JBoss Negotiation 2.0.3.GA with JBoss 4.2.3.GA and I've spent days getting nowhere. So, any and all help is greatly appreciated as I'm pretty desperate because I'm out of time. I've followed the instructions correctly as far as I can tell, but it is still not working and I don't know how to debug any further. Help!!!

      I started at the JBoss Negotiation wiki page (http://www.jboss.org/community/wiki/JBossNegotiation). I downloaded the GA release and followed the instructions in the user guide for Chapter 2, 3 and 5 (for Section 2.2 Realm Properties - I tested w/ and w/o these properties set). After this, I ran the Negotiation Toolkit and clicked on the Basic Negotiation link - the response was "Warning, this is NTLM, only SPNEGO is supported!" which according to the user guide indicates a failed response. Chapter 8 of the user guide identified how to turn on logging so I (a) set org.jboss.security to TRACE, (b) set org.jboss.security.negotiation.MessageTrace to TRACE, (c) set the system property sun.security.krb5.debug to true and (d) set the debug property for the Krb5LoginModule to true. Very little was added to the log files, but I noticed log entries for NTLMNegotiationServlet.

      Having no luck, I visited the Microsoft web site to better understand Kerberos, SPNEGO, the support tools used (e.g., setspn, ktpass), etc. I also looked at examples on other web sites. Lastly, I returned to the JBoss wiki page and noticed a link to an article containing "the steps required on an all Windows domain" (http://www.jboss.org/community/wiki/ConfiguringJBossNegotiationinanallWindowsDomain).

      So, I started over and followed the instructions in this document. The steps I performed are below along w/ detailed information re: my environment. I'm hoping someone can see something I'm doing wrong and/or point me to additional documentation that will help me further troubleshoot this.

      My environment information:
      Windows: all machines involved (domain controllers = 2003, client = XP)
      Realm: MYCO.COM
      Domain: myco.com
      Domain Controllers: dc1, dc2 and dc3 (e.g., dc1.myco.com)
      JBoss host: frog.myco.com
      JBoss port: 5150 (I also tried ports 80 and 8080)
      Client (where IE is running): also on frog
      set -Djava.security.krb5.realm=MYCO.COM
      set -Djava.security.krb5.kdc=dc1


      The following I performed on DC1. I confirmed the changes propagated to DC2 and DC3.

      1) > setspn -l frog

      HOST/Frog.myco.com
      HOST/Frog

      2) > setspn -D HOST/Frog.myco.com frog
      > setspn -D HOST/Frog frog
      > setspn -l frog

      (list empty)

      3) Ignored all further operations using setspn in the JBoss Negotiation user guide.

      4) Created a user named "spnego1" according to the user guide Chapter 3.2. Note: In Figure 3.4, the value in the "User login name" field for me was "spnego1". After (9) below, it is different.

      5) > ktpass -princ HTTP/frog.myco.com@MYCO.COM -pass * -mapuser MYCO\spnego1

      I entered the password I chose for "spnego1" when prompted for the password from this command.

      6) The documentation next says at this step I have found it necessary to rese the password for user_name ready for the ktab step later. I didn't know what this meant, so I didn't do anything.

      7) > setspn -l spnego1

      HTTP/frog.myco.com

      8) > ktab -k spnego1.keytab -a HTTP/frog.myco.com@MYCO.COM

      I entered the password I chose for "spnego1" when prompted for the password from this command.

      9) Copied spnego1.keytab to frog at c:\spnego1.keytab (users have read and execute permissions). Deleted spnego1.keytab on DC1.


      NOTE: At this point, I noticed in the properties for my "spnego1" user, the value in the "User login name" field is now "HTTP/amadeus.inmedius.com@INMEDIUS.COM" (i.e., no long spnego1).


      The following I performed on frog.

      10) Confirmed those in Users group have Read and Read & Execute permissions on spnego1.keytab.

      11) Modified login-config.xml application-policy = host.

      a) set principal to HTTP/frog.myco.com@MYCO.COM
      b) set keyTab to c:/spnego1.keytab

      12) In IE 7.0, my Internet Options are...

      a) Advanced > Enable Integrated Windows Authentication* is checked.
      b) Security > Local Intranet > Custom level... > Automatic logon only in Intranet zone is selected.
      c) Security > Local Intranet > Sites > Advanced > *.myco.com, http://frog, http://frog.myco.com, http://localhost are in the list.

      13) Started JBoss using run.bat.

      14) Opened IE,
      > http://frog.myco.com/jboss-negotiation-toolkit/
      > clicked on Basic Negotiation link

      Output received:

      NTLM Negotiation
      WWW-Authenticate - Negotiate ...

      NTLM - Negotiate_Message
      Warning, this is NTLM, only SPNEGO is supported!
      Negotiate Flags - (encryption56Bit)(sessionKeyExchange128Bit)(negotiateVersion)(ntlm2)(alwaysSign)(oemWorkstationSupplied)(oemDomainSupplied)(ntlm)(requestTarget)(oem)(unicode)
      Domain Name = MYCO - {length=8}{maxLength=8}{offset=47}
      Workstation Name = FROG - {length=7}{maxLength=7}{offset=40}
      Version - ...

      The content of my server.log file:

      2009-11-12 11:34:02,593 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Thu, 12 Nov 2009 11:34:02>
      2009-11-12 11:34:02,593 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2009-11-12 11:34:02,593 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2009-11-12 11:34:02,593 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2009-11-12 11:34:12,593 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Thu, 12 Nov 2009 11:34:12>
      2009-11-12 11:34:12,593 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2009-11-12 11:34:12,593 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2009-11-12 11:34:12,593 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2009-11-12 11:36:12,592 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Thu, 12 Nov 2009 11:36:12>
      2009-11-12 11:36:12,592 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2009-11-12 11:36:12,592 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2009-11-12 11:36:12,592 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2009-11-12 11:36:22,592 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Thu, 12 Nov 2009 11:36:22>
      2009-11-12 11:36:22,592 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2009-11-12 11:36:22,592 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2009-11-12 11:36:22,592 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2009-11-12 11:37:13,076 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
      2009-11-12 11:37:13,092 TRACE [org.jboss.security.SecurityAssociation] popRunAsIdentity, runAs=null
      2009-11-12 11:37:13,092 TRACE [org.jboss.security.SecurityAssociation] clear, server=true
      2009-11-12 11:37:34,623 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
      2009-11-12 11:37:34,638 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
      2009-11-12 11:37:34,638 TRACE [org.jboss.security.SecurityAssociation] popRunAsIdentity, runAs=null
      2009-11-12 11:37:34,638 INFO [org.jboss.security.negotiation.toolkit.BasicNegotiationServlet] No Authorization Header, sending 401
      2009-11-12 11:37:34,638 TRACE [org.jboss.security.SecurityAssociation] popRunAsIdentity, runAs=null
      2009-11-12 11:37:34,638 TRACE [org.jboss.security.SecurityAssociation] clear, server=true
      2009-11-12 11:37:34,638 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
      2009-11-12 11:37:34,638 INFO [org.jboss.security.negotiation.toolkit.BasicNegotiationServlet] Authorization header received - decoding token.
      2009-11-12 11:37:34,654 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
      2009-11-12 11:37:34,654 TRACE [org.jboss.security.SecurityAssociation] popRunAsIdentity, runAs=null
      2009-11-12 11:37:34,654 INFO [org.jboss.security.negotiation.toolkit.NTLMNegotiationServlet] Authorization header received - decoding token.
      2009-11-12 11:37:34,654 INFO [org.jboss.security.negotiation.toolkit.NTLMNegotiationServlet] Using existing message.
      2009-11-12 11:37:34,670 TRACE [org.jboss.security.SecurityAssociation] popRunAsIdentity, runAs=null
      2009-11-12 11:37:34,670 TRACE [org.jboss.security.SecurityAssociation] clear, server=true
      2009-11-12 11:38:22,591 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Thu, 12 Nov 2009 11:38:22>
      2009-11-12 11:38:22,591 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2009-11-12 11:38:22,591 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2009-11-12 11:38:22,591 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2009-11-12 11:38:32,591 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Thu, 12 Nov 2009 11:38:32>
      2009-11-12 11:38:32,591 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2009-11-12 11:38:32,591 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2009-11-12 11:38:32,591 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      



      So at this point I'm lost - I don't know who's not doing the correct thing and how to figure it out. The only other thing I learned when reading the Microsoft MSDN articles was that the format of an SPN includes a port when the port a service is using is not the default (e.g., HTTP/frog.myco.com:5150) BUT
      a) The use of setspn.exe is "skipped" according to the latter instructions I followed.
      b) I changed the port on which JBoss was listening for requests from 5150 to 80 (and 8080) to determine if it was a port related issue.

      Thanks!!!