[CORE-149] JDBC calls to interrupted threads throw sqlexceptions - Queries do not leave medium queue - i2b2 JIRA

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: 1.7.03
Fix Version/s: 1.7.06
Component/s: CRC Cell
Labels:
None
Environment:
Java SE Runtime Environment (build 1.6.0_16-b01)
JBoss AS 7.1.1.Final

i2b2 Feature/s:

Queries - Large
i2b2 Sponsored Project/s:

i2b2 Core

Affects Database/s:

Oracle
Affects Web Browser/s:

All Web Browsers

Developer Notes:
Development done by Mike Mendis
Testing Notes:

Hide
Test Date: 04/10/2015
Build Number:
Test Status: Passed

Test Comments:
Tested with the latest web client build and it appears to be working correctly. The query is now running to completion and the status in Previous Queries is being updated correctly.

Clients Tested :
     i2b2 Web Client

Environments Tested :
     Browsers: Not applicable for this test
     Databases: SQL Server and Oracle
     Client OS: Mac OS and Windows

++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Test Date: 04/09/2015
Build Number:
Test Status: Failed

Test Comments:
Tested with the latest web client build and it is not working correctly. The query never finishes running. It stays in a processing state. It will go from the small to medium queue but it does not appear to go from the medium to large queue. It remains in the medium queue and is never updated with an end date.

Clients Tested :
     i2b2 Web Client

Environments Tested :
     Browsers: Not applicable for this test
     Databases: SQL Server and Oracle
     Client OS: Mac OS and Windows

Show
Test Date: 04/10/2015 Build Number: Test Status: Passed Test Comments: Tested with the latest web client build and it appears to be working correctly. The query is now running to completion and the status in Previous Queries is being updated correctly. Clients Tested :      i2b2 Web Client Environments Tested :      Browsers: Not applicable for this test      Databases: SQL Server and Oracle      Client OS: Mac OS and Windows ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Test Date: 04/09/2015 Build Number: Test Status: Failed Test Comments: Tested with the latest web client build and it is not working correctly. The query never finishes running. It stays in a processing state. It will go from the small to medium queue but it does not appear to go from the medium to large queue. It remains in the medium queue and is never updated with an end date. Clients Tested :      i2b2 Web Client Environments Tested :      Browsers: Not applicable for this test      Databases: SQL Server and Oracle      Client OS: Mac OS and Windows

Description

When moving from small to medium queue, the thread processing the query is interrupted (edu.harvard.i2b2.crc.ejb.QueryManagerBeanUtil:234). The interruptedException is being caught by the jboss jdbc adapters (BaseWrapperManagedConnection.tryLock(BaseWrapperManagedConnection.java:384)) upon any calls to the database and throwing a general sqlexception (java.sql.SQLException: Interrupted attempting lock).

The below error is shown in the logs (and additional related errors upon calls to clean up the temporary tables, etc.). The query never finishes, and shows a processing in the database. As a temporary fix, we've commented out the t.interrupt() call without any ill effects.

09:01:57,048 INFO [stdout] (Thread-203) insert into i2b2data.DX ( patient_num ) select * from ( select distinct patient_num from i2b2data.QUERY_GLOBAL_TEMP where panel_count = 1 ) q
09:06:50,376 ERROR [edu.harvard.i2b2.crc.dao.CRCDAO] (Thread-203) Error while executing sql: java.sql.SQLException: Interrupted attempting lock: org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@998944
        at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.tryLock(BaseWrapperManagedConnection.java:384)
        at org.jboss.jca.adapters.jdbc.WrappedConnection.lock(WrappedConnection.java:146)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.lock(WrappedStatement.java:110)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.executeUpdate(WrappedStatement.java:359)
        at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorHelperDao.executeQuery(QueryExecutorHelperDao.java:309) [CRC-core.jar:]
        at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorDao.executeSQL(QueryExecutorDao.java:320) [CRC-core.jar:]
        at edu.harvard.i2b2.crc.ejb.ExecRunnable.processQueryRequest(ExecRunnable.java:469) [CRC-core.jar:]
        at edu.harvard.i2b2.crc.ejb.ExecRunnable.run(ExecRunnable.java:184) [CRC-core.jar:]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

Attachments

Activity

Ascending order - Click to sort in descending order

Michael Horvath created issue - 18/Sep/14 4:32 PM

Janice Donahoe made changes - 22/Sep/14 1:17 PM

Field	Original Value	New Value
Fix Version/s		1.7.04 [ 10160 ]
Assignee		Mike Mendis [ mem61 ]
i2b2 Sponsored Project/s		i2b2 Core [ 10196 ]
Status	New [ 10000 ]	Open [ 1 ]

Janice Donahoe made changes - 04/Nov/14 9:38 AM

Fix Version/s		1.7.05 [ 10164 ]
Fix Version/s	1.7.04 [ 10160 ]

Nathan Graham added a comment - 10/Feb/15 10:23 AM

We just ran in to this issue at KUMC as well. I applied Michael's temporary fix and it seems to work in at least one case.

Michael's workaround really helped us out with an urgent data request! Thanks Michael!

Nathan Graham added a comment - 10/Feb/15 10:23 AM We just ran in to this issue at KUMC as well. I applied Michael's temporary fix and it seems to work in at least one case. Michael's workaround really helped us out with an urgent data request! Thanks Michael!

Michael Horvath added a comment - 10/Feb/15 1:40 PM

Glad that it could be of some use. We still occasionally see issues that I think are related do to the poor nature of my "fix", that end up requiring a restart of the jboss server. I think the long term response would be to catch the SQLException on any calls to the jdbc library, and check for an interruptedException as the cause, then rethrow the interrupt.

See

https://github.com/swaldman/c3p0/issues/37

and

https://issues.apache.org/bugzilla/show_bug.cgi?id=52066

It's a real nuisance that the jdbc library is swallowing the exception, but at least they're providing a way out be encapsulating it in an sqlexception.

Michael Horvath added a comment - 10/Feb/15 1:40 PM Glad that it could be of some use. We still occasionally see issues that I think are related do to the poor nature of my "fix", that end up requiring a restart of the jboss server. I think the long term response would be to catch the SQLException on any calls to the jdbc library, and check for an interruptedException as the cause, then rethrow the interrupt. See https://github.com/swaldman/c3p0/issues/37 and https://issues.apache.org/bugzilla/show_bug.cgi?id=52066 It's a real nuisance that the jdbc library is swallowing the exception, but at least they're providing a way out be encapsulating it in an sqlexception.

Mike Mendis made changes - 30/Mar/15 12:26 PM

Status

Open [ 1 ]

In Progress [ 3 ]

Mike Mendis made changes - 30/Mar/15 12:26 PM

Assignee	Mike Mendis [ mem61 ]	Janice Donahoe [ jmd86 ]
Status	In Progress [ 3 ]	Ready to Test [ 10001 ]

Janice Donahoe made changes - 31/Mar/15 1:26 PM

Status

Ready to Test [ 10001 ]

Testing [ 10002 ]

Janice Donahoe made changes - 09/Apr/15 1:54 PM

Testing Notes		Test Date: 04/09/2015 Build Number: Test Status: Failed Test Comments: Tested with the latest web client build and it is not working correctly. The query never finishes running. It stays in a processing state. It will go from the small to medium queue but it does not appear to go from the medium to large queue. It remains in the medium queue and is never updated with an end date. Clients Tested : i2b2 Web Client Environments Tested : Browsers: Not applicable for this test Databases: SQL Server and Oracle Client OS: Mac OS and Windows
Status	Testing [ 10002 ]	Testing [ 10002 ]

Janice Donahoe added a comment - 09/Apr/15 1:54 PM

See testing notes for more information on why the issue is reopened.

Janice Donahoe added a comment - 09/Apr/15 1:54 PM See testing notes for more information on why the issue is reopened.

Janice Donahoe made changes - 09/Apr/15 1:54 PM

Assignee	Janice Donahoe [ jmd86 ]	Mike Mendis [ mem61 ]
Status	Testing [ 10002 ]	Reopened [ 4 ]

Mike Mendis made changes - 13/Apr/15 9:23 AM

Status

Reopened [ 4 ]

In Progress [ 3 ]

Mike Mendis made changes - 13/Apr/15 9:23 AM

Assignee	Mike Mendis [ mem61 ]	Janice Donahoe [ jmd86 ]
Status	In Progress [ 3 ]	Ready to Test [ 10001 ]

Janice Donahoe made changes - 13/Apr/15 9:30 AM

Status

Ready to Test [ 10001 ]

Testing [ 10002 ]

Janice Donahoe made changes - 13/Apr/15 9:34 AM

Testing Notes	Test Date: 04/09/2015 Build Number: Test Status: Failed Test Comments: Tested with the latest web client build and it is not working correctly. The query never finishes running. It stays in a processing state. It will go from the small to medium queue but it does not appear to go from the medium to large queue. It remains in the medium queue and is never updated with an end date. Clients Tested : i2b2 Web Client Environments Tested : Browsers: Not applicable for this test Databases: SQL Server and Oracle Client OS: Mac OS and Windows	Test Date: 04/10/2015 Build Number: Test Status: Passed Test Comments: Tested with the latest web client build and it appears to be working correctly. The query is now running to completion and the status in Previous Queries is being updated correctly. Clients Tested : i2b2 Web Client Environments Tested : Browsers: Not applicable for this test Databases: SQL Server and Oracle Client OS: Mac OS and Windows ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Test Date: 04/09/2015 Build Number: Test Status: Failed Test Comments: Tested with the latest web client build and it is not working correctly. The query never finishes running. It stays in a processing state. It will go from the small to medium queue but it does not appear to go from the medium to large queue. It remains in the medium queue and is never updated with an end date. Clients Tested : i2b2 Web Client Environments Tested : Browsers: Not applicable for this test Databases: SQL Server and Oracle Client OS: Mac OS and Windows
Status	Testing [ 10002 ]	Testing [ 10002 ]

Janice Donahoe made changes - 13/Apr/15 9:34 AM

Resolution		Fixed [ 1 ]
Status	Testing [ 10002 ]	Resolved [ 5 ]

Janice Donahoe added a comment - 12/May/15 10:51 AM

Version 1.7.05 of the i2b2 Software has been released and is available for download on the i2b2 website (http://www.i2b2.org/software).

Janice Donahoe added a comment - 12/May/15 10:51 AM Version 1.7.05 of the i2b2 Software has been released and is available for download on the i2b2 website ( http://www.i2b2.org/software ).

Janice Donahoe made changes - 12/May/15 10:51 AM

Status

Resolved [ 5 ]

Closed [ 6 ]

Michael Horvath added a comment - 10/Jun/15 3:15 PM

I am still seeing this issue in 1.7.05 when a query tries to move into the medium queue.

2015-06-10 15:07:32,110 ERROR [edu.harvard.i2b2.crc.dao.CRCDAO] (Thread-141) Error while executing sql: java.sql.SQLException: IJ031013: Interrupted attempting lock: org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@5df04a03
        at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.tryLock(BaseWrapperManagedConnection.java:409)
        at org.jboss.jca.adapters.jdbc.WrappedConnection.lock(WrappedConnection.java:149)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.lock(WrappedStatement.java:114)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.executeUpdate(WrappedStatement.java:363)
        at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorHelperDao.executeQuery(QueryExecutorHelperDao.java:309)
        at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorDao.executeSQL(QueryExecutorDao.java:320)
        at edu.harvard.i2b2.crc.ejb.ExecRunnable.processQueryRequest(ExecRunnable.java:469)
        at edu.harvard.i2b2.crc.ejb.ExecRunnable.run(ExecRunnable.java:184)
        at java.lang.Thread.run(Thread.java:744)

Can consistently replicate by setting the small_queue timeout to 2s (modifying the thinClientName:'queryTimeout' key/value pair of js-i2b2/cells/CRC/cell_config_data.js in the webclient) and running a simple query.

Michael Horvath added a comment - 10/Jun/15 3:15 PM I am still seeing this issue in 1.7.05 when a query tries to move into the medium queue. 2015-06-10 15:07:32,110 ERROR [edu.harvard.i2b2.crc.dao.CRCDAO] (Thread-141) Error while executing sql: java.sql.SQLException: IJ031013: Interrupted attempting lock: org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@5df04a03 at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.tryLock(BaseWrapperManagedConnection.java:409) at org.jboss.jca.adapters.jdbc.WrappedConnection.lock(WrappedConnection.java:149) at org.jboss.jca.adapters.jdbc.WrappedStatement.lock(WrappedStatement.java:114) at org.jboss.jca.adapters.jdbc.WrappedStatement.executeUpdate(WrappedStatement.java:363) at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorHelperDao.executeQuery(QueryExecutorHelperDao.java:309) at edu.harvard.i2b2.crc.dao.setfinder.QueryExecutorDao.executeSQL(QueryExecutorDao.java:320) at edu.harvard.i2b2.crc.ejb.ExecRunnable.processQueryRequest(ExecRunnable.java:469) at edu.harvard.i2b2.crc.ejb.ExecRunnable.run(ExecRunnable.java:184) at java.lang.Thread.run(Thread.java:744) Can consistently replicate by setting the small_queue timeout to 2s (modifying the thinClientName:'queryTimeout' key/value pair of js-i2b2/cells/CRC/cell_config_data.js in the webclient) and running a simple query.

Janice Donahoe made changes - 06/Jul/15 3:45 PM

Resolution	Fixed [ 1 ]
Status	Closed [ 6 ]	Reopened [ 4 ]

Janice Donahoe made changes - 06/Jul/15 3:46 PM

Fix Version/s		1.7.06 [ 10200 ]
Fix Version/s	1.7.05 [ 10164 ]

Janice Donahoe made changes - 23/Jul/15 10:24 AM

Summary

JDBC calls to interrupted threads throw sqlexceptions

JDBC calls to interrupted threads throw sqlexceptions - Queries do not leave medium queue

Janice Donahoe made changes - 23/Jul/15 10:24 AM

Status

Reopened [ 4 ]

In Progress [ 3 ]

Janice Donahoe made changes - 23/Jul/15 10:25 AM

Developer Notes		Development done by Mike Mendis
Status	In Progress [ 3 ]	Ready to Test [ 10001 ]

Janice Donahoe made changes - 23/Jul/15 10:25 AM

Status

Ready to Test [ 10001 ]

Testing [ 10002 ]

Janice Donahoe made changes - 23/Jul/15 10:25 AM

Resolution		Fixed [ 1 ]
Status	Testing [ 10002 ]	Resolved [ 5 ]

Tom Morris added a comment - 23/Jul/15 6:20 PM

From memory, the core issue is that there's a bug in the logging code of the exception handler for the SQL processing. The "interrupted" exception goes through this path, but any other SQL error will as well. While disabling the interrupt call will handle the common case of queue timeout, any other SQL error will trigger the same behavior with all queue processing dying, requiring the server to be restarted.

Tom Morris added a comment - 23/Jul/15 6:20 PM From memory, the core issue is that there's a bug in the logging code of the exception handler for the SQL processing. The "interrupted" exception goes through this path, but any other SQL error will as well. While disabling the interrupt call will handle the common case of queue timeout, any other SQL error will trigger the same behavior with all queue processing dying, requiring the server to be restarted.

Janice Donahoe added a comment - 18/Aug/15 9:29 AM

The fix for this issue was included in the 1.7.06 release.

i2b2 version 1.7.06 was released on August 12, 2015.

Janice Donahoe added a comment - 18/Aug/15 9:29 AM The fix for this issue was included in the 1.7.06 release. i2b2 version 1.7.06 was released on August 12, 2015.

Janice Donahoe made changes - 18/Aug/15 9:29 AM

Status

Resolved [ 5 ]

Closed [ 6 ]

George Kowalski added a comment - 23/Jan/16 4:38 PM - edited

Should we still be seeing this error in 1.7.06 with Jobs going from the Medium to Long queue ? If so is there any effect on the i2b2 instance or does it function "Normally" ? Our instance is having issues where long running queries just never return , showing up as "PROCESSING". Sometimes they do so and there are result counts in the QT_QUERY_MASTER table ...

George Kowalski added a comment - 23/Jan/16 4:38 PM - edited Should we still be seeing this error in 1.7.06 with Jobs going from the Medium to Long queue ? If so is there any effect on the i2b2 instance or does it function "Normally" ? Our instance is having issues where long running queries just never return , showing up as "PROCESSING". Sometimes they do so and there are result counts in the QT_QUERY_MASTER table ...

Hubert Hickman added a comment - 10/Nov/16 2:05 PM

This bug still seems to happen both in 1.7.07 and 1.7.08 when jobs initially timeout and go into the medium queue. I'll enter another ticket to open it back up but noting here in cause it is the same issue.

Hubert Hickman added a comment - 10/Nov/16 2:05 PM This bug still seems to happen both in 1.7.07 and 1.7.08 when jobs initially timeout and go into the medium queue. I'll enter another ticket to open it back up but noting here in cause it is the same issue.

People

Assignee:: Janice Donahoe

Reporter:: Michael Horvath

Participant/s:: George Kowalski, Hubert Hickman, Janice Donahoe, Michael Horvath, Nathan Graham, Tom Morris

Votes:: 0 Vote for this issue

Watchers:: 10 Start watching this issue

Dates

Created:: 18/Sep/14 4:32 PM

Updated:: 10/Nov/16 2:05 PM

Resolved:: 23/Jul/15 10:25 AM

i2b2 Core Software

Details

Description

Attachments

Activity

People

Dates