-
Bug
-
Resolution: Fixed
-
High
-
8.5.8, 7.13.18, 8.13.1
-
7.13
-
10
-
Severity 2 - Major
-
2
-
Issue Summary
Issue Type Screen Scheme does not reflect correctly on all node after the scheme is updated. The node who make the change contains the correct value, and even though the other nodes receive cache invalidation message, they display the incorrect previous value.
Steps to Reproduce
- Setup a 2 node DC cluster (I used Jira 8.5.8)
- Create a blank SCRUM project. This will create an issue type scheme: KEY: Scrum Issue Type Screen Scheme, with two issue type defined within: Default, and Bug
- You can setup TRACE logging on com.atlassian.jira.cluster.distribution.localq, com.atlassian.jira.cluster.distribution.localq.LocalQCacheManager, com.atlassian.jira.cluster.distribution.localq.LocalQCacheReplicator, net.sf.ehcache.distribution , and/or enable SQL log if you wish to review log as shared in the [Expected Results] section below
- Setup two browsers, and log in one browser to node 1, the other to node 2.
- Open Network Tools on each, then visit Network Tab and choose Disable cache, so that we always get the fresh page from the server
- Edit the Issue Type Screen Scheme, EG, http://NODE/secure/admin/ConfigureIssueTypeScreenScheme.jspa?id=10000 on each browser
- On node1, edit "Bug" to be the KEY: Scrum Default Screen Scheme
- Refresh page of node 1
- Refresh page of node 2
- Note that both nodes show the correct values
- Now on node 2, edit "Bug" to be the KEY: Scrum Bug Screen Scheme
- Refresh Node 1
- Note that Node 1 incorrectly shows KEY: Scrum Default Screen Scheme
- You can now refresh node 1 and node 2 as much as you want and the incorrect value will stick on Node 1
You do not have to switch change from Node 1, to Node 2. Even two sequential change on Node 1 will cause the bug, provided that the ConfigureIssueTypeScreenScheme is accessed on a different node in between changes
This is on an individual ITS Scheme basis. IE, if you change a scheme once, then change a different scheme once, both changes will apply to all nodes
This can be triggered with just a single change to the Issue Type Screen Scheme. The reproduction steps show multiple changes because this was the most reliable path to replicate the problem.
Expected Results
Both node 1 and node 2 show the same Screen Scheme configuration. In our test:
- Default = KEY: Scrum Default Screen Scheme
- Issue Type Bug = KEY: Scrum Bug Screen Scheme
When creating a new issue of type Bug in the relevant project, the fields shown are that of the scheme that was set. IE: Issue Type Bug will get fields for screen in KEY: Scrum Bug Screen Scheme
Actual Results
Node 1 incorrectly shows KEY: Scrum Default Screen Scheme.
When creating a new issue of type Bug in the relevant project, the fields shown are that of the incorrect Key: Scrum Default Screen Scheme
Cache Log: Node 1
Cache replication completes for the update on node1 - Done replicating cache to queues
Cache replication message is received fastly for the update on node2: RMICachePeer for cache com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache: remote remove received for key
tail -f atlassian-jira.log | grep -E "Done replicating cache to queues: com\.atlassian\.jira\.issue\.fields\.screen\.issuetype\.DefaultIssueTypeScreenSchemeManager\.schemeCache|remote remove received for key"
Click Edit on Node 1 Update to ASDF Scrum Default Screen Scheme on Node1.... 2020-11-24 03:23:39,515+0000 http-nio-8080-exec-8 TRACE admin 203x6873x1 g8fvop 192.168.48.1 /secure/admin/EditIssueTypeScreenSchemeEntity.jspa [c.a.j.c.distribution.localq.LocalQCacheReplicator] Done replicating cache to queues: com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache, operation: REMOVE, key: 10000, numberOfQueues: 1, timeMillis: 5, stacktrace: java.lang.Throwable Refresh Node 1.... Refresh Node 2.... Result: Node 2 matches Node1 Edit Node 2... Set to Scrum bug screeen scheme on Node 2 2020-11-24 03:25:45,076+0000 RMI TCP Connection(1971)-192.168.48.5 DEBUG [n.s.ehcache.distribution.RMICachePeer] RMICachePeer for cache com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache: remote remove received for key: 10001 Refresh node 1 Result = Node 1 shows incorrect "Scrum Default Screen Scheme". Node 2 shows correct Scrum Bug Screen Scheme
Cache Log: Node2
Cache replication message is received fastly for the update on node1: RMICachePeer for cache com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache: remote remove received for key .
Cache replication completes for the update on Node 2: replication completes for the update on node1 - Done replicating cache to queues
tail -f atlassian-jira.log | grep -E "Done replicating cache to queues: com\.atlassian\.jira\.issue\.fields\.screen\.issuetype\.DefaultIssueTypeScreenSchemeManager\.schemeCache|remote remove received for key"
Click Edit on Node 1 Update to ASDF Scrum Default Screen Scheme on Node1.... 2020-11-24 03:23:39,515+0000 RMI TCP Connection(2047)-192.168.48.3 DEBUG [n.s.ehcache.distribution.RMICachePeer] RMICachePeer for cache com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache: remote remove received for key: 10000 Refresh Node 1.... Refresh Node 2.... Result: Node 2 matches Node1 Edit Node 2... Set to Scrum bug screeen scheme on Node 2 2020-11-24 03:25:45,077+0000 http-nio-8080-exec-9 TRACE admin 205x5058x1 tnooso 192.168.48.1 /secure/admin/EditIssueTypeScreenSchemeEntity.jspa [c.a.j.c.distribution.localq.LocalQCacheReplicator] Done replicating cache to queues: com.atlassian.jira.issue.fields.screen.issuetype.DefaultIssueTypeScreenSchemeManager.schemeCache, operation: REMOVE, key: 10001, numberOfQueues: 1, timeMillis: 5, stacktrace: java.lang.Throwable Refresh node 1 Result = Node 1 shows incorrect "Scrum Default Screen Scheme". Node 2 shows correct Scrum Bug Screen Scheme
SQL Log: Node 1
At the first UPDATE occuring on Node 1, we can see the DB operation - UPDATE public.issuetypescreenschemeentity
After the second UPDATE, occuring on Node 2, we don't see any SELECT operation to refresh the cache from issuetypescreenschemeentity
tail -f atlassian-jira-sql.log | grep -i -P "(SELECT|INSERT|UPDATE|DELETE)+.*(fieldscreenscheme|issuetypescreenschemeentity|IssueTypeScreenScheme)+"
Click Edit on Node 1 2020-11-24 03:23:13,574+0000 http-nio-8080-exec-1 admin 203x6837x1 g8fvop /secure/admin/ViewEditIssueTypeScreenSchemeEntity.jspa 0ms "SELECT ID, NAME, DESCRIPTION FROM public.fieldscreenscheme ORDER BY NAME" Update to ASDF Scrum Default Screen Scheme on Node1.... 2020-11-24 03:23:39,505+0000 http-nio-8080-exec-8 admin 203x6873x1 g8fvop /secure/admin/EditIssueTypeScreenSchemeEntity.jspa 3ms "UPDATE public.issuetypescreenschemeentity SET ISSUETYPE='10102', SCHEME='10000', FIELDSCREENSCHEME='10000' WHERE ID='10101'" 2020-11-24 03:23:39,534+0000 http-nio-8080-exec-1 admin 203x6874x1 g8fvop /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT NAME, DESCRIPTION FROM public.issuetypescreenscheme WHERE ID='10000'" 2020-11-24 03:23:39,534+0000 http-nio-8080-exec-1 admin 203x6874x1 g8fvop /secure/admin/ConfigureIssueTypeScreenScheme.jspa 0ms "SELECT SOURCE_NODE_ID, SOURCE_NODE_ENTITY, SINK_NODE_ID, SINK_NODE_ENTITY, ASSOCIATION_TYPE, SEQUENCE FROM public.nodeassociation WHERE SOURCE_NODE_ENTITY='Project' AND SINK_NODE_ID='10000' AND SINK_NODE_ENTITY='IssueTypeScreenScheme' AND ASSOCIATION_TYPE='ProjectScheme'" 2020-11-24 03:23:39,536+0000 http-nio-8080-exec-1 admin 203x6874x1 g8fvop /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT ID, ISSUETYPE, SCHEME, FIELDSCREENSCHEME FROM public.issuetypescreenschemeentity WHERE SCHEME='10000'" Refresh Node 1.... 2020-11-24 03:23:57,832+0000 http-nio-8080-exec-9 admin 203x6910x1 g8fvop /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT SOURCE_NODE_ID, SOURCE_NODE_ENTITY, SINK_NODE_ID, SINK_NODE_ENTITY, ASSOCIATION_TYPE, SEQUENCE FROM public.nodeassociation WHERE SOURCE_NODE_ENTITY='Project' AND SINK_NODE_ID='10000' AND SINK_NODE_ENTITY='IssueTypeScreenScheme' AND ASSOCIATION_TYPE='ProjectScheme'" Refresh Node 2.... Result: Node 2 matches Node1 Edit Node 2... Set to Scrum bug screeen scheme on Node 2 Refresh node 1 2020-11-24 03:25:57,704+0000 http-nio-8080-exec-10 admin 205x6948x1 g8fvop /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT SOURCE_NODE_ID, SOURCE_NODE_ENTITY, SINK_NODE_ID, SINK_NODE_ENTITY, ASSOCIATION_TYPE, SEQUENCE FROM public.nodeassociation WHERE SOURCE_NODE_ENTITY='Project' AND SINK_NODE_ID='10000' AND SINK_NODE_ENTITY='IssueTypeScreenScheme' AND ASSOCIATION_TYPE='ProjectScheme'" Result = Node 1 shows incorrect "Scrum Default Screen Scheme". Node 2 shows correct Scrum Bug Screen Scheme
SQL Log: Node 2
After the first UPDATE occurred on Node 1, we refresh node 2, and see that it reads from the database - SELECT ID, ISSUETYPE, SCHEME, FIELDSCREENSCHEME FROM public.issuetypescreenschemeentity. This results in the Scheme displaying correcty
At the second UPDATE occuring on Node 2, we can see the DB operation - UPDATE public.issuetypescreenschemeentity
tail -f atlassian-jira-sql.log | grep -i -P "(SELECT|INSERT|UPDATE|DELETE)+.*(fieldscreenscheme|issuetypescreenschemeentity|IssueTypeScreenScheme)+"
Click Edit on Node 1 Update to ASDF Scrum Default Screen Scheme on Node1.... Refresh Node 1.... Refresh Node 2.... 2020-11-24 03:24:10,858+0000 http-nio-8080-exec-3 admin 204x4980x1 tnooso /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT NAME, DESCRIPTION FROM public.issuetypescreenscheme WHERE ID='10000'" 2020-11-24 03:24:10,859+0000 http-nio-8080-exec-3 admin 204x4980x1 tnooso /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT SOURCE_NODE_ID, SOURCE_NODE_ENTITY, SINK_NODE_ID, SINK_NODE_ENTITY, ASSOCIATION_TYPE, SEQUENCE FROM public.nodeassociation WHERE SOURCE_NODE_ENTITY='Project' AND SINK_NODE_ID='10000' AND SINK_NODE_ENTITY='IssueTypeScreenScheme' AND ASSOCIATION_TYPE='ProjectScheme'" 2020-11-24 03:24:10,861+0000 http-nio-8080-exec-3 admin 204x4980x1 tnooso /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT ID, ISSUETYPE, SCHEME, FIELDSCREENSCHEME FROM public.issuetypescreenschemeentity WHERE SCHEME='10000'" Result: Node 2 matches Node1 Edit Node 2... 2020-11-24 03:25:28,385+0000 http-nio-8080-exec-10 admin 205x5021x1 tnooso /secure/admin/ViewEditIssueTypeScreenSchemeEntity.jspa 0ms "SELECT ID, NAME, DESCRIPTION FROM public.fieldscreenscheme ORDER BY NAME" Set to Scrum bug screeen scheme on Node 2 2020-11-24 03:25:45,068+0000 http-nio-8080-exec-9 admin 205x5058x1 tnooso /secure/admin/EditIssueTypeScreenSchemeEntity.jspa 3ms "UPDATE public.issuetypescreenschemeentity SET ISSUETYPE='10102', SCHEME='10000', FIELDSCREENSCHEME='10001' WHERE ID='10101'" 2020-11-24 03:25:45,084+0000 http-nio-8080-exec-1 admin 205x5059x1 tnooso /secure/admin/ConfigureIssueTypeScreenScheme.jspa 1ms "SELECT SOURCE_NODE_ID, SOURCE_NODE_ENTITY, SINK_NODE_ID, SINK_NODE_ENTITY, ASSOCIATION_TYPE, SEQUENCE FROM public.nodeassociation WHERE SOURCE_NODE_ENTITY='Project' AND SINK_NODE_ID='10000' AND SINK_NODE_ENTITY='IssueTypeScreenScheme' AND ASSOCIATION_TYPE='ProjectScheme'" Refresh node 1 Result = Node 1 shows incorrect "Scrum Default Screen Scheme". Node 2 shows correct Scrum Bug Screen Scheme
Note on Cache Invalidation
If you wait without checking any of the ITS Screen Scheme pages for at least 30 minutes, and check again, the bad node will refresh it's value and display correctly. This may be due to the cache invalidation of 30 minute:
/jira/jira-components/jira-core/src/main/java/com/atlassian/jira/issue/fields/screen/issuetype/DefaultIssueTypeScreenSchemeManager.java
schemeCache = cacheManager.getCache(getClass().getName() + ".schemeCache", this::loadIssueTypeScreenScheme, new CacheSettingsBuilder().expireAfterAccess(30, TimeUnit.MINUTES).build());
Workaround
A rolling restart of the affected nodes will resolve each instance of the cache not updating.