[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

View 4 older comments

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.

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.

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