Bug 1643813 - Managing tags fails with ConcurrentModificationException
Summary: Managing tags fails with ConcurrentModificationException
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 4.2.6
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ovirt-4.3.0
: 4.3.0
Assignee: Dana
QA Contact: Liran Rotenberg
URL:
Whiteboard:
Depends On:
Blocks: 1651132
TreeView+ depends on / blocked
 
Reported: 2018-10-29 04:20 UTC by Germano Veit Michel
Modified: 2022-03-13 16:11 UTC (History)
4 users (show)

Fixed In Version: ovirt-engine-4.3.0_alpha
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1651132 (view as bug list)
Environment:
Last Closed: 2019-05-08 12:38:47 UTC
oVirt Team: Infra
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHV-45207 0 None None None 2022-03-13 16:11:02 UTC
Red Hat Product Errata RHEA-2019:1085 0 None None None 2019-05-08 12:39:02 UTC
oVirt gerrit 95413 0 master MERGED engine: Use ConcurrentHashMap when adding tags 2020-11-27 14:58:20 UTC
oVirt gerrit 95508 0 ovirt-engine-4.2 MERGED engine: Use ConcurrentHashMap when adding tags 2020-11-27 14:57:55 UTC

Description Germano Veit Michel 2018-10-29 04:20:54 UTC
Description of problem:

Apparently 2 POST at the same time to manage VM tags, can result in java.util.ConcurrentModificationException.

[22/Oct/2018:15:03:02 +0200] "POST /ovirt-engine/api/vms/a6928c53-ed11-4d6f-afb0-63add888bb49/tags HTTP/1.1" 201 242
[22/Oct/2018:15:03:02 +0200] "POST /ovirt-engine/api/vms/a6928c53-ed11-4d6f-afb0-63add888bb49/tags HTTP/1.1" 500 128

So the second POST returned 500. Engine logs:

2018-10-22 15:03:02,937+02 ERROR [org.ovirt.engine.core.bll.GetAllTagsQuery] (default task-47) [34996d5c-4ebc-4eee-9f14-c67d3980158d] Exception: java.util.ConcurrentModificationException
        at java.util.HashMap$HashIterator.nextNode(HashMap.java:1442) [rt.jar:1.8.0_181]
        at java.util.HashMap$ValueIterator.next(HashMap.java:1471) [rt.jar:1.8.0_181]
        at org.ovirt.engine.core.utils.collections.CopyOnAccessMap.values(CopyOnAccessMap.java:155) [utils.jar:]
        at org.ovirt.engine.core.bll.TagsDirector.getAllTags(TagsDirector.java:334) [bll.jar:]
        at org.ovirt.engine.core.bll.GetAllTagsQuery.executeQueryCommand(GetAllTagsQuery.java:19) [bll.jar:]
        at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:106) [bll.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendQueryExecutor.execute(DefaultBackendQueryExecutor.java:14) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:538) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:507) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)

Other interesting logs around that time are:

1) Adding a new tag to the system:

2018-10-22 15:03:02,935+02 INFO  [org.ovirt.engine.core.bll.AddTagCommand] (default task-5) [ef7535d4-1212-403d-bcd2-45b3c284cfa2] Running command: AddTagCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group TAG_MANAGEMENT with role type ADMIN

2) Adding the just added tag to another VM

2018-10-22 15:03:03,136+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-17) [b25ad432-606f-4dff-80f0-2fe2f71ca099] EVENT_ID: USER_ATTACH_TAG_TO_VM(440), Tag xyz was attached to VM(s) abc by admin@internal-authz.

Version-Release number of selected component (if applicable):
rhvm-4.2.6.4-0.1.el7ev.noarch
ovirt-engine-restapi-4.2.6.4-0.1.el7ev.noarch

How reproducible:
- Randomly on customer site, apparently its rare given the number of calls.
- Did not reproduce in our labs

Steps to Reproduce:
- 2 thread python script adding and removing 2 tags in a loop did not reproduce it after 30min running.

Comment 3 Dana 2018-11-13 13:30:19 UTC
I wasn't able to reproduce the bug, but I added a fix that should solve this issue

Comment 5 Liran Rotenberg 2018-12-20 17:19:58 UTC
Verified on:
ovirt-engine-4.3.0-0.4.master.20181218200623.gitf1f0e41.el7.noarch
ovirt-engine-restapi-4.3.0-0.4.master.20181218200623.gitf1f0e41.el7.noarch

Steps:
1. Have a VM that has 4 tags assigned to it
2. Execute Jan's script against such VM: https://gist.github.com/jan-zmeskal/48585a5dbbef5b52cb28faac67a0a161
3. Keep it running for 30 or more minutes
4. Make sure that no error was raised during the script's execution
5. grep engine.log for "java.util.ConcurrentModificationException"

Results:
No exception were when running the script for 1 hour. 
No Error with "java.util.ConcurrentModificationException" were in the engine log.

Comment 7 errata-xmlrpc 2019-05-08 12:38:47 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2019:1085


Note You need to log in before you can comment on or make changes to this bug.