[CWD-3688] Transaction errors due to cwd_token constraint violation

Type: Bug
Resolution: Fixed
Priority: Medium
Fix Version/s: 2.7.1
Affects Version/s: 2.7
Component/s: Database
Labels:
None

Bug Fix Policy:
View Atlassian Server bug fix policy

Customers are seeing issues with the token table – clashing primary keys and missing rows – that suggest concurrency issues remain after ~~CWD-2703~~.

Errors in the log include:

ERROR: current transaction is aborted, commands ignored until end of transaction block

is a regression of

CWD-2703 Hibernate StaleStateExceptions in Crowd

Closed

is related to

CWD-3697 Crowd token storage in database causing Crowd to hang

Closed

relates to

CWD-2703 Hibernate StaleStateExceptions in Crowd

Closed

was split into

CWD-3692 Crowd freezes under heavy load

Closed

mentioned in: Page Failed to load; Page Loading...; Page Loading...

(2 mentioned in)

Diego Berrueta added a comment - 23/Jan/2014 9:57 PM

Hi bie5466,

We're aware of the problem with Crowd 2.7.1, and we're investigating it in two new separate issues. Please watch and comment on ~~CWD-3768~~ and ~~CWD-3769~~.

Also, could you please follow the suggestion at https://jira.atlassian.com/browse/CWD-3768?focusedCommentId=561919&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-561919 and tell us if that change improves the stability of the server? Thank you.

Diego Berrueta added a comment - 23/Jan/2014 9:57 PM Hi bie5466 , We're aware of the problem with Crowd 2.7.1, and we're investigating it in two new separate issues. Please watch and comment on CWD-3768 and CWD-3769 . Also, could you please follow the suggestion at https://jira.atlassian.com/browse/CWD-3768?focusedCommentId=561919&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-561919 and tell us if that change improves the stability of the server? Thank you.

Volker Bier added a comment - 23/Jan/2014 9:34 AM

I am still seeing this with 2.7.1. Crowd completely hangs (already two times today), the complete server is unusable. It seems to be worse with 2.7.1. I had similar exceptions with 2.7.0, but the server did not hang.

The relevant log lines (with the username replaced):

2014-01-23 07:58:56,713 http-bio-8095-exec-363 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: 23505
2014-01-23 07:58:56,713 http-bio-8095-exec-363 ERROR [engine.jdbc.spi.SqlExceptionHelper] Batch entry 0 insert into cwd_token (directory_id, entity_name, random_number, identifier_hash, random_hash, created_date, last_accessed_date, last_accessed_time, duration, id) values ('1', '********', '8722680166496800442', 'QgE4HudsSA0Gv0PhzjRsqQ00', 'Nc0o9EUVDcT07dldsVoUgw00', '2014-01-23 07:58:56.694000 +01:00:00', '2014-01-23 07:58:56.694000 +01:00:00', '1390460336694', NULL, '7341482') was aborted.  Call getNextException to see the cause.
2014-01-23 07:58:56,713 http-bio-8095-exec-363 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: 23505
2014-01-23 07:58:56,713 http-bio-8095-exec-363 ERROR [engine.jdbc.spi.SqlExceptionHelper] ERROR: duplicate key value violates unique constraint "cwd_token_identifier_hash_key"
2014-01-23 07:58:56,714 http-bio-8095-exec-363 ERROR [jdbc.batch.internal.BatchingBatch] HHH000315: Exception executing batch [could not perform addBatch]

Ps shows this:

[root@pforge data]# ps -ef |grep crowd
crowd    17325     1 13 10:05 ?        00:02:22 /usr/bin/java -Djava.util.logging.config.file=/home/crowd/atlassian-crowd/apache-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Xms128m -Xmx512m -XX:MaxPermSize=256m -Dfile.encoding=UTF-8 -Djava.endorsed.dirs=/home/crowd/atlassian-crowd/apache-tomcat/endorsed -classpath /home/crowd/atlassian-crowd/apache-tomcat/bin/bootstrap.jar:/home/crowd/atlassian-crowd/apache-tomcat/bin/tomcat-juli.jar -Dcatalina.base=/home/crowd/atlassian-crowd/apache-tomcat -Dcatalina.home=/home/crowd/atlassian-crowd/apache-tomcat -Djava.io.tmpdir=/home/crowd/atlassian-crowd/apache-tomcat/temp org.apache.catalina.startup.Bootstrap start
postgres 17642  2055  0 10:08 ?        00:00:00 postgres: crowd crowd 127.0.0.1(56634) INSERT waiting
postgres 17789  2055  0 10:11 ?        00:00:00 postgres: crowd crowd 127.0.0.1(58664) idle in transaction
postgres 17839  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59299) idle       
postgres 17844  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59317) idle       
postgres 17868  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59571) idle       
postgres 17869  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59572) idle       
postgres 17871  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59586) idle       
postgres 17872  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59587) idle       
postgres 17873  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59685) idle       
postgres 17874  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59686) idle       
postgres 17875  2055  0 10:12 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59688) idle       
postgres 17901  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(59999) idle       
postgres 17902  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60001) idle       
postgres 17904  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60006) idle       
postgres 17905  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60008) idle       
postgres 17906  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60010) idle       
postgres 17915  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60020) idle in transaction
postgres 17917  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60021) idle       
postgres 17918  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60022) idle       
postgres 17921  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60071) idle       
postgres 17924  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60102) idle       
postgres 17927  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60107) idle       
postgres 17928  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60109) idle       
postgres 17929  2055  0 10:13 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60110) idle       
postgres 18026  2055  0 10:14 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60747) idle       
postgres 18049  2055  0 10:14 ?        00:00:00 postgres: crowd crowd 127.0.0.1(60839) idle       
postgres 18086  2055  0 10:15 ?        00:00:00 postgres: crowd crowd 127.0.0.1(32776) idle in transaction
postgres 18090  2055  0 10:15 ?        00:00:00 postgres: crowd crowd 127.0.0.1(32779) idle in transaction
postgres 18146  2055  0 10:15 ?        00:00:00 postgres: crowd crowd 127.0.0.1(33047) idle       
postgres 18207  2055  0 10:17 ?        00:00:00 postgres: crowd crowd 127.0.0.1(33678) idle in transaction
root     18751 16210  0 10:23 pts/1    00:00:00 grep crowd

Volker Bier added a comment - 23/Jan/2014 9:34 AM I am still seeing this with 2.7.1. Crowd completely hangs (already two times today), the complete server is unusable. It seems to be worse with 2.7.1. I had similar exceptions with 2.7.0, but the server did not hang. The relevant log lines (with the username replaced): 2014-01-23 07:58:56,713 http-bio-8095-exec-363 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: 23505 2014-01-23 07:58:56,713 http-bio-8095-exec-363 ERROR [engine.jdbc.spi.SqlExceptionHelper] Batch entry 0 insert into cwd_token (directory_id, entity_name, random_number, identifier_hash, random_hash, created_date, last_accessed_date, last_accessed_time, duration, id) values ( '1' , '********' , '8722680166496800442' , 'QgE4HudsSA0Gv0PhzjRsqQ00' , 'Nc0o9EUVDcT07dldsVoUgw00' , '2014-01-23 07:58:56.694000 +01:00:00' , '2014-01-23 07:58:56.694000 +01:00:00' , '1390460336694' , NULL, '7341482' ) was aborted. Call getNextException to see the cause. 2014-01-23 07:58:56,713 http-bio-8095-exec-363 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: 23505 2014-01-23 07:58:56,713 http-bio-8095-exec-363 ERROR [engine.jdbc.spi.SqlExceptionHelper] ERROR: duplicate key value violates unique constraint "cwd_token_identifier_hash_key" 2014-01-23 07:58:56,714 http-bio-8095-exec-363 ERROR [jdbc.batch.internal.BatchingBatch] HHH000315: Exception executing batch [could not perform addBatch] Ps shows this: [root@pforge data]# ps -ef |grep crowd crowd 17325 1 13 10:05 ? 00:02:22 /usr/bin/java -Djava.util.logging.config.file=/home/crowd/atlassian-crowd/apache-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Xms128m -Xmx512m -XX:MaxPermSize=256m -Dfile.encoding=UTF-8 -Djava.endorsed.dirs=/home/crowd/atlassian-crowd/apache-tomcat/endorsed -classpath /home/crowd/atlassian-crowd/apache-tomcat/bin/bootstrap.jar:/home/crowd/atlassian-crowd/apache-tomcat/bin/tomcat-juli.jar -Dcatalina.base=/home/crowd/atlassian-crowd/apache-tomcat -Dcatalina.home=/home/crowd/atlassian-crowd/apache-tomcat -Djava.io.tmpdir=/home/crowd/atlassian-crowd/apache-tomcat/temp org.apache.catalina.startup.Bootstrap start postgres 17642 2055 0 10:08 ? 00:00:00 postgres: crowd crowd 127.0.0.1(56634) INSERT waiting postgres 17789 2055 0 10:11 ? 00:00:00 postgres: crowd crowd 127.0.0.1(58664) idle in transaction postgres 17839 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59299) idle postgres 17844 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59317) idle postgres 17868 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59571) idle postgres 17869 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59572) idle postgres 17871 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59586) idle postgres 17872 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59587) idle postgres 17873 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59685) idle postgres 17874 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59686) idle postgres 17875 2055 0 10:12 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59688) idle postgres 17901 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(59999) idle postgres 17902 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60001) idle postgres 17904 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60006) idle postgres 17905 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60008) idle postgres 17906 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60010) idle postgres 17915 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60020) idle in transaction postgres 17917 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60021) idle postgres 17918 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60022) idle postgres 17921 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60071) idle postgres 17924 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60102) idle postgres 17927 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60107) idle postgres 17928 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60109) idle postgres 17929 2055 0 10:13 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60110) idle postgres 18026 2055 0 10:14 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60747) idle postgres 18049 2055 0 10:14 ? 00:00:00 postgres: crowd crowd 127.0.0.1(60839) idle postgres 18086 2055 0 10:15 ? 00:00:00 postgres: crowd crowd 127.0.0.1(32776) idle in transaction postgres 18090 2055 0 10:15 ? 00:00:00 postgres: crowd crowd 127.0.0.1(32779) idle in transaction postgres 18146 2055 0 10:15 ? 00:00:00 postgres: crowd crowd 127.0.0.1(33047) idle postgres 18207 2055 0 10:17 ? 00:00:00 postgres: crowd crowd 127.0.0.1(33678) idle in transaction root 18751 16210 0 10:23 pts/1 00:00:00 grep crowd

Bruno Ballekens added a comment - 13/Dec/2013 7:59 AM

Hi,

can you let us know when the 2.7.1 will be released ?
I'm having this almost every week ...

Bruno Ballekens added a comment - 13/Dec/2013 7:59 AM Hi, can you let us know when the 2.7.1 will be released ? I'm having this almost every week ...

Diego Berrueta added a comment - 18/Nov/2013 8:54 PM

Hi paul.grove,

We haven't announced a release date. We're working on it.

Diego Berrueta added a comment - 18/Nov/2013 8:54 PM Hi paul.grove , We haven't announced a release date. We're working on it.

Paul Grove added a comment - 18/Nov/2013 12:13 PM

Any news on when 2.7.1 will be released?

Paul Grove added a comment - 18/Nov/2013 12:13 PM Any news on when 2.7.1 will be released?

uvoellger added a comment - 22/Oct/2013 7:02 AM

For us, it seems not to be related to really heavy load. Viewing some standard Crowd views in several tabs lead to this problem in very short time.

uvoellger added a comment - 22/Oct/2013 7:02 AM For us, it seems not to be related to really heavy load. Viewing some standard Crowd views in several tabs lead to this problem in very short time.

uvoellger added a comment - 21/Oct/2013 7:19 AM

We checked this problem against Postgres 8.4, 9.0 and 9.2. The problem occurs in all versions.

We see this problem also if the requests come from Jira and Crowd in parallel during normal work (there is no need for Cmd-R or something else). Don't know which request finally creates the lock, but for the user, both Jira and Crowd stop working completely. So for us it is a showstopper to go to Crowd 2.7.

uvoellger added a comment - 21/Oct/2013 7:19 AM We checked this problem against Postgres 8.4, 9.0 and 9.2. The problem occurs in all versions. We see this problem also if the requests come from Jira and Crowd in parallel during normal work (there is no need for Cmd-R or something else). Don't know which request finally creates the lock, but for the user, both Jira and Crowd stop working completely. So for us it is a showstopper to go to Crowd 2.7.

Diego Berrueta added a comment - 21/Oct/2013 5:48 AM - edited

I've split ~~CWD-3692~~ as a related issue.

Diego Berrueta added a comment - 21/Oct/2013 5:48 AM - edited I've split CWD-3692 as a related issue.

Assignee:: Diego Berrueta

Reporter:: joe

Affected customers:: 3 This affects my team

Watchers:: 23 Start watching this issue

Created:: 16/Oct/2013 12:40 AM

Updated:: 27/Jan/2025 6:13 PM

Resolved:: 27/Oct/2013 9:45 PM

Details

Description

Attachments

Issue Links

Forms

Activity

Collapse comment: Diego Berrueta added a comment - 23/Jan/2014 9:57 PM

Expand comment: Diego Berrueta added a comment - 23/Jan/2014 9:57 PM

Collapse comment: Volker Bier added a comment - 23/Jan/2014 9:34 AM

Expand comment: Volker Bier added a comment - 23/Jan/2014 9:34 AM

Collapse comment: Bruno Ballekens added a comment - 13/Dec/2013 7:59 AM

Expand comment: Bruno Ballekens added a comment - 13/Dec/2013 7:59 AM

Collapse comment: Diego Berrueta added a comment - 18/Nov/2013 8:54 PM

Expand comment: Diego Berrueta added a comment - 18/Nov/2013 8:54 PM

Collapse comment: Paul Grove added a comment - 18/Nov/2013 12:13 PM

Expand comment: Paul Grove added a comment - 18/Nov/2013 12:13 PM

Collapse comment: uvoellger added a comment - 22/Oct/2013 7:02 AM

Expand comment: uvoellger added a comment - 22/Oct/2013 7:02 AM

Collapse comment: uvoellger added a comment - 21/Oct/2013 7:19 AM

Expand comment: uvoellger added a comment - 21/Oct/2013 7:19 AM

Collapse comment: Diego Berrueta added a comment - 21/Oct/2013 5:48 AM, Edited by Diego Berrueta - 22/Oct/2013 12:50 AM

Expand comment: Diego Berrueta added a comment - 21/Oct/2013 5:48 AM, Edited by Diego Berrueta - 22/Oct/2013 12:50 AM

People

Dates