Bug 1097276 - [GSS](6.4.z) MsSql datasource throws IllegalStateException while obtaining connection
Summary: [GSS](6.4.z) MsSql datasource throws IllegalStateException while obtaining co...
Status: CLOSED CURRENTRELEASE
Alias: None
Product: JBoss Enterprise Application Platform 6
Classification: JBoss
Component: Security
Version: 6.3.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: CR1
: EAP 6.4.4
Assignee: Darran Lofthouse
QA Contact: Martin Simka
Russell Dickenson
URL:
Whiteboard:
Keywords: TestCaseNeeded
Depends On:
Blocks: 1257226 1235744 1256953
TreeView+ depends on / blocked
 
Reported: 2014-05-13 13:19 UTC by Martin Simka
Modified: 2017-01-17 10:50 UTC (History)
19 users (show)

(edit)
This release of JBoss EAP 6 carries a bug that produces the exception; `java.lang.IllegalStateException: This ticket is no longer valid` in MySQ datasources while obtaining connection.

This issue is expected to be resolved in a future release.
Clone Of:
: 1257226 (view as bug list)
(edit)
Last Closed: 2017-01-17 10:49:54 UTC


Attachments (Terms of Use)
server.log (128.33 KB, text/x-log)
2014-05-13 13:19 UTC, Martin Simka
no flags Details
MSSQL Stack Traces (8.12 KB, text/plain)
2014-05-16 14:34 UTC, Darran Lofthouse
no flags Details
byteman-server.log (1.08 MB, text/x-log)
2014-05-19 13:54 UTC, Martin Simka
no flags Details
byteman-two-test-connection-in-pool-calls-server.log (129.67 KB, text/x-log)
2014-08-15 11:08 UTC, Martin Simka
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
JBoss Issue Tracker EAP6-217 Major Closed Authorization with static Kerberos credentials to SQLServer on Oracle JVM 2018-11-21 07:23 UTC
Red Hat Bugzilla 1097276 None CLOSED [GSS](6.4.z) MsSql datasource throws IllegalStateException while obtaining connection 2018-11-21 07:23 UTC
JBoss Issue Tracker JBEAP-843 Blocker Closed Add protection of our GSSCredential added by the KerberosLoginModule 2018-11-21 07:23 UTC
JBoss Issue Tracker SECURITY-905 Major Resolved Add protection of our GSSCredential added by the KerberosLoginModule 2018-11-21 07:23 UTC

Internal Trackers: 1097276

Description Martin Simka 2014-05-13 13:19:32 UTC
Created attachment 895132 [details]
server.log

*Description of problem:
Exception "java.lang.IllegalStateException: This ticket is no longer valid" is thrown in mssql XA datasource while obtaining connection. This error doesn't happen with non-XA datasource. I'll try to debug and some more details. 

Datasource:
                <xa-datasource jndi-name="java:jboss/datasources/TestDatasource" pool-name="TestDatasource" enabled="true" spy="true">
                    <xa-datasource-property name="URL">
                        jdbc:sqlserver://dpaz-win2008.msdomain.mw.lab.eng.bos.redhat.com;DatabaseName=krbusr01
                    </xa-datasource-property>
                    <xa-datasource-property name="integratedSecurity">
                        true
                    </xa-datasource-property>
                    <xa-datasource-property name="authenticationScheme">
                        JavaKerberos
                    </xa-datasource-property>
                    <xa-datasource-class>com.microsoft.sqlserver.jdbc.SQLServerXADataSource</xa-datasource-class>
                    <driver>mssql2008R2.jar</driver>
                    <xa-pool>
                        <min-pool-size>0</min-pool-size>
                        <max-pool-size>1</max-pool-size>
                        <allow-multiple-users>true</allow-multiple-users>
                    </xa-pool>
                    <security>
                        <security-domain>DatabaseUser</security-domain>
                    </security>
                </xa-datasource>

I also tried to remove elements <xa-datasource-property> for integratedSecurity and authenticationScheme and add them direcly to URL


Exception: (full stacktrace in attached server.log)
Caused by: java.lang.IllegalStateException: This ticket is no longer valid
        at javax.security.auth.kerberos.KerberosTicket.toString(KerberosTicket.java:638) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSCredentialImpl.toString(GSSCredentialImpl.java:633) [rt.jar:1.7.0_17]
        at java.lang.String.valueOf(String.java:2854) [rt.jar:1.7.0_17]
        at java.lang.StringBuilder.append(StringBuilder.java:128) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSUtil$1.run(GSSUtil.java:342) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSUtil$1.run(GSSUtil.java:331) [rt.jar:1.7.0_17]
        at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSUtil.searchSubject(GSSUtil.java:329) [rt.jar:1.7.0_17]
        at sun.security.jgss.krb5.Krb5MechFactory.getCredFromSubject(Krb5MechFactory.java:68) [rt.jar:1.7.0_17]
        at sun.security.jgss.krb5.Krb5MechFactory.getCredentialElement(Krb5MechFactory.java:115) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSManagerImpl.getCredentialElement(GSSManagerImpl.java:192) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSCredentialImpl.add(GSSCredentialImpl.java:406) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSCredentialImpl.<init>(GSSCredentialImpl.java:60) [rt.jar:1.7.0_17]
        at sun.security.jgss.GSSManagerImpl.createCredential(GSSManagerImpl.java:153) [rt.jar:1.7.0_17]
        at com.microsoft.sqlserver.jdbc.KerbAuthentication$1.run(KerbAuthentication.java:189)
        at com.microsoft.sqlserver.jdbc.KerbAuthentication$1.run(KerbAuthentication.java:187)
        at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_17]
        at javax.security.auth.Subject.doAs(Subject.java:415) [rt.jar:1.7.0_17]
        at com.microsoft.sqlserver.jdbc.KerbAuthentication.getClientCredential(KerbAuthentication.java:199)
        at com.microsoft.sqlserver.jdbc.KerbAuthentication.intAuthInit(KerbAuthentication.java:150)
        at com.microsoft.sqlserver.jdbc.KerbAuthentication.GenerateClientContext(KerbAuthentication.java:268)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.sendLogon(SQLServerConnection.java:2691)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.logon(SQLServerConnection.java:2234)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.access$000(SQLServerConnection.java:41)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection$LogonCommand.doExecute(SQLServerConnection.java:2220)
        at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:5696)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1715)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:1326)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:991)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:827)
        at com.microsoft.sqlserver.jdbc.SQLServerXAConnection.<init>(SQLServerXAConnection.java:43)
        at com.microsoft.sqlserver.jdbc.SQLServerXADataSource.getXAConnection(SQLServerXADataSource.java:51)
        at org.jboss.jca.adapters.jdbc.xa.XAManagedConnectionFactory.getXAManagedConnection(XAManagedConnectionFactory.java:497)



*Version-Release number of selected component (if applicable):
EAP 6.3.0.ER3
IronJacamar 1.0.26

*Steps to Reproduce:
1. clone datasource-kerberos test suite git://git.app.eng.bos.redhat.com/jbossqe-eap-tests-domain-mode.git
2. extract eap somewhere
3. run mvn integration-test -Djboss.dist=<path-to-eap> -Ddb.profile=mssql2008R2 -Djdbc.installation.type=deployment -Dit.test=org.jboss.qa.krbds.test.XADatasourceWithAllowMultipleUsersTestCase#testDatasource
4. test fails, see server.log

for manual testing you can now run eap and deploy app target/deployment/_DEFAULT__hostTestDeployment_HostTestWebApp.war and then access http://localhost:8080/HostTestWebApp/HostTestServlet?profile=mssql2008R2


*Additional info:
I've chosen security component, because error message seems to be related to kerberos ticket. But it could be related also to JCA as there is no error with non XA datasource. 


Setting blocker? flag because it's RFE

Comment 1 Martin Simka 2014-05-16 11:39:06 UTC
same problem with non-XA datasource. It does not happen while running single test (-Dit.test=) but it always fails with all tests task. With XA datasource it happens in both cases, all tests and single test.

Comment 2 Darran Lofthouse 2014-05-16 11:45:27 UTC
I will get an EAP build running in a minute, we should not be hitting any timeouts here but I am wondering if something is calling dispose on the GSSCredential and making it invalid.

Comment 3 Darran Lofthouse 2014-05-16 14:34:37 UTC
Created attachment 896426 [details]
MSSQL Stack Traces

Attaching a debugger I can confirm that the error message being reported is as a result of the JDBC driver disposing of the KerberosTicket that it is using and then subsequently attempting to use it again, the two stacks in the file illustrate this.

Comment 4 Darran Lofthouse 2014-05-16 14:56:24 UTC
I think the following could now be beneficial: -
 - Update testing so that the category 'com.microsoft' is logged at level FINEST
 - Update the test to use ByteMan to log the stack each time javax.security.auth.kerberos.KerberosTicket.dispose() us called.

My feeling at the moment is that the driver is taking a valid Subject, something during the call is causing the driver to invalidate one of the tickets and the driver subsequently tries to use it an fails.  The additional logging should help map this better with the ByteMan traces as well.  It could be that there is something we can fix and it is an initial connection attempt that is failing but we only see an error message for a retry or it could be an issue within the JDBC driver.

Comment 5 Martin Simka 2014-05-19 13:54:42 UTC
Created attachment 897158 [details]
byteman-server.log

suggested changes were added to test suite, branch byteman. KerberosTicket.destroy is always called after authentication. Details in attached server.log

Comment 8 Martin Simka 2014-08-15 11:08:44 UTC
Created attachment 927065 [details]
byteman-two-test-connection-in-pool-calls-server.log

Attached server.log with two test-connection-in-pool calls. First passes, second fails. 

com.microsoft log category set to TRACE
byteman rule that logs stack each time javax.security.auth.kerberos.KerberosTicket.destroy() us called

Comment 10 Darran Lofthouse 2014-11-04 15:56:52 UTC
Don't think we already added clarification regarding the difference between XA and non-XA but simply it is the recovery thread for the XA connections that is causing the error to be reported sooner as that thread can result in an attempt to obtain a connection sooner.

Comment 11 JBoss JIRA Server 2014-12-09 12:15:34 UTC
Kabir Khan <kabir.khan@jboss.com> updated the status of jira EAP6-217 to Resolved

Comment 12 JBoss JIRA Server 2015-04-28 15:04:19 UTC
John Doyle <jdoyle@jboss.org> updated the status of jira EAP6-217 to Closed

Comment 46 Carlo de Wolf 2015-08-21 07:13:23 UTC
As per https://bugzilla.redhat.com/show_bug.cgi?id=1097276#c25 I believe the authentication cache disabling must be applied in conjunction with disabling prefill.
Most likely IronJacamar fills the cache in a loop with the same Subject. If that is the case, maybe we can change that loop to always go through authentication and leave the Subject caching to the security configuration.

Comment 47 Carlo de Wolf 2015-08-21 07:15:00 UTC
As suggested by Derek Horton:
> Change:
>  
>   <security-domain name="SQLJDBC_KERBEROS" cache-type="default"> 
> 
> to this:
>  
>   <security-domain name="SQLJDBC_KERBEROS">

Comment 63 Martin Simka 2015-09-25 08:39:27 UTC
verified with EAP 6.4.4.CP.CR3

Comment 64 JBoss JIRA Server 2015-10-08 13:08:52 UTC
Martin Simka <msimka@redhat.com> updated the status of jira JBEAP-843 to Closed

Comment 65 Dave Sullivan 2015-10-28 16:41:21 UTC
Per erich,

"I have been given information that EAP 6.4.4 shipped and should be available."

Curious why this BZ doesn't reflect that and why it is not in closed state?

Comment 66 Petr Penicka 2017-01-17 10:49:54 UTC
Retroactively bulk-closing issues from released EAP 6.4 cumulative patches.

Comment 67 Petr Penicka 2017-01-17 10:50:47 UTC
Retroactively bulk-closing issues from released EAP 6.4 cumulative patches.


Note You need to log in before you can comment on or make changes to this bug.