Uploaded image for project: 'Jira Data Center'
  1. Jira Data Center
  2. JRASERVER-68174

Issue Create/Update action is slow when WebHooks are configured

XMLWordPrintable

      Summary

      Create Issue takes longer when there are configured WebHooks with Create Issue event.

      The WebHooks are fired asynchronously, but the logic that evaluates whether a WebHook should be called is synchronous and executes one JQL query per each configured WebHook.

      On instances that have problems with slow JQLs or with overly complicated WebHook filters configured, this can increase the time it takes to perform actions in Jira.

      Environment

      An environment where there are WebHooks with Create Issue event and with complex JQL queries.

      Expected Results

      When a customer creates an issue, they should swiftly see it's created on the UI. Slow JQLs configured for the WebHooks shouldn't impact the issue creation time.

      Actual Results

      The customer clicks on Create Issue, Issue is created and the logic determining which WebHooks to call is executed. After all JQL filters are executed, user sees the new issue in the UI and the actual WebHooks are called in separate background threads.

      Jira log:

      2018-10-26 05:15:47,287 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98453} AND {key in ("TEST-123")}' produced lucene query and took '59' ms to run.
2018-10-26 05:15:47,373 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98465} AND {key in ("TEST-123")}' produced lucene query and took '54' ms to run.
2018-10-26 05:15:48,491 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '955' ms to run.
2018-10-26 05:15:49,541 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "RGHT"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1050' ms to run.
2018-10-26 05:15:50,507 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '959' ms to run.
2018-10-26 05:15:51,630 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1123' ms to run.
2018-10-26 05:15:52,739 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1040' ms to run.
2018-10-26 05:15:53,773 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1019' ms to run.
2018-10-26 05:15:54,812 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '927' ms to run.
2018-10-26 05:15:55,752 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "GRSD"} AND {FILTER = 89511} AND {key in ("TEST-123")}' produced lucene query and took '940' ms to run.
2018-10-26 05:15:55,807 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98454} AND {key in ("TEST-123")}' produced lucene query and took '55' ms to run.
2018-10-26 05:15:55,862 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98452} AND {key in ("TEST-123")}' produced lucene query and took '54' ms to run.
2018-10-26 05:15:56,978 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1062' ms to run.
2018-10-26 05:15:58,400 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1313' ms to run.
2018-10-26 05:15:58,535 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98459} AND {key in ("TEST-123")}' produced lucene query and took '65' ms to run.
2018-10-26 05:15:59,709 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1075' ms to run.
2018-10-26 05:16:00,760 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1051' ms to run.
2018-10-26 05:16:01,841 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1080' ms to run.
2018-10-26 05:16:03,013 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1123' ms to run.
2018-10-26 05:16:12,856 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98453} AND {key in ("TEST-123")}' produced lucene query and took '65' ms to run.
2018-10-26 05:16:12,955 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXXX"} AND {filter = 98465} AND {key in ("TEST-123")}' produced lucene query and took '68' ms to run.
2018-10-26 05:16:14,022 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '938' ms to run.
 2018-10-26 05:16:14,919 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project =
 "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '896' ms to run.
2018-10-26 05:16:15,788 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '862' ms to run.
2018-10-26 05:16:16,721 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '932' ms to run.
2018-10-26 05:16:17,667 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '879' ms to run.
2018-10-26 05:16:18,564 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '884' ms to run.
2018-10-26 05:16:19,542 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '868' ms to run.
2018-10-26 05:16:20,451 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {FILTER = 89511} AND {key in ("TEST-123")}' produced lucene query and took '890' ms to run.
2018-10-26 05:16:20,573 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98452} AND {key in ("TEST-123")}' produced lucene query and took '72' ms to run.
2018-10-26 05:16:20,628 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98455} AND {key in ("TEST-123")}' produced lucene query and took '54' ms to run.
2018-10-26 05:16:21,569 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '932' ms to run.
2018-10-26 05:16:22,589 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '918' ms to run.
2018-10-26 05:16:23,752 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '940' ms to run.
2018-10-26 05:16:24,699 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '946' ms to run.
2018-10-26 05:16:25,632 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '932' ms to run.
2018-10-26 05:16:26,553 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '881' ms to run.
2018-10-26 05:16:26,670 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.h.s.task.impl.SendNotificationTask] Found 1 messages to send to HipChat
2018-10-26 05:16:26,721 http-nio-8090-exec-298 WARN UMercEu 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.o.scriptrunner.runner.ScriptRunnerImpl] EH3: Current PCF Status is null. New value is also the same, so not updating PCF Status field and its time aggregator.
2018-10-26 05:16:29,035 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98453} AND {key in ("TEST-123")}' produced lucene query and took '286' ms to run.
2018-10-26 05:16:29,091 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project in ("xxxxx", "xxxxxx")} AND {project = "xxxxx"} AND {status not in ("closed", "cancelled", "archived", "Done")} AND {component in ("xxxx", "xxxxx")} AND {key in ("TEST-123")}' produced lucene query and took '56' ms to run.
2018-10-26 05:16:29,153 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98465} AND {key in ("TEST-123")}' produced lucene query and took '60' ms to run.
2018-10-26 05:16:30,388 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1100' ms to run.
2018-10-26 05:16:31,383 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '994' ms to run.
2018-10-26 05:16:33,627 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1181' ms to run.
2018-10-26 05:16:34,785 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1096' ms to run.
2018-10-26 05:16:35,801 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1002' ms to run.
2018-10-26 05:16:36,946 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1023' ms to run.
2018-10-26 05:16:37,957 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {FILTER = 89511} AND {key in ("TEST-123")}' produced lucene query and took '1011' ms to run.
2018-10-26 05:16:38,011 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98454} AND {key in ("TEST-123")}' produced lucene query and took '53' ms to run.
2018-10-26 05:16:38,076 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "XXXXX"} AND {filter = 98452} AND {key in ("TEST-123")}' produced lucene query and took '64' ms to run.
2018-10-26 05:16:39,049 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '917' ms to run.
2018-10-26 05:16:40,044 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '878' ms to run.
2018-10-26 05:16:41,026 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '828' ms to run.
2018-10-26 05:16:41,854 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '827' ms to run.
2018-10-26 05:16:42,706 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '851' ms to run.
2018-10-26 05:16:43,622 http-nio-8090-exec-298 INFO XXXXXXXXX 315x2689003x27 cxcxcxccx XXXXXXXXXXXXX /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query '{project = "xxxx"} AND {filter = 89511} AND {key in ("TEST-123")}' produced lucene query and took '881' ms to run.

      Workaround

      No workaround if Webhooks will be used. But if the aim is to increase the performance of creating issue, then Webhooks should be disabled or JQLs should be tuned.

      Fix

      Asynchronous Webhooks were introduced in version 8.19.1, although it has some minor side effects (e.g. Jira shutdown may be delayed). We recommend using versions listed in "Fix Version/s" or newer. They should significantly improve the performance of Webhooks with complex JQL queries. To enable them:

      1. manually enable the "com.atlassian.jira.webhookEventsAsyncProcessing.enabled" feature flag with following instruction.
      2. restart your Jira instance (or each node in case of DC) 

        1. oie_G6x2BRf0mTm8.png
          oie_G6x2BRf0mTm8.png
          275 kB

            [JRASERVER-68174] Issue Create/Update action is slow when WebHooks are configured

            Roberto Martignano added a comment -

            Hello,

            on Jira 8.20.14 we still have a lot of the following logs:

            2023-07-26 12:23:05,028+0200 http-nio-8080-exec-43 INFO 742x4913511x13 1v5hypn /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query ' produced lucene query and took '103' ms to run.

            • When adding the fix should those logs disappear?

            We are not experiencing critical delays on issue create/update at the moment, so I was just wondering if it is helpful to activate the fix, and what happens after activating it.

            Thank you!

            Roberto Martignano added a comment - Hello, on Jira 8.20.14 we still have a lot of the following logs: 2023-07-26 12:23:05,028+0200 http-nio-8080-exec-43 INFO 742x4913511x13 1v5hypn /secure/CreateIssueDetails.jspa [c.a.j.p.webhooks.matcher.JqlEventMatcher_SLOW] JQL query ' produced lucene query and took '103' ms to run. When adding the fix should those logs disappear? We are not experiencing critical delays on issue create/update at the moment, so I was just wondering if it is helpful to activate the fix, and what happens after activating it. Thank you!

            Chand Chandrasegaram added a comment -

            Hi Team, This bug is affecting the performance of a large Jira DC (25k user base) of a UK bank. We would like to see this bug getting fixed and ported to 8.20.x version ASAP.  

            Chand Chandrasegaram added a comment - Hi Team, This bug is affecting the performance of a large Jira DC (25k user base) of a UK bank. We would like to see this bug getting fixed and ported to 8.20.x version ASAP.  

            Patryk Latkowski added a comment -

            Hi!
            We noted some unexpected behavior of asynchronous webhooks. For this reason, as of version 8.20.7, most events are set to synchronous processing, and the feature flag has been disabled by default. Even manually enabling the flag, asynchronous webhooks may not work as expected, so we decided to reopen this ticket. We are currently working on this issue and will try to solve it as soon as possible.

            Best regards,
            Patryk Latkowski
            Jira Server Developer 

            Patryk Latkowski added a comment - Hi! We noted some unexpected behavior of asynchronous webhooks. For this reason, as of version 8.20.7, most events are set to synchronous processing, and the feature flag has been disabled by default. Even manually enabling the flag, asynchronous webhooks may not work as expected, so we decided to reopen this ticket. We are currently working on this issue and will try to solve it as soon as possible. Best regards, Patryk Latkowski Jira Server Developer 

            David Yu added a comment -

            I got around to testing this on 8.20.X today (I didn't realize a feature flag + restart was required) and I still saw delays when I enabled a slow webhook query. Was this the reason it got re-opened again today?

            David Yu added a comment - I got around to testing this on 8.20.X today (I didn't realize a feature flag + restart was required) and I still saw delays when I enabled a slow webhook query. Was this the reason it got re-opened again today?

            Filipi Lima added a comment -

            https://getsupport.atlassian.com/browse/PS-83825

            Filipi Lima added a comment - https://getsupport.atlassian.com/browse/PS-83825

            Pablo added a comment -

            Hi

            I'm using post/get Rest API calls quite often for other integrations

            (based on events/post-functions/jobs in SR)

            and IMHO the performance impact is insensible

            Unfortunately In my case i need exactly same webhook (which looks exactly the same as webhook created via Jira) for integration with third party app

            and my biggest issue it to create it in the easiest way

            (https://community.atlassian.com/t5/Jira-Core-Server-questions/Webhooks-send-via-SR/qaq-p/1779672)

             

            At this moment I'm working at workaraund (which works for me) but I'm still verifying it's stability and performance

            Pablo added a comment - Hi I'm using post/get Rest API calls quite often for other integrations (based on events/post-functions/jobs in SR) and IMHO the performance impact is insensible Unfortunately In my case i need exactly same webhook (which looks exactly the same as webhook created via Jira) for integration with third party app and my biggest issue it to create it in the easiest way ( https://community.atlassian.com/t5/Jira-Core-Server-questions/Webhooks-send-via-SR/qaq-p/1779672)   At this moment I'm working at workaraund (which works for me) but I'm still verifying it's stability and performance

            Ganga Bopaiah added a comment -

            Hey pawel.gryzewski1 

            Do you have any samples of how to use scriptrunner to create JSON call instead of webhooks?

            This issue is getting on my nerves now.

            Would this issue impact Jira's performance in a long run? I don't want my system crashing owing to this issue.

            Ganga Bopaiah added a comment - Hey  pawel.gryzewski1   Do you have any samples of how to use scriptrunner to create JSON call instead of webhooks? This issue is getting on my nerves now. Would this issue impact Jira's performance in a long run? I don't want my system crashing owing to this issue.

            Pablo added a comment - - edited

            Few more info - maybe it'll help to investigate and more

             

            adding webhooks (with body) on updated event increeses time of sprint closing. For ex when you'll add few different webhooks on this event and you'll try to close sprint - closing time can even myltiply;/

             

            WORKARAOUD:

            User scriptrunner to create JSON call instead of webhooks (IMHO works without slowing down updating/creating issues)

             

            Pablo added a comment - - edited Few more info - maybe it'll help to investigate and more   adding webhooks (with body) on updated event increeses time of sprint closing. For ex when you'll add few different webhooks on this event and you'll try to close sprint - closing time can even myltiply;/   WORKARAOUD: User scriptrunner to create JSON call instead of webhooks (IMHO works without slowing down updating/creating issues)  

            Ganga Bopaiah added a comment -

            We nowhave end users complain about this, we are 8.5.5 and its still not fixed

            Ganga Bopaiah added a comment - We nowhave end users complain about this, we are 8.5.5 and its still not fixed

            Lady Glencora added a comment -

            Please fix this. It’s not a “feature.”

            Lady Glencora added a comment - Please fix this. It’s not a “feature.”

              3e387befff2c Patryk Latkowski
              ayanar Alp
              Affected customers:
              141 This affects my team
              Watchers:
              125 Start watching this issue

                Created:
                Updated:
                Resolved: