Data Center 8.2
Versions

Rule execution trace made easy

Troubleshoot automation rules

On this page

Related content

  • No related content found

Still need help?

The Atlassian Community is here for you.

Ask the community

Since Automation for Jira version 8.0.5, there is more information logged in the DEBUG level to easily trace event caused rule execution.

Setup

There are just three log categories that must be set up with the DEBUG level to have trace information available:

  • com.codebarrel.jira.plugin.automation.event - the category provides logs related to Jira event handling in A4J
  • com.codebarrel.jira.plugin.automation.queue - the category provides logs related to asynchronous rule execution supported by queue
  • com.codebarrel.automation.api.service - the category provides logs related to every rule execution

Find more information on setting up the logging level in this knowledge base article.

Below you can find an example automation rule that was used to demonstrate how A4J handles Jira events and executes rules:

The rule simply reacts to the issue created event and adds new comment under newly created issue.

Captured log

Here is the output captured from the main Jira log file when an issue was created in the project named SCRUM. The captured data was trimmed to have just 60 lines to make it easier to analyze. Some unimportant lines that appeared in the middle of the relevant payload were also removed. There were also additional three automation rules in the system that shouldn't react to the issue created. The log contains information how they are ignored.

The table below contains three columns, so use horizontal scroll to see the important comments.
No Content Comment
1
2022-10-13 09:31:51,705+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received Jira issue event bundle:
com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)
A4J built-in event listener is informed about new issue related event. 
The event is propagated as transaction aware event bundle 
(that might span information about multiple issue related events). 
A4J captures the event in the same 
client thread, the issue was created - 'http-nio-2990-exec-2'.
2
2022-10-13 09:31:51,705+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry received issue event bundle: 
com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)
The captured event 
(correlated by thread id and the event class - TxnAwareEventFactoryImpl) 
is passed to rule registry which contains relevant handlers.
3
2022-10-13 09:31:51,705+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry has extracted 1 event(s) from bundle.
Event handler in the rule registry extracted exactly one issue related event 
from the transaction aware bundle which was received from the listener.
4
2022-10-13 09:31:51,705+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry is handling issue event:
com.atlassian.jira.event.issue.IssueEvent@6f3952d6[
  issue=SCRUM-2,comment=<null>,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=1,
  sendMail=true,
  params={eventsource=workflow, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]
Here is information about details of the event being handled. 
The event relates to SCRUM-2 issue 
- exactly the one created to produce the exemplary log.
5
2022-10-13 09:31:51,711+0200 
JIRA-INFORM-Thread-4 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
PerformanceEvent{
  type=CONVERTING_TO_DB, 
  duration=6 ms, 
  success=true, 
  parameters={parameters.size=23}
}
A4J Jira event listener is working in the other threads as well, 
so there are other events captured in parallel.
This event is not related to the one being traced because log line comes 
from the other thread JIRA-INFORM-Thread-4.
6
2022-10-13 09:31:51,711+0200 
JIRA-INFORM-Thread-4 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
'PerformanceEvent{
  type=CONVERTING_TO_DB, 
  duration=6 ms, 
  success=true, 
  parameters={parameters.size=23}
}'
Another entry related to PerformanceEvent captured above 
(not related to the SCRUM-2 issue event being traced). 
There is no built-in event handler in A4J 
for such event, then 3rd party handlers are checked.
7
2022-10-13 09:31:51,722+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry executeEventRules init: 
traceId '31f8b301-e63d-4b2e-9e56-1dcb9145dfea' assigned, 
0 sync rules, 3 async rules found for 
event 'com.atlassian.jira.event.issue.IssueEvent@6f3952d6[
  issue=SCRUM-2,
  comment=<null>,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=1,
  sendMail=true,
  params={eventsource=workflow, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]'
Here goes important information 
- the traceId was generated for our event: '31f8b301-e63d-4b2e-9e56-1dcb9145dfea'.
It will be used for future references.Also there is information here that there 
are 3 asynchronous rules related to this event type and 0 synchronous rules. 
Because there is no synchronous rules, 
the event will be processed by automation queue only.
8
2022-10-13 09:31:51,722+0200 
http-nio-2990-exec-2 
DEBUG admin 571x8197x1 5auuyt 127.0.0.1 
/secure/QuickCreateIssue.jspa 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 'com.atlassian.jira.event.issue.IssueEvent@6f3952d6[
  issue=SCRUM-2,
  comment=<null>,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=1,
  sendMail=true,
  params={eventsource=workflow, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]'
This information says that there are no rules configured with 3rd party triggers 
that could be executed as reaction to traced event.
9
2022-10-13 09:31:51,732+0200 
automation-event-serializer:thread-1 
DEBUG admin 568x45x1 rwo96v 127.0.0.1 
/rest/api/2/issue 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Submitting AutomationEvent 'jira:issue_created:issue_created' 
with traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea' for asynchronous processing...
The Jira Event is transformed into Automation Event and submitted to
the automation queue by automation-event-serializer:thread-1 
- this is done off the client thread ('http-nio-2990-exec-2').
By submitting the event to automation queue Jira event handling phase ends. 
10
2022-10-13 09:31:51,736+0200 
automation-rule-executor:thread-5 
DEBUG      
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Started processing queue item: QueueItemBean{
  id=5, 
  auditItemId=null, 
  executionUuid=f2b9b149-58f3-4fa7-ba3e-5f8a0b072fbf, 
  ruleId=null, 
  priority=5, 
  created=2022-10-13 09:31:51.732, 
  claimant='automation-queue-claimer', 
  claimTime=2022-10-13 09:31:51.734, 
  payload='{
    "tenantContext":{
      "clientKey":"com.codebarrel.tenant.global",
      "environment":"prod",
      "tenantId":{"id":"00000000-0000-0000-0000-000000bbbbbb"}
  },
  "event":{
    "clientKey":"com.codebarrel.tenant.global",
    "triggerType":"EVENT",
    "type":"jira:issue_created:issue_...'
}
Automation executor thread ('automation-rule-executor:thread-5') 
is provided with new Automation Event obtained from the queue. 
There is no information that the event 
relates to the SCRUM-2 Jira issue so far. 
But the event type says it is "jira:issue_created:issue_..".
11
2022-10-13 09:31:51,736+0200 
automation-rule-executor:thread-5 
DEBUG      
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor is processing AutomationEvent 
with traceId=31f8b301-e63d-4b2e-9e56-1dcb9145dfea
Here is meaningfull information that the same 
executor thread (automation-rule-executor:thread-5) 
is handling event with traceId=31f8b301-e63d-4b2e-9e56-1dcb9145dfea.
So this is the same event we observed in the very first line of the log.
12
2022-10-13 09:31:51,737+0200 
automation-rule-executor:thread-5 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor found 3 rules for AutomationEvent 
with traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea'.
Automation executor performs final matching 
against available rules - only rules that are matching the 
Automation event and its project conditions will be executed. 
There are 3 rules configured, the thread will analyse.
13
2022-10-13 09:31:51,739+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Component can not handle: 
ComponentTypeKey{component=TRIGGER, type='jira.issue.event.trigger:commented'}
First rule rule starts with trigger 'on issue commented' 
and doesn't fit the Automation event being handled.
14
2022-10-13 09:31:51,740+0200 
automation-rule-executor:thread-5 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor postponed execution of Rule(id=4, name='comment to audit log') 
for AutomationEvent with traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea' 
because it doesn't fit the event.
Automation thread ignored the rule above.
15
2022-10-13 09:31:51,742+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Component can not handle: ComponentTypeKey{
  component=TRIGGER, 
  type='jira.issue.field.changed'
}
Second rule starts with trigger 'on field value changed' 
and doesn't fit the Automation event being handled.
16
2022-10-13 09:31:51,742+0200 
automation-rule-executor:thread-5 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor postponed execution 
of Rule(id=1, name='Global rule for description change') 
for AutomationEvent with traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea' 
because it doesn't fit the event.
Automation thread ignored the rule above.
17
2022-10-13 09:31:51,748+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Rule execution 'Global rule for Issue created' (rule ID [2], audit ID [7]) 
on tenant com.codebarrel.tenant.global 
and event traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea': STARTED
Third rule satisfies the Automation event, the this rule will be executed.
18
2022-10-13 09:31:51,748+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.ComponentChainImpl] 
Started executing component jira.issue.event.trigger:created. 
Rule ID [2], component ID [10], audit ID [7]
'Global rule for Issue created' execution starts.
19
2022-10-13 09:31:51,759+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.ComponentChainImpl] 
Completed executing component jira.issue.event.trigger:created. 
Rule ID [2], component ID [10], audit ID [7]
Execution of trigger component - this is just pass through execution.
20
2022-10-13 09:31:51,759+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.ComponentChainImpl] 
Started executing component jira.issue.comment. 
Rule ID [2], component ID [11], audit ID [7]
Start of execution of  'Add comment to issue' action.
21
2022-10-13 09:31:51,769+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.issue.IssueEventBundleFactoryImpl$(...)
Now the A4J event listener receives nested Jira event that was raised after 
the 'Global rule for Issue created' automation rule changed the issue.
Such nested events are propagated in the same thread that 
changed the issue - so the client thread now 
is 'automation-rule-executor:thread-5'.
In the next lines we will observe events posted 
after the issue was commented, and how A4J handles them. 
22
2022-10-13 09:31:51,769+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
com.atlassian.jira.event.issue.IssueEventBundleFactoryImpl$(...)
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in 
A4J handlers, so there is only option to handle them 
by rules with 3rd party triggers.
23
2022-10-13 09:31:51,769+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.comment.CommentCreatedEvent@1b01073f
Derived event capture (matched by 'automation-rule-executor:thread-5')
24
2022-10-13 09:31:51,769+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 'com.atlassian.jira.event.comment.CommentCreatedEvent@1b01073f'
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in A4J handlers, 
so there is only option to handle them by rules with 3rd party triggers.
25
2022-10-13 09:31:51,769+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.issue.DefaultIssueEventBundle@169d4436
Derived event capture (matched by 'automation-rule-executor:thread-5')
26
2022-10-13 09:31:51,770+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
com.atlassian.jira.event.issue.DefaultIssueEventBundle@169d4436
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in 
A4J handlers, so there is only option to handle them 
by rules with 3rd party triggers.
27
2022-10-13 09:31:51,771+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.issue.commit.OnCommitJiraIssueEventBuilder$(...)
Derived event capture (matched by 'automation-rule-executor:thread-5')
28
2022-10-13 09:31:51,771+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
com.atlassian.jira.event.issue.commit.OnCommitJiraIssueEventBuilder$(...)
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in 
A4J handlers, so there is only option to handle them 
by rules with 3rd party triggers.
29
2022-10-13 09:31:51,771+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.issue.commit.OnCommitJiraIssueEventBuilder$(...)
Derived event capture (matched by 'automation-rule-executor:thread-5')
30
2022-10-13 09:31:51,771+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
com.atlassian.jira.event.issue.commit.OnCommitJiraIssueEventBuilder$(...)
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in 
A4J handlers, so there is only option to handle them 
by rules with 3rd party triggers.
31
2022-10-13 09:31:51,771+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)
Derived event capture (matched by 'automation-rule-executor:thread-5')
32
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
'com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)'
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- generic event are not handled by built-in 
A4J handlers, so there is only option to handle them 
by rules with 3rd party triggers.
33
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received Jira issue event bundle:
com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)
Derived event capture (matched by 'automation-rule-executor:thread-5')
34
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry received issue event bundle: 
com.atlassian.jira.event.issue.txnaware.TxnAwareEventFactoryImpl$(...)
Derived event handling (matched by 'automation-rule-executor:thread-5') 
- this one is handled by built-in handler.
35
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry has extracted 1 event(s) from bundle.
The event bundle being handled provides one issue related event.
36
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry is handling issue event:
com.atlassian.jira.event.issue.IssueEvent@29d1132[
  issue=SCRUM-2,
  comment=com.atlassian.jira.issue.comments.CommentImpl@53cac860,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=6,
  sendMail=true,
  params={eventsource=action, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]
The event says that issue SCRUM-2 was commented. 
Notice that the thread is still the same 
that the rule was executed in ('automation-rule-executor:thread-5').
37
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry executeEventRules init: 
traceId '31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633' 
assigned, 
0 sync rules, 3 async rules found for event 
'com.atlassian.jira.event.issue.IssueEvent@29d1132[
  issue=SCRUM-2,
  comment=com.atlassian.jira.issue.comments.CommentImpl@53cac860,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=6,
  sendMail=true,
  params={eventsource=action, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]'
The nested traceId is generated for this event 
- the first part of it is exactly the same as for the initial event 
('31f8b301-e63d-4b2e-9e56-1dcb9145dfea').
Also there is the same type of information about 
initial match of rules (0 synchronous, 3 synchronous).
38
2022-10-13 09:31:51,772+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 'com.atlassian.jira.event.issue.IssueEvent@29d1132[
  issue=SCRUM-2,
  comment=com.atlassian.jira.issue.comments.CommentImpl@53cac860,
  worklog=<null>,
  changelog=<null>,
  eventTypeId=6,
  sendMail=true,
  params={eventsource=action, baseurl=http://localhost:2990/jira},
  subtasksUpdated=false,spanningOperation=Optional.empty
]'
No third party rules found for the nested event.
39
2022-10-13 09:31:51,778+0200 
JIRA-INFORM-Thread-0 
DEBUG anonymous 568x45x1 rwo96v 127.0.0.1 
/rest/api/2/issue [c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
PerformanceEvent{
  type=CONVERTING_TO_DB, 
  duration=4 ms, 
  success=true, 
  parameters={parameters.size=16}
}
In the meantime A4J Jira event listener is working 
on behalf of other Jira threads.
40
2022-10-13 09:31:51,778+0200 
JIRA-INFORM-Thread-0 
DEBUG anonymous 568x45x1 rwo96v 127.0.0.1 
/rest/api/2/issue 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 
'PerformanceEvent{
  type=CONVERTING_TO_DB, 
  duration=4 ms, 
  success=true, 
  parameters={parameters.size=16}
}'
The same context as above but the handler does its job.
41
2022-10-13 09:31:51,781+0200 
automation-event-serializer:thread-2 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Submitting AutomationEvent 'jira:issue_updated:issue_commented' 
with 
traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633' 
for asynchronous processing...
This is the event serializer job for the nested event 
which is submitted to the queue. 
Nested event handling phase ends here.
42
2022-10-13 09:31:51,782+0200 
JIRA-INFORM-Thread-0 
DEBUG anonymous 568x45x1 rwo96v 127.0.0.1 
/rest/api/2/issue 
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received generic event :
com.atlassian.jira.plugins.inform.api.events.OnEventBundleSave@4bfdd1e6
In the meantime A4J Jira event listener is working 
on behalf of other Jira threads.
43
2022-10-13 09:31:51,782+0200 
JIRA-INFORM-Thread-0 
DEBUG anonymous 568x45x1 rwo96v 127.0.0.1 
/rest/api/2/issue 
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 'com.atlassian.jira.plugins.inform.api.events.OnEventBundleSave@4bfdd1e6'
The same context as above but the handler does its job.
44
2022-10-13 09:31:51,785+0200 
automation-rule-executor:thread-6 
DEBUG      
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Started processing queue item: QueueItemBean{
  id=6, 
  auditItemId=null, 
  executionUuid=ac31f47a-2b53-405b-b918-d1d1693c0214, 
  ruleId=null, 
  priority=5, 
  created=2022-10-13 09:31:51.781, 
  claimant='automation-queue-claimer', 
  claimTime=2022-10-13 09:31:51.784, 
  payload='{"
    tenantContext":{
      "clientKey":"com.codebarrel.tenant.global",
      "environment":"prod",
      "tenantId":{"id":"00000000-0000-0000-0000-000000bbbbbb"}
    },
    "event":{
      "clientKey":"com.codebarrel.tenant.global",
      "triggerType":"EVENT",
      "type":"jira:issue_updated:issue_...'
}
Automation executor thread ('automation-rule-executor:thread-6') 
is provided with new Automation Event obtained 
from the queue - this is the nested one. 
There is no information that the event relates 
to the SCRUM-2 Jira issue so far. 
But the event type says it is "jira:issue_updated:issue_...".
45
2022-10-13 09:31:51,785+0200 
automation-rule-executor:thread-6 
DEBUG      
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor is processing AutomationEvent 
with 
traceId=31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633
This is strict information that the executor is dealing with the 
nested event raised after issue was commented 
(first part of traceId is 31f8b301-e63d-4b2e-9e56-1dcb9145dfea).
46
2022-10-13 09:31:51,786+0200 
automation-rule-executor:thread-6 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor found 3 rules for AutomationEvent 
with 
traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633'.
Executor reads rules for final matching ad will analyse them.
47
2022-10-13 09:31:51,788+0200 
automation-rule-executor:thread-6 
DEBUG admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Ignoring event 'EVENT:jira:issue_updated:issue_commented' 
since its author is the app user. 
This was most likely triggered by a previous rule execution.
Execution is ignored because A4J knows that the event is nested.
48
2022-10-13 09:31:51,788+0200 
automation-rule-executor:thread-6 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor postponed execution of Rule(id=4, name='comment to audit log') 
for AutomationEvent 
with 
traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633' 
because it doesn't fit the event.
The rule trigger doesn't fit the Automation Event type.
49
2022-10-13 09:31:51,792+0200 
automation-rule-executor:thread-6 
DEBUG admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Component can not handle: ComponentTypeKey{
  component=TRIGGER, 
  type='jira.issue.field.changed'
}
The rule trigger doesn't fit the Automation Event type.
50
2022-10-13 09:31:51,792+0200 
automation-rule-executor:thread-6 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor postponed execution of 
Rule(id=1, name='Global rule for description change') 
for AutomationEvent 
with 
traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633' 
because it doesn't fit the event.
The rule trigger doesn't fit the Automation Event type.
51
2022-10-13 09:31:51,793+0200 
automation-rule-executor:thread-6 
DEBUG admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Component can not handle: ComponentTypeKey{
  component=TRIGGER, 
  type='jira.issue.event.trigger:created'
}
The rule trigger doesn't fit the Automation Event type.
52
2022-10-13 09:31:51,793+0200 
automation-rule-executor:thread-6 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Async executor postponed execution of 
Rule(id=2, name='Global rule for Issue created') 
for AutomationEvent 
with 
traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea::efdc6e7c-b870-4793-a887-033efe905633' 
because it doesn't fit the event.
The rule trigger doesn't fit the Automation Event type.
53
2022-10-13 09:31:51,794+0200 
automation-rule-executor:thread-6 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 
Resolving queue item (in 9ms): QueueItemBean{
  id=6, 
  auditItemId=null, 
  executionUuid=ac31f47a-2b53-405b-b918-d1d1693c0214, 
  ruleId=null, 
  priority=5, 
  created=2022-10-13 09:31:51.781, 
  claimant='automation-queue-claimer', 
  claimTime=2022-10-13 09:31:51.784, 
  payload='{
    "tenantContext":{
      "clientKey":"com.codebarrel.tenant.global",
      "environment":"prod",
      "tenantId":{"id":"00000000-0000-0000-0000-000000bbbbbb"}
  },
  "event":{
    "clientKey":"com.codebarrel.tenant.global",
    "triggerType":"EVENT",
    "type":"jira:issue_updated:issue_...'
}
Automation executor thread ends the job for the nested event.
54
2022-10-13 09:31:51,810+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.JiraIssueEventListenerImpl] 
Received Jira issue property set event :
com.atlassian.jira.event.issue.property.IssuePropertySetEvent@6eb0d778
Here the additional info from the initial event executor 
- thread  'automation-rule-executor:thread-5', 
there are more nested event raised and captured by A4J listener again.
55
2022-10-13 09:31:51,810+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry received issue property event: 
com.atlassian.jira.event.issue.property.IssuePropertySetEvent@6eb0d778
Same as above but from handler's job.
56
2022-10-13 09:31:51,810+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry executeEventRules init: 
traceId '31f8b301-e63d-4b2e-9e56-1dcb9145dfea::cd66765b-44db-486d-bad6-5148977ef1d4' 
assigned, 
0 sync rules, 0 async rules found for event 
'com.atlassian.jira.event.issue.property.IssuePropertySetEvent@6eb0d778'
Same as above but from handler's job.
57
2022-10-13 09:31:51,810+0200 
automation-rule-executor:thread-5 
DEBUG admin     
[c.c.j.p.automation.event.DefaultEventRuleRegistry] 
Rule registry handleEventWithThirdPartyTriggers init: 0 3rd party rules found 
for event 'com.atlassian.jira.event.issue.property.IssuePropertySetEvent@6eb0d778'
Same as above but from handler's job.
58
2022-10-13 09:31:51,811+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.ComponentChainImpl] 
Completed executing component jira.issue.comment. 
Rule ID [2], component ID [11], audit ID [7]
Finish of execution of  'Add comment to issue' action
59
2022-10-13 09:31:51,812+0200 
automation-rule-executor:thread-5 
INFO admin     
[c.c.a.api.service.SingleRuleExecutorServiceImpl] 
Rule execution 'Global rule for Issue created' (rule ID [2], audit ID [7]) 
on tenant com.codebarrel.tenant.global 
and event traceId='31f8b301-e63d-4b2e-9e56-1dcb9145dfea': 
FINISHED (Took 65ms to run, 108ms end to end)
Finish of rule execution.
60
2022-10-13 09:31:51,820+0200 
automation-rule-executor:thread-5 
DEBUG anonymous     
[c.c.j.p.automation.queue.JiraAutomationQueueExecutor] 

Resolving queue item (in 85ms): QueueItemBean{
  id=5, 
  auditItemId=null, 
  executionUuid=f2b9b149-58f3-4fa7-ba3e-5f8a0b072fbf, 
  ruleId=null, 
  priority=5, 
  created=2022-10-13 09:31:51.732, 
  claimant='automation-queue-claimer', 
  claimTime=2022-10-13 09:31:51.734, 
  payload='{
    "tenantContext":{
      "clientKey":"com.codebarrel.tenant.global",
      "environment":"prod",
      "tenantId":{"id":"00000000-0000-0000-0000-000000bbbbbb"}
  },
  "event":{
    "clientKey":"com.codebarrel.tenant.global",
    "triggerType":"EVENT",
    "type":"jira:issue_created:issue_...'
}
Automation executor finished the job for initial Automation Event.

Event flow across automation threads

Last modified on Nov 22, 2022

Was this helpful?

Yes
No
Provide feedback about this article

Related content

  • No related content found
Powered by Confluence and Scroll Viewport.