Bug 987825

Summary: [rhevm] - Network - Error in engine when creating new VM (MAC_POOL_NOT_INITIALIZED - code 5011 [after using rhevm-sdk])
Product: Red Hat Enterprise Virtualization Manager Reporter: David Botzer <dbotzer>
Component: ovirt-engineAssignee: Mike Kolesnik <mkolesni>
Status: CLOSED CURRENTRELEASE QA Contact: Martin Pavlik <mpavlik>
Severity: high Docs Contact:
Priority: high    
Version: 3.3.0CC: acathrow, amureini, gklein, iheim, lpeer, lyarwood, masayag, myakove, pstehlik, Rhev-m-bugs, yeylon
Target Milestone: ---Keywords: Reopened
Target Release: 3.3.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: network
Fixed In Version: IS14 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-02-10 07:44:00 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Network RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
rhevm logs
none
python script
none
engine none

Description David Botzer 2013-07-24 08:54:35 UTC 
Created attachment 777665 [details]
rhevm logs

Description of problem:
[rhevm] - Network - Error in engine when creating new VM (MAC_POOL_NOT_INITIALIZED - code 5011)

I Try to use rhevm-sdk to create VM but failed,
Later on I could not create VMs via webadmin - Error in engine when creating new VM - 
MAC_POOL_NOT_INITIALIZED (Failed with VDSM error MAC_POOL_NOT_INITIALIZED a
nd code 5011)

Version-Release number of selected component (if applicable):
3.3/is6

How reproducible:
always

Steps to Reproduce:
1.Install rhevm+dwh+reports
2.Create new vm using rhevm-sdk script (create new vm using python)
3.Create new VM via webadmin & examine the logs

Actual results:
Gets Error with insufficient info, Gets error in engine.log 

 - MAC_POOL_NOT_INITIALIZED - code 5011
 - Error while executing action:
aaaaa:
    General command validation failure.

Expected results:
Should allow creation of VMs

Additional info:
Using rhevm-sdk
4.12. Example: Creating a Virtual Machine using Python
-----------------
http://documentation-devel.engineering.redhat.com/docs/en-US/Red_Hat_Enterprise_Virtualization/3.3/html/Developer_Guide/index.html

My MacPoolRange is
00:1A:4A:23:A1:00-00:1A:4A:23:A1:FF
Comment 1 David Botzer 2013-07-24 08:57:58 UTC 
Created attachment 777668 [details]
python script
Comment 2 David Botzer 2013-07-24 09:03:30 UTC 
Created attachment 777669 [details]
engine
Comment 3 David Botzer 2013-07-24 09:16:19 UTC 
he engine.log contains: 

2013-07-21 11:30:47,386 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-4-thread-1) Start initializing MacPoolManager
2013-07-21 11:30:47,435 INFO  [org.ovirt.engine.core.bll.InitBackendServicesOnStartupBean] (ServerService Thread Pool -- 40) Init VM custom properties utilities
2013-07-21 11:30:47,452 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-4-thread-1) Finished initializing MacPoolManager

and later on 
2013-07-23 12:11:17,419 ERROR [org.ovirt.engine.core.bll.network.MacPoolManager] (ajp-/127.0.0.1:8702-9) The MAC addresses pool is not initialized
2013-07-23 12:11:17,424 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp-/127.0.0.1:8702-9) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Mac Address Pool is not initialized. Failed to get available Macs count.
Comment 4 Itamar Heim 2013-08-22 09:37:44 UTC 
*** Bug 989403 has been marked as a duplicate of this bug. ***
Comment 5 Itamar Heim 2013-08-22 09:38:15 UTC 
*** Bug 987798 has been marked as a duplicate of this bug. ***
Comment 6 Itamar Heim 2013-08-28 15:12:05 UTC 
could this be something similar to http://gerrit.ovirt.org/#/c/18655/?
Comment 7 Allon Mureinik 2013-08-28 16:21:49 UTC 
(In reply to Itamar Heim from comment #6)
> could this be something similar to http://gerrit.ovirt.org/#/c/18655/?
Doesn't seem so - the MacPoolManager class seems well constructed, and uses a  ReentrantReadWriteLock to protect the initialize() method.
The instance is initialized inline, i.e., during the classloading, where its protected by the classloader's lock.
Comment 8 Moti Asayag 2013-09-01 08:30:48 UTC 
(In reply to Allon Mureinik from comment #7)
> (In reply to Itamar Heim from comment #6)
> > could this be something similar to http://gerrit.ovirt.org/#/c/18655/?
> Doesn't seem so - the MacPoolManager class seems well constructed, and uses
> a  ReentrantReadWriteLock to protect the initialize() method.
> The instance is initialized inline, i.e., during the classloading, where its
> protected by the classloader's lock.

In addition, the log indicates that the mac address pool manager was successfully initialized prior to the request from the client.
We'd might suspect that the 'create vm' flow might have use a different instance of the mac pool manager due to some classloading issue - so we'd like to add the instance id of the mac pool manager during its creation to the log and to compare it to the instance id of the mac pool manager when it fails due to this reason.

I'm not convinced this issue is reproducible always, else any installation weren't capable to create a vm or to add a nic to it.
Comment 9 Mike Kolesnik 2013-09-01 13:00:29 UTC 
The bug doesn't reproduce for me on upstream latest version.

As stated on comment #8, a patch was merged to improve the logs of the MAC pool manager mechanism.
Please try to reproduce with the patch and if the issue reproduces please attach updated engine.log
Comment 10 David Botzer 2013-09-02 08:23:51 UTC 
Trying to reproduce on is12,
1. In order to recreate the ENV I need dwh, I Cannot install dwh (waiting on Ack from Alex L)
2. Cannot work the sdk api, need assistance, who should I ask ?
Comment 11 Martin Pavlik 2013-09-12 14:10:28 UTC 
works in is14, after adding VM using attached python script, I can add another VM via GUI just fine
Comment 13 Itamar Heim 2014-01-21 22:18:59 UTC 
Closing - RHEV 3.3 Released
Comment 14 Itamar Heim 2014-01-21 22:25:13 UTC 
Closing - RHEV 3.3 Released
Comment 15 Lee Yarwood 2014-02-10 07:26:07 UTC 
Reopening after GIS (GSS lab) have reported an instance of this, logs to follow.
Comment 16 Moti Asayag 2014-02-10 07:38:55 UTC 
(In reply to Lee Yarwood from comment #15)
> Reopening after GIS (GSS lab) have reported an instance of this, logs to
> follow.

Could you also provide the output of the mac pool ranges:

  engine-config -g MacPoolRanges
  engine-config -g MaxMacsCountInPool
Comment 17 Lee Yarwood 2014-02-10 07:44:00 UTC 
(In reply to Lee Yarwood from comment #15)
> Reopening after GIS (GSS lab) have reported an instance of this, logs to
> follow.

Closing again, this was actually BZ#1056803, workaround from the solution attached  to that bug applied and working. Apologies for the noise all!