Hello,
we have a Jira 7.13 Instance (see *1)) that makes extensive use of apps, scripting and automations.
It rarely has more than 5 users working on it concurrently but the actions they perform are quite load-intensive.
When the load on the system rises we sometimes get Exceptions like this:
2021-04-20 16:35:43,129 http-nio-127.0.0.1-8080-exec-193 ERROR s.xxxxx 995x540616x1 1cy303 217.239.225.203,127.0.0.1 /secure/CommentAssignIssue.jspa [c.o.s.jira.workflow.AbstractScriptWorkflowFunction] Script function failed on issue: WB-48741, actionId: 31, file: null
com.atlassian.jira.exception.DataAccessException: org.ofbiz.core.entity.GenericDataSourceException: SQL Exception while executing the following:SELECT pkey, issuenum, PROJECT, REPORTER, ASSIGNEE, CREATOR, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM public.jiraissue WHERE ID=? (ERROR: current transaction is aborted, commands ignored until end of transaction block)
Full Exception: here
Starting with this exception every SQL call the system makes within this web request fails.
I want to understand better what is happening there.
My Interpreation so far:
ERROR: current transaction is aborted, commands ignored until end of transaction block)
The current database transaction was aborted in Postgres. Therefore Postgres doesnt execute any selects or other sql statements any more until a new transaction is started.
My Question:
Who requested to abort the transaction? There is nothing suspicious in the atlassian-jira.log above this exception.
Did Postgres abort the transaction? Or did Jira order Postgres to do so?
Whoever did it, why does it do that?
Edit
It seems to be related to this error message that appears in the postgresql-9.6-main.log
This message always preceeds the occurrences of the other "Transaction aborted" Exceptions
2021-04-19 07:00:37.776 CEST [3324] jira@jiradb ERROR: canceling statement due to user request
2021-04-19 07:00:37.776 CEST [3324] jira@jiradb CONTEXT: while updating tuple (504,154) in relation "AO_60DB71_LEXORANK"
2021-04-19 07:00:37.776 CEST [3324] jira@jiradb STATEMENT: UPDATE public."AO_60DB71_LEXORANK" SET "LOCK_HASH" = $1, "LOCK_TIME" = $2 WHERE "ID" IN ($3, $4) AND ("LOCK_HASH" IS NULL OR "LOCK_TIME" < $5)
Context information
- When we encounter this the load is mostly increased, e.g. above 7
- But i also had one case now where the server load was only 1.5
- something you can do to provoke this is created a lot of issues.
In this case we created 86 issues within 156 seconds in one web request (using script runner for jira to implement a file import) and then 60 more in the next web request within 130 seconds - Postgres Version is 9.6
- Postgres and Jira are running on the same Ubuntu 18.04 machine with 4 cores, 15 GB RAM
- I used the optimizer at pgtune.leopard.in.ua to generate the memory config for Postgres using the settings "6GB RAM, 2 CPUs, SSD storage, Postgres 9.6)
- Jira is configured not to use more than 5GB of heap memory
- I think one reason the issues take relatively long to create is that the app "Stagil Asset Relations" is used intensivly and slows down the issue creation (also see this question)
- When these import issues are created we made sure not to trigger more automations once the issue is created.
*1) im am aware the instance is beyond it's EOL, an upgrade is planned but we cannot update the instance on short notice because of other requirements with higher priority in this project
Bounty
To resolve this issue we would be willing to pay some of your work.
Mention me to contact me about that.
