Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1651132

Summary: [downstream clone - 4.2.8] Managing tags fails with ConcurrentModificationException
Product: Red Hat Enterprise Virtualization Manager Reporter: RHV bug bot <rhv-bugzilla-bot>
Component: ovirt-engineAssignee: Dana <delfassy>
Status: CLOSED ERRATA QA Contact: Jan Zmeskal <jzmeskal>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.2.6CC: lleistne, lsvaty, mgoldboi, mperina, ratamir, Rhev-m-bugs
Target Milestone: ovirt-4.2.8Keywords: ZStream
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: ovirt-engine-4.2.8.1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1643813 Environment:
Last Closed: 2019-01-22 12:44:51 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1643813    
Bug Blocks:    

Description RHV bug bot 2018-11-19 09:27:04 UTC 
+++ This bug is a downstream clone. The original bug is: +++
+++   bug 1643813 +++
======================================================================

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.

(Originally by Germano Veit Michel)
Comment 3 RHV bug bot 2018-11-19 09:27:15 UTC 
I wasn't able to reproduce the bug, but I added a fix that should solve this issue

(Originally by Dana Elfassy)
Comment 5 Jan Zmeskal 2018-12-11 15:10:54 UTC 
Verification steps:
1. Have a VM that has 4 tags assigned to it
2. Execute this simple 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"

If you don't want to read the referenced script, its main purpose is to constantly add and remove four tags on one VM in multi-threaded fashion. I am using ovirt-python-sdk v4 for this. If the SDK receives some different status code than 200, it raises an exception. To be completely sure, I also checked that "java.util.ConcurrentModificationException" is not found in engine.log.

Verified on:
rhvm-4.2.8-0.1.el7ev.noarch
ovirt-engine-restapi-4.2.8-0.1.el7ev.noarch
Comment 6 Dana 2018-12-17 16:46:42 UTC 
I ran the script for over an hour, no errors nor java.util.ConcurrentModificationException was found in the log, so I suppose it is safe to say that the fix had solved the issue
Comment 8 errata-xmlrpc 2019-01-22 12:44:51 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/RHBA-2019:0121