[jira] [Commented] (OPENJPA-2517) Incorrect the time unit of query timeout value.

["Heath Thomann (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/OPENJPA-2517?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14659426#comment-14659426 ] 

Heath Thomann commented on OPENJPA-2517:
----------------------------------------

OK, I have talked to Rick Curtis and Kevin Sutter about this some more and I have to add some more details and slightly back track.  This post is going to be extremely long, however, I want to add lots of details for history sake.  In this post I'm also going to do something that is probably very unorthodox, and that is I'm going to explain the way EclipseLink (ECL) handles the 'javax.persistence.query.timeout' (QT for short).  I know, I know, I shouldn't mix the two, however it appears that two major JPA providers are incorrectly handling the QT so I think it is worth pointing this out as it may also help to justify our final proposed handling of QT.  :)

I'd suggest the reader read the email I sent to Rick and Kevin for back ground [1].  This email details what OpenJPA is doing wrong when it comes to handling of the QT during a find/update scenario.  Basically OpenJPA does two things wrong:

1) It applies the "javax.persistence.query.timeout" value to a find/update (an EM operation).
2) It uses units of seconds, rather than milliseconds, in the find/update case.

As I explained back on May 27th, the spec is slightly vague about the application of QT.  But after a careful read, you can see that the QT should NOT apply to EM operations, only Query operations.  Therefore, #1 by OpenJPA (and ECL) is incorrect.  However, given that OpenJPA has applied the QT to EM operations since the inception of QT, we feel it is best to continue to do so.  We do not what to fix this and break all users who may directly or indirectly rely on this.  At some point we could add options to enable/disable this (although OpenJPA does allow a user to disable the QT.....actually this is the default value).   Also keep in mind that the JPA 2.0 and 2.1 specs both point out that the QT is just a hint, and a user should not completely depend on it, so I think there is further wiggle room for interpretation and implementation.  Furthermore, customer's have argued that the QT should apply to all operations; both EM and Query.  IMHO I agree with them.....it seems odd that one can control a timeout for a query, but NOT for an exactly same find/update operation.   
Next, given that we are not going to change things, we do feel we should address #2.  We do feel we should do as the originator of this JIRA suggested, that is, to properly convert the QT value in 'ConfiguringConnectionDecorator' to milliseconds, from seconds.  The DBDictionary converts the QT from milliseconds to seconds, the 'ConfiguringConnectionDecorator' should follow suite for consistency.


[1] Email to Kevin Sutter, Rick Curtis, et al.:
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>EMAIL START>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Hey Team!  I need help with a likely bug in OpenJPA (and ECL?) with our javax.persistence.query.timeout (QT for short) usage.  I know some of you worked on a QT issue on ECL.....my issue might also apply to ECL.  This issue takes a bit of time to describe so settle in with a cup of coffee or tea.  Basically though the root question is: should the QT apply to a finder+update (EM operation, no Query)?  If so both OJ and ECL have a bug.
To start, you could read my details in OJ2517, and look at the test.  But even these details aren't exactly the same as my latest issue.  In the JIRA the user was expecting the QT to apply to a EM.find/update scenario.  In other words, they expected the QT to apply to ALL EM operations.  However, as I explained in the JIRA the QT should only apply to javax.persistence.Query operations......Kevin's email [removed] seemed to back this up, the spec 'implies' this, and the TestQueryTimout test written by Pinaki would seem to offer further proof.  However, I've found a scenario where both OJ and ECL apply the QT to an EM.find/update.  Let me explain exactly what I mean by a 'EM.find/update' by using a code snippet to describe the scenario:

Thread 1 (T1) uses JDBC to 'lock' a row with id 1, in a table name Bug, and then sleeps, as follows:

int jdbcDelayTime = 9000;
Connection conn = .......     
Statement stmt = conn.createStatement();
stmt.execute("UPDATE Bug set title = 'a' where bugId = 1");
System.out.println("\nJDBC Thread will now sleep for " + jdbcDelayTime + " ms");
// emulate long process to hold lock on the row:
Thread.sleep(jdbcDelayTime); 

Thread 2 (T2) uses JPA to find entity Bug with id=1 and update it while T1 sleeps:

int jpaQueryTimeoutMillis = 6000;
//The QT is in units of milliseconds as per the spec:
props.put("javax.persistence.query.timeout", jpaQueryTimeoutMillis);
.....
em.getTransaction().begin();
Bug b = em.find(Bug.class, 1);
b.setTitle("update by find");            
//The 'commit' will hang waiting for the lock on the row:
em.getTransaction().commit();


With this test, you can see that the QT is set to 6000ms and T1 will sleep for 9000ms, in other words T1 will sleep longer than QT.  Because we are doing a find/update the QT will have no effect on the scenario (at least the allusion is it doesn't have an effect, as I'll explain in a moment).  Therefore the outcome is that T2 will wait until it gets the row lock (after about 9000ms) and after it gets the lock it will successfully update the entity.  If on the other hand, you change the find/update to something like the follow, On OpenJPA (but not ECL due to bug Bug 456067 ) would get a query timeout type of exception (QTE) after 6000ms:

            Query q = em.createQuery("UPDATE Bug o SET o.title = 'my title' where o.bugId = 1");
            q.executeUpdate();            
            em.getTransaction().commit();

So, at this time, all is as expected (assume we all agree that the QT should NOT have an effect on the find/update scenario) - expect for ECL in the query case due to Bug 456067 , however if I update the test to take into account ECL uses seconds I can get a QTE in the ECL case, so once ECL fixes the bug all will be the same for OJ and ECL.  
Next, I will explain why the scenario is giving the "allusion" that the find/update is not effected by the QT.  In the above find/update scenario, change 'jdbcDelayTime' from 9000ms to say 9000000ms (i.e. 9000 seconds).  Leave QT at 6000ms.  In this case, we will get a QTE after approx. 6000 seconds.  Yes, 6000 seconds, NOT milliseconds.  In the Query scenario, the results are the same, we'd get a QTE after 6 seconds.  Therefore, for a Query, life is good and the QT is behaving properly.  However, for the find/update scenario, I think we have to ask ourselves two questions:

1) Why is the QT having an effect on the find/update (and should it)?
2) Why is the QT being treated as seconds, rather than ms, in the find/update case.

For #1, I won't go into a ton of details at this time since this note is getting so long, but basically 'ConfiguringConnectionDecorator' does a 'setQueryTimeout' during the prepare and create of a statement.  So the timeout would seem to be set on the statement ALWAYS, regardless of whether a query is performed or find/update.  Furthermore, the value is not divided by 1000 (i.e. not converted from ms, to seconds, so the QT value is treated as seconds in this case).  This would explain why there is the 'allusion' that the QT has no effect on a find/update scenario when the QT is larger than the JDBC sleep time in my scenario.....because we *think* we are setting the QT in millis, yet seconds are actually used by the JDBC driver, it seems like the ST has no effect......it is only when the QT is less than the JDBC sleep time that we see the QT does actually have an effect on the find/update case.  Now, in the case of a Query, there are places where we call 'setQueryTimeout' on the Statement a seconds time.  One such place is the JDBCStoreQuery which calls the dictionary which in turn calls 'setQueryTimeout'.  In this case, the QT is divided by 1000 to convert the JPA spec defined QT units of millis to the JDBC expected units of seconds.  Therefore, in the query case, the QT is properly handled (well at least for OJ, not for ECL).    
In conclusion, I'd say we have a bug here either way and one of the following options needs to be taken (for OpenJPA): 
a) if the QT should not effect the find/update, then we need to detect this path and not call 'setQueryTimeout' in the 'ConfiguringConnectionDecorator'.
b) If the QT should effect the find/update, then we need to convert from millis to seconds.

Phew.....thoughts?  I'd be glad to discuss this on the phone if that would be easier.

Thanks,

Heath
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>EMAIL END>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Thanks,

Heath Thomann

> Incorrect the time unit of query timeout value.
> -----------------------------------------------
>
>                 Key: OPENJPA-2517
>                 URL: https://issues.apache.org/jira/browse/OPENJPA-2517
>             Project: OpenJPA
>          Issue Type: Bug
>          Components: jdbc
>    Affects Versions: 2.2.0, 2.2.1, 2.2.2, 2.3.0
>            Reporter: Masafumi Koba
>            Assignee: Heath Thomann
>         Attachments: OPENJPA-2517.patch, openjpa-querytimeout-bug.zip, openjpa-querytimeout-working.zip
>
>
> The value of the "javax.persistence.query.timeout" property have been passed to the java.sql.Statement.setQueryTimeout(int) in milliseconds rather than seconds.
> The query timeout milliseconds should be converted to seconds.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)