[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Michael Schuetze (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16812632#comment-16812632
 ] 

Michael Schuetze commented on DERBY-7042:
-

{quote}I am trying to understand how to trip this bug, but so far I have not 
been able to make it occur. It runs without error for me.{quote}

After reading the comment chain, it seems you have figured it out. If you have 
any more questions feel free to let me know.

The actions are performed correctly, the timing for how long the actions take 
is what is wrong.

> Multiple triggers with rowLocking = false causes deadlock
> -
>
> Key: DERBY-7042
> URL: https://issues.apache.org/jira/browse/DERBY-7042
> Project: Derby
>  Issue Type: Bug
>  Components: Documentation, JDBC
>Affects Versions: 10.8.2.2, 10.8.3.0, 10.9.1.0, 10.10.1.1, 10.10.2.0, 
> 10.11.1.1, 10.12.1.1, 10.13.1.1, 10.14.1.0, 10.14.2.0, 10.15.1.3
> Environment: -- Java Information --
> Java Version:1.8.0_201
> Java Vendor: Oracle Corporation
> OS name: Linux
> OS architecture: i386
> OS version:  4.15.0-46-generic
> java.specification.name: Java Platform API Specification
> java.specification.version: 1.8
> java.runtime.version: 1.8.0_201-b09
> - Derby Information 
> [.../TriggerRepro/derby/derby-10.14.1.0.jar] 10.14.1.0 - (1808820)
>Reporter: Michael Schuetze
>Priority: Minor
>  Labels: documentation, performance
> Attachments: Derby7042.java, Derby7042.java
>
>
> Repro for the bug can be found here: 
> [https://github.com/mjschuetze102/TriggerRepro]
> Includes a detailed README of steps that show effect of bug as well as two 
> versions of the Derby database. 10.8.1.2, the last version where the bug was 
> not present and version 10.14.1.0, for easy access.
> This may just be an issue of not having enough documentation on database 
> Triggers (see Conclusions Based on Results)
> h2. Summary of Issue
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
>  # Executing Update trigger causes deadlock when there is an Insert or Delete 
> trigger
>  # Executing Insert trigger causes deadlock when there is a Delete trigger
>  # Executing Delete trigger does not cause deadlock
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
>  # While executing issue above, none of the triggers were terminated and 
> waitTimeout time was hit
> h2. Conclusions Based on Results
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
> Triggers seem to get into deadlock scenarios with any trigger defined after 
> itself. If this is the case, it should be documented somewhere that 
> rowLocking needs to be enabled to use the trigger feature if multiple 
> triggers would be used on the same database table.
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
> Based on documentation, I could not find any concrete evidence of whether 
> this is intended functionality.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Rick Hillegas (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16811686#comment-16811686
 ] 

Rick Hillegas commented on DERBY-7042:
--

Thanks for those suggestions, Bryan. Attaching a new version of Derby7042.java. 
This version adds another procedure which leaves more fingerprints in 
derby.log. I also updated the script with the following changes:

* Moved the property-setting out of the script and onto the VM boot command, 
just in case I'm misunderstanding when the properties take effect.

* Printed timestamps before and after the UPDATE statement.

* Increased the lock timeout to twice the length of the deadlock timeout.

* Performed two UPDATEs back-to-back.

I ran with the following trace properties:

{noformat}
  -Dderby.storage.rowLocking=false \
  -Dderby.locks.deadlockTimeout=5 \
  -Dderby.locks.waitTimeout=10 \
  -Dderby.locks.deadlockTrace=true \
  -Dderby.locks.monitor=true \
  -Dderby.language.logStatementText=true \
  -Dderby.stream.error.logSeverityLevel=0 \
{noformat}

The revised experiment discloses the following behavior:

* The INSERT takes 10 seconds to run, the length of the lock timeout. Looking 
inside derby.log, the 10 seconds elapse between the compilation and execution 
of the insert trigger. The trigger compilation and execution occur AFTER the 
execution of the INSERT statement.

* The first UPDATE takes 10 seconds to run, the length of the lock timeout. As 
with the INSERT statement, the 10 seconds elapse between the compilation and 
execution of the update trigger. The trigger compilation and execution occur 
AFTER the execution of the UPDATE statement.

* The second UPDATE executes immediately. There is no pause between the 
compilation and execution of the update trigger.

* There are no timeout or deadlock diagnostics in derby.log. However, there are 
transaction ids on the statements. It appears that the triggers are being 
compiled in the same transaction as their triggering statements.

Maybe, somehow, the table-level lock forced by derby.storage.rowLocking=false 
is interfering with the compilation of the triggers. The second execution goes 
fast because the triggers are already compiled and sitting in the statement 
cache.

Here is the revised script:

{noformat}
connect 'jdbc:derby:memory:db1;create=true';

-- create schema
CREATE TABLE ZooAnimals
(
Name VARCHAR(255),
Amount INT,
Feed BOOLEAN,
Zoo VARCHAR(255)
)
;

CREATE PROCEDURE helloDML(dml varchar(100))
  LANGUAGE JAVA
  EXTERNAL NAME 'Derby7042.helloDML'
  PARAMETER STYLE JAVA
  NO SQL
;

CREATE TRIGGER ZooUpdateTrigger
  AFTER UPDATE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('UPDATE')
;

CREATE TRIGGER ZooInsertTrigger
  AFTER INSERT ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('INSERT')
;

CREATE TRIGGER ZooDeleteTrigger
  AFTER DELETE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('DELETE')
;

-- populate table. this takes 10 seconds, the length of the lock timeout.
VALUES CURRENT_TIMESTAMP;
INSERT INTO ZooAnimals (Name, Amount, Feed, Zoo) VALUES ('Gorilla', 1, true, 
'Cincinnati');
VALUES CURRENT_TIMESTAMP;
SELECT * FROM ZooAnimals;

-- reboot to flush the statement cache.
connect 'jdbc:derby:memory:db1;shutdown=true';
connect 'jdbc:derby:memory:db1';

-- update table. the UPDATE takes 10 seconds, the length of the lock timeout.
VALUES CURRENT_TIMESTAMP;
UPDATE ZooAnimals SET Name = 'Aardvark' WHERE Zoo = 'Cincinnati';
VALUES CURRENT_TIMESTAMP;
SELECT * FROM ZooAnimals;

-- try it again. the UPDATE runs immediately.
VALUES CURRENT_TIMESTAMP;
UPDATE ZooAnimals SET Name = 'Alligator' WHERE Zoo = 'Cincinnati';
VALUES CURRENT_TIMESTAMP;
SELECT * FROM ZooAnimals;
{noformat}

Here is its output:

{noformat}
ij version 10.16
ij> connect 'jdbc:derby:memory:db1;create=true';
ij> -- create schema
CREATE TABLE ZooAnimals
(
Name VARCHAR(255),
Amount INT,
Feed BOOLEAN,
Zoo VARCHAR(255)
)
;
0 rows inserted/updated/deleted
ij> CREATE PROCEDURE helloDML(dml varchar(100))
  LANGUAGE JAVA
  EXTERNAL NAME 'Derby7042.helloDML'
  PARAMETER STYLE JAVA
  NO SQL
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooUpdateTrigger
  AFTER UPDATE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('UPDATE')
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooInsertTrigger
  AFTER INSERT ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('INSERT')
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooDeleteTrigger
  AFTER DELETE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloDML('DELETE')
;
0 rows inserted/updated/deleted
ij> -- populate table. this takes 10 seconds, the length of the lock timeout.
VALUES CURRENT_TIMESTAMP;
1
-
2019-04-06 12:57:55.049  

1 row selected
ij> INSERT INTO ZooAnimals (Name, Amount, Feed, Zoo) VALUES ('Gorilla', 1, 

[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Bryan Pendleton (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16811634#comment-16811634
 ] 

Bryan Pendleton commented on DERBY-7042:


Rick, can you tell from running those scripts in IJ whether the INSERT and 
UPDATE statements complete immediately, or whether they take 5 seconds, timeout 
(somewhere), and then complete? Can you arrange to have timestamped statement 
tracing in derby.log that would show whether the deadlockTimeout and/or 
waitTimeout are being reached or not?

> Multiple triggers with rowLocking = false causes deadlock
> -
>
> Key: DERBY-7042
> URL: https://issues.apache.org/jira/browse/DERBY-7042
> Project: Derby
>  Issue Type: Bug
>  Components: Documentation, JDBC
>Affects Versions: 10.8.2.2, 10.8.3.0, 10.9.1.0, 10.10.1.1, 10.10.2.0, 
> 10.11.1.1, 10.12.1.1, 10.13.1.1, 10.14.1.0, 10.14.2.0, 10.15.1.3
> Environment: -- Java Information --
> Java Version:1.8.0_201
> Java Vendor: Oracle Corporation
> OS name: Linux
> OS architecture: i386
> OS version:  4.15.0-46-generic
> java.specification.name: Java Platform API Specification
> java.specification.version: 1.8
> java.runtime.version: 1.8.0_201-b09
> - Derby Information 
> [.../TriggerRepro/derby/derby-10.14.1.0.jar] 10.14.1.0 - (1808820)
>Reporter: Michael Schuetze
>Priority: Minor
>  Labels: documentation, performance
> Attachments: Derby7042.java
>
>
> Repro for the bug can be found here: 
> [https://github.com/mjschuetze102/TriggerRepro]
> Includes a detailed README of steps that show effect of bug as well as two 
> versions of the Derby database. 10.8.1.2, the last version where the bug was 
> not present and version 10.14.1.0, for easy access.
> This may just be an issue of not having enough documentation on database 
> Triggers (see Conclusions Based on Results)
> h2. Summary of Issue
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
>  # Executing Update trigger causes deadlock when there is an Insert or Delete 
> trigger
>  # Executing Insert trigger causes deadlock when there is a Delete trigger
>  # Executing Delete trigger does not cause deadlock
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
>  # While executing issue above, none of the triggers were terminated and 
> waitTimeout time was hit
> h2. Conclusions Based on Results
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
> Triggers seem to get into deadlock scenarios with any trigger defined after 
> itself. If this is the case, it should be documented somewhere that 
> rowLocking needs to be enabled to use the trigger feature if multiple 
> triggers would be used on the same database table.
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
> Based on documentation, I could not find any concrete evidence of whether 
> this is intended functionality.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Rick Hillegas (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16811617#comment-16811617
 ] 

Rick Hillegas commented on DERBY-7042:
--

I am trying to understand how to trip this bug, but so far I have not been able 
to make it occur. I have extracted the following script from your repro and I 
have run the script against both the development trunk and the latest 10.15.1.3 
release. It runs without error for me. Could you take a look at this script and 
suggest how to make it demonstrate the problem you are seeing?

Thanks,
-Rick

Here is the script:

{noformat}
connect 'jdbc:derby:memory:db1;create=true';

CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.storage.rowLocking', 
'false');

CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.locks.deadlockTimeout', '5');

CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.locks.waitTimeout', '5');

-- create schema
CREATE TABLE ZooAnimals
(
Name VARCHAR(255),
Amount INT,
Feed BOOLEAN,
Zoo VARCHAR(255)
)
;

CREATE PROCEDURE helloWorld()
  LANGUAGE JAVA
  EXTERNAL NAME 'Derby7042.helloWorld'
  PARAMETER STYLE JAVA
  NO SQL
;

CREATE TRIGGER ZooUpdateTrigger
  AFTER UPDATE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;

CREATE TRIGGER ZooInsertTrigger
  AFTER INSERT ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;

CREATE TRIGGER ZooDeleteTrigger
  AFTER DELETE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;

-- populate table
INSERT INTO ZOOANIMALS (Name, Amount, Feed, Zoo) VALUES ('Gorilla', 1, true, 
'Cincinnati');
SELECT * FROM ZooAnimals;

-- reboot just in case the documentation lies about the properties being dynamic
connect 'jdbc:derby:memory:db1;shutdown=true';
connect 'jdbc:derby:memory:db1';

-- update table
UPDATE ZooAnimals SET Name = 'Aardvark' WHERE Zoo = 'Cincinnati';
SELECT * FROM ZooAnimals;
{noformat}

Here is the output of the script when run against 10.15.1.3:

{noformat}
ij version 10.15
ij> connect 'jdbc:derby:memory:db1;create=true';
ij> CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.storage.rowLocking', 
'false');
0 rows inserted/updated/deleted
ij> CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.locks.deadlockTimeout', 
'5');
0 rows inserted/updated/deleted
ij> CALL SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.locks.waitTimeout', '5');
0 rows inserted/updated/deleted
ij> -- create schema
CREATE TABLE ZooAnimals
(
Name VARCHAR(255),
Amount INT,
Feed BOOLEAN,
Zoo VARCHAR(255)
)
;
0 rows inserted/updated/deleted
ij> CREATE PROCEDURE helloWorld()
  LANGUAGE JAVA
  EXTERNAL NAME 'Derby7042.helloWorld'
  PARAMETER STYLE JAVA
  NO SQL
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooUpdateTrigger
  AFTER UPDATE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooInsertTrigger
  AFTER INSERT ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;
0 rows inserted/updated/deleted
ij> CREATE TRIGGER ZooDeleteTrigger
  AFTER DELETE ON ZOOANIMALS FOR EACH STATEMENT MODE DB2SQL
CALL helloWorld()
;
0 rows inserted/updated/deleted
ij> -- populate table
INSERT INTO ZOOANIMALS (Name, Amount, Feed, Zoo) VALUES ('Gorilla', 1, true, 
'Cincinnati');
Hello World
1 row inserted/updated/deleted
ij> SELECT * FROM ZooAnimals;
NAME
|AMOUNT |FEED |ZOO  

   
---
Gorilla 
|1  |true |Cincinnati   

   

1 row selected
ij> -- reboot just in case the documentation lies about the properties being 
dynamic
connect 'jdbc:derby:memory:db1;shutdown=true';
ERROR 08006: Database 'memory:db1' shutdown.
ij> connect 'jdbc:derby:memory:db1';
ij(CONNECTION1)> -- update table
UPDATE ZooAnimals SET Name = 'Aardvark' WHERE Zoo = 'Cincinnati';
Hello World
1 row inserted/updated/deleted
ij(CONNECTION1)> SELECT * FROM ZooAnimals;
NAME
|AMOUNT |FEED |ZOO  

   

[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Michael Schuetze (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16808741#comment-16808741
 ] 

Michael Schuetze commented on DERBY-7042:
-

The bug is that the Insert and Update times are hitting the full waitTimeout 
period. If you change it to 60 seconds, those times will be 60 seconds, if you 
set them to -1, the program will sit there forever without timing out. The 
operations themselves should take less than a second.

In versions of derby prior to 10.8.2.2, this operation would perform at the 
same speed as rowLocking set to true

> Multiple triggers with rowLocking = false causes deadlock
> -
>
> Key: DERBY-7042
> URL: https://issues.apache.org/jira/browse/DERBY-7042
> Project: Derby
>  Issue Type: Bug
>  Components: Documentation, JDBC
>Affects Versions: 10.8.2.2, 10.8.3.0, 10.9.1.0, 10.10.1.1, 10.10.2.0, 
> 10.11.1.1, 10.12.1.1, 10.13.1.1, 10.14.1.0, 10.14.2.0, 10.15.1.3
> Environment: -- Java Information --
> Java Version:1.8.0_201
> Java Vendor: Oracle Corporation
> OS name: Linux
> OS architecture: i386
> OS version:  4.15.0-46-generic
> java.specification.name: Java Platform API Specification
> java.specification.version: 1.8
> java.runtime.version: 1.8.0_201-b09
> - Derby Information 
> [.../TriggerRepro/derby/derby-10.14.1.0.jar] 10.14.1.0 - (1808820)
>Reporter: Michael Schuetze
>Priority: Minor
>  Labels: documentation, performance
> Attachments: Derby7042.java
>
>
> Repro for the bug can be found here: 
> [https://github.com/mjschuetze102/TriggerRepro]
> Includes a detailed README of steps that show effect of bug as well as two 
> versions of the Derby database. 10.8.1.2, the last version where the bug was 
> not present and version 10.14.1.0, for easy access.
> This may just be an issue of not having enough documentation on database 
> Triggers (see Conclusions Based on Results)
> h2. Summary of Issue
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
>  # Executing Update trigger causes deadlock when there is an Insert or Delete 
> trigger
>  # Executing Insert trigger causes deadlock when there is a Delete trigger
>  # Executing Delete trigger does not cause deadlock
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
>  # While executing issue above, none of the triggers were terminated and 
> waitTimeout time was hit
> h2. Conclusions Based on Results
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
> Triggers seem to get into deadlock scenarios with any trigger defined after 
> itself. If this is the case, it should be documented somewhere that 
> rowLocking needs to be enabled to use the trigger feature if multiple 
> triggers would be used on the same database table.
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
> Based on documentation, I could not find any concrete evidence of whether 
> this is intended functionality.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

[jira] [Commented] (DERBY-7042) Multiple triggers with rowLocking = false causes deadlock

[Rick Hillegas (JIRA)]

[ 
https://issues.apache.org/jira/browse/DERBY-7042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16808236#comment-16808236
 ] 

Rick Hillegas commented on DERBY-7042:
--

Attaching Derby7042.java--this is the Database.java class from the git site. I 
have simply renamed the class. When I run the repro, it produces the following 
output:

{noformat}
Hello World
Insert time: 15 seconds
Hello World
Update time: 15 seconds
Gorilla 3 true Cincinnati
Hello World
{noformat}

Can you explain how this is evidence of the bug? Thanks.

> Multiple triggers with rowLocking = false causes deadlock
> -
>
> Key: DERBY-7042
> URL: https://issues.apache.org/jira/browse/DERBY-7042
> Project: Derby
>  Issue Type: Bug
>  Components: Documentation, JDBC
>Affects Versions: 10.8.2.2, 10.8.3.0, 10.9.1.0, 10.10.1.1, 10.10.2.0, 
> 10.11.1.1, 10.12.1.1, 10.13.1.1, 10.14.1.0, 10.14.2.0, 10.15.1.3
> Environment: -- Java Information --
> Java Version:1.8.0_201
> Java Vendor: Oracle Corporation
> OS name: Linux
> OS architecture: i386
> OS version:  4.15.0-46-generic
> java.specification.name: Java Platform API Specification
> java.specification.version: 1.8
> java.runtime.version: 1.8.0_201-b09
> - Derby Information 
> [.../TriggerRepro/derby/derby-10.14.1.0.jar] 10.14.1.0 - (1808820)
>Reporter: Michael Schuetze
>Priority: Minor
>  Labels: documentation, performance
> Attachments: Derby7042.java
>
>
> Repro for the bug can be found here: 
> [https://github.com/mjschuetze102/TriggerRepro]
> Includes a detailed README of steps that show effect of bug as well as two 
> versions of the Derby database. 10.8.1.2, the last version where the bug was 
> not present and version 10.14.1.0, for easy access.
> This may just be an issue of not having enough documentation on database 
> Triggers (see Conclusions Based on Results)
> h2. Summary of Issue
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
>  # Executing Update trigger causes deadlock when there is an Insert or Delete 
> trigger
>  # Executing Insert trigger causes deadlock when there is a Delete trigger
>  # Executing Delete trigger does not cause deadlock
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
>  # While executing issue above, none of the triggers were terminated and 
> waitTimeout time was hit
> h2. Conclusions Based on Results
> *Having multiple triggers with {{'derby.storage.rowLocking', 'false'}} causes 
> issues with deadlocking*
> Triggers seem to get into deadlock scenarios with any trigger defined after 
> itself. If this is the case, it should be documented somewhere that 
> rowLocking needs to be enabled to use the trigger feature if multiple 
> triggers would be used on the same database table.
> *{{'derby.locks.deadlockTimeout'}} does not seem to work in above case*
> Based on documentation, I could not find any concrete evidence of whether 
> this is intended functionality.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)