You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@groovy.apache.org by acefael <es...@acefael.es> on 2015/11/13 11:44:23 UTC
Sql Concurrency Issue?
hi Guillaume, hi Everyone,
first: thanks for making Groovy! It simply is great!
I am using groovy.sql.Sql with a commons dbcp2 BasicDataSource and am encountering a stacktrace as in [2] below. I do create many identical closures with different data, and I pass them all at once to ExecutorService.invokeAll. The closures are all using the same Sql instance.
I believe this is a race condition because it happens only when the database is over a network, and not when the database is local.
To work around I can set Sql.cacheNamedQueries = false. Problem is reliably gone in this case. So I guess the culprit is in [1], with my sql already being cached in namedParamSqlCache, but not yet in namedParamIndexPropCache?
Yours,
acefael
[1] the line in the source code
https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L4407
[2] the stacktrace
java.lang.NullPointerException
at java.util.ArrayList.<init>(ArrayList.java:168) ~[?:1.8.0]
at groovy.sql.Sql.buildSqlWithIndexedProps(Sql.java:4422) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql.checkForNamedParams(Sql.java:4369) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql.getPreparedStatement(Sql.java:4360) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql.getPreparedStatement(Sql.java:4439) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql.execute(Sql.java:2366) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql.execute(Sql.java:2438) ~[groovy-all-2.4.5.jar:2.4.5]
at groovy.sql.Sql$execute$1.call(Unknown Source) ~[?:?]
at es.acefael.BaseMigration.execute(BaseMigration.groovy:2017) ~[es-acefael-dostuff-SNAPSHOT.jar:?]
Re: Sql Concurrency Issue?
Posted by Jochen Theodorou <bl...@gmx.org>.
On 14.11.2015 01:33, John Wagenleitner wrote:
> Hi acefael,
>
> Probably would be good to open a JIRA for this, definitely looks like an
> issue with the block of code you identified. I do believe the general
> intent of the Sql class is to be thread safe.
If the class is made to be thread safe, then it will need quite a bit
work on the synchronization. As it is now, it is far from threadsafe.
That already starts with the multiple locks in use and if that is really
correct - multiple locks in methods calling each other can easily create
deadlocks for example.
bye blackdrag
Re: Sql Concurrency Issue?
Posted by acefael <es...@acefael.es>.
hi John,
i raised https://issues.apache.org/jira/browse/GROOVY-7673
i never call close() at all, still the NPE occurs frequently,
but not always, while executing the closures. it's really
easy to reproduce; code block is on the ticket.
let me know if i can be of further help.
acefael
On Fri, Nov 13, 2015 at 04:33:16PM -0800, John Wagenleitner wrote:
> Hi acefael,
>
> Probably would be good to open a JIRA for this, definitely looks like an
> issue with the block of code you identified. I do believe the general
> intent of the Sql class is to be thread safe. As Pascal pointed out, there
> might be other issues if calls are made to methods that cause a cached
> connection. But at a quick glance the caching of the parsed named
> parameter queries looks separate from connection and statement caching.
>
> Are you calling sql.close() from any of the closures? Just wondering since
> close() clears both maps.
>
> John
>
> [1]
> https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L3517
>
> On Fri, Nov 13, 2015 at 2:02 PM, Pascal Schumacher <pascalschumacher@gmx.net
> > wrote:
>
> >
> > Hi acefael,
> >
> > I guess there could be concurrency problems with SQL and chaching, because
> > Findbugs also generates some warnings:
> >
> > IS Inconsistent synchronization of groovy.sql.Sql.cacheConnection; locked
> > 84% of time
> >
> > Bug type IS2_INCONSISTENT_SYNC (click for details)
> > <http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
> > In class groovy.sql.Sql
> > Field groovy.sql.Sql.cacheConnection
> > Synchronized 84% of the time
> > Unsynchronized access at Sql.java:[line 4160]
> > Unsynchronized access at Sql.java:[line 4181]
> > Unsynchronized access at Sql.java:[line 4245]
> > Synchronized access at Sql.java:[line 3516]
> > Synchronized access at Sql.java:[line 3517]
> > Synchronized access at Sql.java:[line 3547]
> > Synchronized access at Sql.java:[line 3549]
> > Synchronized access at Sql.java:[line 3550]
> > Synchronized access at Sql.java:[line 3547]
> > Synchronized access at Sql.java:[line 3549]
> > Synchronized access at Sql.java:[line 3550]
> > Synchronized access at Sql.java:[line 3491]
> > Synchronized access at Sql.java:[line 3492]
> > Synchronized access at Sql.java:[line 3498]
> > Synchronized access at Sql.java:[line 3500]
> > Synchronized access at Sql.java:[line 3498]
> > Synchronized access at Sql.java:[line 3501]
> > Synchronized access at Sql.java:[line 3500]
> > Synchronized access at Sql.java:[line 3501]
> > IS Inconsistent synchronization of groovy.sql.Sql.cacheStatements; locked
> > 53% of time
> >
> > Bug type IS2_INCONSISTENT_SYNC (click for details)
> > <http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
> > In class groovy.sql.Sql
> > Field groovy.sql.Sql.cacheStatements
> > Synchronized 53% of the time
> > Unsynchronized access at Sql.java:[line 3479]
> > Unsynchronized access at Sql.java:[line 4160]
> > Unsynchronized access at Sql.java:[line 4181]
> > Unsynchronized access at Sql.java:[line 4228]
> > Unsynchronized access at Sql.java:[line 4338]
> > Unsynchronized access at Sql.java:[line 4216]
> > Synchronized access at Sql.java:[line 3469]
> > Synchronized access at Sql.java:[line 3835]
> > Synchronized access at Sql.java:[line 3836]
> > Synchronized access at Sql.java:[line 3842]
> > Synchronized access at Sql.java:[line 3844]
> > Synchronized access at Sql.java:[line 3842]
> > Synchronized access at Sql.java:[line 3844]
> >
> > I do not know if they are related to your problem.
> >
> > -Pascal
> >
> >
> > Am 13.11.2015 um 11:44 schrieb acefael:
> >
> > hi Guillaume, hi Everyone,
> >
> > first: thanks for making Groovy! It simply is great!
> >
> > I am using groovy.sql.Sql with a commons dbcp2 BasicDataSource and am encountering a stacktrace as in [2] below. I do create many identical closures with different data, and I pass them all at once to ExecutorService.invokeAll. The closures are all using the same Sql instance.
> >
> > I believe this is a race condition because it happens only when the database is over a network, and not when the database is local.
> >
> > To work around I can set Sql.cacheNamedQueries = false. Problem is reliably gone in this case. So I guess the culprit is in [1], with my sql already being cached in namedParamSqlCache, but not yet in namedParamIndexPropCache?
> >
> > Yours,
> > acefael
> >
> >
> >
> > [1] the line in the source code
> > https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L4407
> >
> > [2] the stacktrace
> >
> > java.lang.NullPointerException
> > at java.util.ArrayList.<init>(ArrayList.java:168) ~[?:1.8.0]
> > at groovy.sql.Sql.buildSqlWithIndexedProps(Sql.java:4422) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql.checkForNamedParams(Sql.java:4369) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql.getPreparedStatement(Sql.java:4360) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql.getPreparedStatement(Sql.java:4439) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql.execute(Sql.java:2366) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql.execute(Sql.java:2438) ~[groovy-all-2.4.5.jar:2.4.5]
> > at groovy.sql.Sql$execute$1.call(Unknown Source) ~[?:?]
> > at es.acefael.BaseMigration.execute(BaseMigration.groovy:2017) ~[es-acefael-dostuff-SNAPSHOT.jar:?]
> >
> >
> >
> >
> >
Re: Sql Concurrency Issue?
Posted by John Wagenleitner <jo...@gmail.com>.
Hi acefael,
Probably would be good to open a JIRA for this, definitely looks like an
issue with the block of code you identified. I do believe the general
intent of the Sql class is to be thread safe. As Pascal pointed out, there
might be other issues if calls are made to methods that cause a cached
connection. But at a quick glance the caching of the parsed named
parameter queries looks separate from connection and statement caching.
Are you calling sql.close() from any of the closures? Just wondering since
close() clears both maps.
John
[1]
https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L3517
On Fri, Nov 13, 2015 at 2:02 PM, Pascal Schumacher <pascalschumacher@gmx.net
> wrote:
>
> Hi acefael,
>
> I guess there could be concurrency problems with SQL and chaching, because
> Findbugs also generates some warnings:
>
> IS Inconsistent synchronization of groovy.sql.Sql.cacheConnection; locked
> 84% of time
>
> Bug type IS2_INCONSISTENT_SYNC (click for details)
> <http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
> In class groovy.sql.Sql
> Field groovy.sql.Sql.cacheConnection
> Synchronized 84% of the time
> Unsynchronized access at Sql.java:[line 4160]
> Unsynchronized access at Sql.java:[line 4181]
> Unsynchronized access at Sql.java:[line 4245]
> Synchronized access at Sql.java:[line 3516]
> Synchronized access at Sql.java:[line 3517]
> Synchronized access at Sql.java:[line 3547]
> Synchronized access at Sql.java:[line 3549]
> Synchronized access at Sql.java:[line 3550]
> Synchronized access at Sql.java:[line 3547]
> Synchronized access at Sql.java:[line 3549]
> Synchronized access at Sql.java:[line 3550]
> Synchronized access at Sql.java:[line 3491]
> Synchronized access at Sql.java:[line 3492]
> Synchronized access at Sql.java:[line 3498]
> Synchronized access at Sql.java:[line 3500]
> Synchronized access at Sql.java:[line 3498]
> Synchronized access at Sql.java:[line 3501]
> Synchronized access at Sql.java:[line 3500]
> Synchronized access at Sql.java:[line 3501]
> IS Inconsistent synchronization of groovy.sql.Sql.cacheStatements; locked
> 53% of time
>
> Bug type IS2_INCONSISTENT_SYNC (click for details)
> <http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
> In class groovy.sql.Sql
> Field groovy.sql.Sql.cacheStatements
> Synchronized 53% of the time
> Unsynchronized access at Sql.java:[line 3479]
> Unsynchronized access at Sql.java:[line 4160]
> Unsynchronized access at Sql.java:[line 4181]
> Unsynchronized access at Sql.java:[line 4228]
> Unsynchronized access at Sql.java:[line 4338]
> Unsynchronized access at Sql.java:[line 4216]
> Synchronized access at Sql.java:[line 3469]
> Synchronized access at Sql.java:[line 3835]
> Synchronized access at Sql.java:[line 3836]
> Synchronized access at Sql.java:[line 3842]
> Synchronized access at Sql.java:[line 3844]
> Synchronized access at Sql.java:[line 3842]
> Synchronized access at Sql.java:[line 3844]
>
> I do not know if they are related to your problem.
>
> -Pascal
>
>
> Am 13.11.2015 um 11:44 schrieb acefael:
>
> hi Guillaume, hi Everyone,
>
> first: thanks for making Groovy! It simply is great!
>
> I am using groovy.sql.Sql with a commons dbcp2 BasicDataSource and am encountering a stacktrace as in [2] below. I do create many identical closures with different data, and I pass them all at once to ExecutorService.invokeAll. The closures are all using the same Sql instance.
>
> I believe this is a race condition because it happens only when the database is over a network, and not when the database is local.
>
> To work around I can set Sql.cacheNamedQueries = false. Problem is reliably gone in this case. So I guess the culprit is in [1], with my sql already being cached in namedParamSqlCache, but not yet in namedParamIndexPropCache?
>
> Yours,
> acefael
>
>
>
> [1] the line in the source code
> https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L4407
>
> [2] the stacktrace
>
> java.lang.NullPointerException
> at java.util.ArrayList.<init>(ArrayList.java:168) ~[?:1.8.0]
> at groovy.sql.Sql.buildSqlWithIndexedProps(Sql.java:4422) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.checkForNamedParams(Sql.java:4369) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.getPreparedStatement(Sql.java:4360) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.getPreparedStatement(Sql.java:4439) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.execute(Sql.java:2366) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.execute(Sql.java:2438) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql$execute$1.call(Unknown Source) ~[?:?]
> at es.acefael.BaseMigration.execute(BaseMigration.groovy:2017) ~[es-acefael-dostuff-SNAPSHOT.jar:?]
>
>
>
>
>
Re: Sql Concurrency Issue?
Posted by Pascal Schumacher <pa...@gmx.net>.
Hi acefael,
I guess there could be concurrency problems with SQL and chaching,
because Findbugs also generates some warnings:
IS Inconsistent synchronization of groovy.sql.Sql.cacheConnection;
locked 84% of time
Bug type IS2_INCONSISTENT_SYNC (click for details)
<http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
In class groovy.sql.Sql
Field groovy.sql.Sql.cacheConnection
Synchronized 84% of the time
Unsynchronized access at Sql.java:[line 4160]
Unsynchronized access at Sql.java:[line 4181]
Unsynchronized access at Sql.java:[line 4245]
Synchronized access at Sql.java:[line 3516]
Synchronized access at Sql.java:[line 3517]
Synchronized access at Sql.java:[line 3547]
Synchronized access at Sql.java:[line 3549]
Synchronized access at Sql.java:[line 3550]
Synchronized access at Sql.java:[line 3547]
Synchronized access at Sql.java:[line 3549]
Synchronized access at Sql.java:[line 3550]
Synchronized access at Sql.java:[line 3491]
Synchronized access at Sql.java:[line 3492]
Synchronized access at Sql.java:[line 3498]
Synchronized access at Sql.java:[line 3500]
Synchronized access at Sql.java:[line 3498]
Synchronized access at Sql.java:[line 3501]
Synchronized access at Sql.java:[line 3500]
Synchronized access at Sql.java:[line 3501]
IS Inconsistent synchronization of groovy.sql.Sql.cacheStatements;
locked 53% of time
Bug type IS2_INCONSISTENT_SYNC (click for details)
<http://ci.groovy-lang.org/repository/download/Groovy_CoverageIndyRuntime/29803:id/subprojects/groovy-sql/target/reports/findbugs/main.html#IS2_INCONSISTENT_SYNC>
In class groovy.sql.Sql
Field groovy.sql.Sql.cacheStatements
Synchronized 53% of the time
Unsynchronized access at Sql.java:[line 3479]
Unsynchronized access at Sql.java:[line 4160]
Unsynchronized access at Sql.java:[line 4181]
Unsynchronized access at Sql.java:[line 4228]
Unsynchronized access at Sql.java:[line 4338]
Unsynchronized access at Sql.java:[line 4216]
Synchronized access at Sql.java:[line 3469]
Synchronized access at Sql.java:[line 3835]
Synchronized access at Sql.java:[line 3836]
Synchronized access at Sql.java:[line 3842]
Synchronized access at Sql.java:[line 3844]
Synchronized access at Sql.java:[line 3842]
Synchronized access at Sql.java:[line 3844]
I do not know if they are related to your problem.
-Pascal
Am 13.11.2015 um 11:44 schrieb acefael:
> hi Guillaume, hi Everyone,
>
> first: thanks for making Groovy! It simply is great!
>
> I am using groovy.sql.Sql with a commons dbcp2 BasicDataSource and am encountering a stacktrace as in [2] below. I do create many identical closures with different data, and I pass them all at once to ExecutorService.invokeAll. The closures are all using the same Sql instance.
>
> I believe this is a race condition because it happens only when the database is over a network, and not when the database is local.
>
> To work around I can set Sql.cacheNamedQueries = false. Problem is reliably gone in this case. So I guess the culprit is in [1], with my sql already being cached in namedParamSqlCache, but not yet in namedParamIndexPropCache?
>
> Yours,
> acefael
>
>
>
> [1] the line in the source code
>
> https://github.com/apache/incubator-groovy/blob/GROOVY_2_4_X/subprojects/groovy-sql/src/main/java/groovy/sql/Sql.java#L4407
>
> [2] the stacktrace
>
> java.lang.NullPointerException
> at java.util.ArrayList.<init>(ArrayList.java:168) ~[?:1.8.0]
> at groovy.sql.Sql.buildSqlWithIndexedProps(Sql.java:4422) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.checkForNamedParams(Sql.java:4369) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.getPreparedStatement(Sql.java:4360) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.getPreparedStatement(Sql.java:4439) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.execute(Sql.java:2366) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql.execute(Sql.java:2438) ~[groovy-all-2.4.5.jar:2.4.5]
> at groovy.sql.Sql$execute$1.call(Unknown Source) ~[?:?]
> at es.acefael.BaseMigration.execute(BaseMigration.groovy:2017) ~[es-acefael-dostuff-SNAPSHOT.jar:?]
>
>