Infrastructure Software

Hi,

I'm trying to register a VM template created with OVAB. By selecting Catalog > Register Template, I start the process, but soon the following error appears:

Register operation on GOoF3poDOBgl13_qKWj7qoDOBgl13 to DefaultConnection::serverpool failed! [[
CAUSE: Template registration for the capture id TemplateIdImpl[uuid=UuidImpl[id=qKWj7qoDOBgl13]] for the OVM platform and the OEL OS failed


This is what logs show:

assemblybuilder.log:

[2011-11-21T19:41:56.896+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.introspector] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] IntrospectorServiceActivator - activated
[2011-11-21T19:42:01.276+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] WLOC MSA Service WorkManagerImpl(System) started.
[2011-11-21T19:42:01.281+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] WLOC MSA Service TimerManagerImpl(System) started.
[2011-11-21T19:42:01.326+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.oracle.adaptive.arc.filestore.internal] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] Using filestore configuration provider oracle.as.assemblybuilder.ovab.deployer.internal.WLOCAgentConfigurationProvider.
[2011-11-21T19:42:01.346+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] WLOC MSA Service FileStoreServiceImpl started.
[2011-11-21T19:42:01.382+03:00] [as] [WARNING] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] Warning from managed process: Error while initializing NativeProcessControlService. Plain Processes cannot be restored..
[2011-11-21T19:42:02.825+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] WLOC MSA Service CacheManagerServiceImpl started.
[2011-11-21T19:42:02.827+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.com.bea.adaptive.logging] [tid: 10] [ecid: 0000JF70MFVEwGWzLwyGOA1EmbxK000000,0] WLOC MSA Service StandaloneAgent started.
[2011-11-21T19:42:24.970+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Registering my_assembly1 to DefaultConnection::serverpool started.
[2011-11-21T19:42:24.976+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Connecting to DefaultConnection::serverpool for register operation.
[2011-11-21T19:42:33.435+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Connected to DefaultConnection::serverpool. Beginning register operation.
[2011-11-21T19:42:34.355+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Starting register operation for GOoF3poDOBgl13_qKWj7qoDOBgl13 on DefaultConnection::serverpool
[2011-11-21T19:42:34.497+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.ovab] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Resource DefaultConnection:serverpool has disk available 433209 MB
[2011-11-21T19:42:34.498+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.ovab] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Template GOoF3poDOBgl13_qKWj7qoDOBgl13 require disk size 4008 MB
[2011-11-21T19:42:50.954+03:00] [as] [WARNING] [] [oracle.as.assemblybuilder.resourcepool] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Error occurred when importing the template GOoF3poDOBgl13_qKWj7qoDOBgl13. Error is: java.lang.Exception: Expecting template state 'Pending', instead got 'ImportError' indicating possible error[[
at com.oracle.vmm.client.ResourcePoolImpl.waitForTemplateState(ResourcePoolImpl.java:359)
at com.oracle.vmm.client.ResourcePoolImpl.importTemplate(ResourcePoolImpl.java:184)
at oracle.as.assemblybuilder.resourcepool.service.ovm.internal.OVMResourcePoolServiceImpl.importTemplate(OVMResourcePoolServiceImpl.java:287)
at oracle.as.assemblybuilder.ovab.deployer.internal.PoolTemplatesManagerImpl.registerTemplateInternal(PoolTemplatesManagerImpl.java:225)
at oracle.as.assemblybuilder.ovab.deployer.internal.PoolTemplatesManagerImpl.registerTemplate(PoolTemplatesManagerImpl.java:152)
at oracle.as.assemblybuilder.ovab.deployer.internal.PoolTemplatesManagerImpl.registerTemplates(PoolTemplatesManagerImpl.java:426)
at oracle.as.assemblybuilder.ovab.deployer.internal.TemplateManagerImpl.registerTemplates(TemplateManagerImpl.java:174)
at oracle.as.assemblybuilder.fcp.internal.model.register.TemplateManagerFacadeImpl$RegisterTask.run(TemplateManagerFacadeImpl.java:93)
at java.lang.Thread.run(Thread.java:619)

]]
[2011-11-21T19:42:50.965+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Register operation on GOoF3poDOBgl13_qKWj7qoDOBgl13 to DefaultConnection::serverpool failed! [[
CAUSE: Template registration for the capture id TemplateIdImpl[uuid=UuidImpl[id=qKWj7qoDOBgl13]] for the OVM platform and the OEL OS failed
]]
[2011-11-21T19:42:51.356+03:00] [as] [NOTIFICATION] [] [oracle.as.assemblybuilder.fcp] [tid: 14] [ecid: 0000JF70T5DEwGWzLwyGOA1EmbxK000002,0] Registering of my_assembly1 to DefaultConnection::serverpool failed.

///////////////////////////////////////////////////////////

oc4j.log:

11/11/21 19:41:28 Oracle Containers for J2EE 10g (10.1.3.2.0) initialized
2011-11-21 19:42:31.227 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:32.425 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:32.452 NOTIFICATION Get server pool metrics info need:1231
2011-11-21 19:42:32.578 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:33.353 NOTIFICATION Getting network bridges for agent: 192.168.100.2 ...
2011-11-21 19:42:33.413 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:34.331 NOTIFICATION getAllTemplateResources(): 2
2011-11-21 19:42:34.717 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:34.742 NOTIFICATION Get server pool metrics info need:1329
2011-11-21 19:42:34.825 NOTIFICATION master server is:192.168.100.2
2011-11-21 19:42:34.881 WARNING getTemplateResourceByName(110, GOoF3poDOBgl13_qKWj7qoDOBgl13) returns null
2011-11-21 19:42:34.888 ERROR OWS-04046 Caught exception while handling request: oracle.ovs.biz.exception.OVSException: OVM-5101 The template {0} cannot be found. oracle.ovs.biz.exception.OVSException: OVM-5101 The template {0} cannot be found.
2011-11-21 19:42:35.626 NOTIFICATION **** Running runAsyncTask[registerTemplate]
2011-11-21 19:42:35.645 WARNING getTemplateResourceByName(110, GOoF3poDOBgl13_qKWj7qoDOBgl13) returns null
2011-11-21 19:42:35.709 WARNING getTemplateResourceByName(110, GOoF3poDOBgl13_qKWj7qoDOBgl13) returns null
2011-11-21 19:42:35.710 ERROR OWS-04046 Caught exception while handling request: oracle.ovs.biz.exception.OVSException: OVM-5101 The template {0} cannot be found. oracle.ovs.biz.exception.OVSException: OVM-5101 The template {0} cannot be found.
2011-11-21 19:42:35.733 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Virtual Machine Core Service]Register dummy virtual machine[GOoF3poDOBgl13_qKWj7qoDOBgl13]
2011-11-21 19:42:35.928 NOTIFICATION CREATE VM INFO
2011-11-21 19:42:36.485 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Resource Download Service(RDS)]
-----------------------------------
SERVER POOL: serverpool
RESOURCE TYPE: Virtual Machine Template
DOWNLOAD URL: https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb
PROXY URL: null
TARGET LOCATION: /OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13
ASYNCHRONOUS JOB: true

2011-11-21 19:42:36.542 NOTIFICATION remove /OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13 succeed
2011-11-21 19:42:36.685 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Resource Download Service(RDS)][Creating new download task(1DF03CDE548B489CAB19F52B02A08602]
2011-11-21 19:42:36.686 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Resource Download Service(RDS)][Start downloading...]
2011-11-21 19:42:46.863 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Resource Download Service(RDS)][Download Complete]
2011-11-21 19:42:47.424 NOTIFICATION [ResourceController Info] get_vm_size(): 1
11/11/21 19:42:47 oracle.ovs.biz.exception.OVSException: OVM-5004 Invalid virtual machine config file.
11/11/21 19:42:47 at oracle.ovs.biz.resource.NeoResourceController.detectImportType(NeoResourceController.java:1459)
11/11/21 19:42:47 at oracle.ovs.biz.resource.services.VMCoreService.checkVMConfigPrerequistic(VMCoreService.java:304)
11/11/21 19:42:47 at oracle.ovs.biz.resource.services.VMCoreService.parseVMConfig(VMCoreService.java:74)
11/11/21 19:42:47 at oracle.ovs.biz.resource.services.AbstractImportVirtualMachineService.createVMFull(AbstractImportVirtualMachineService.java:79)
11/11/21 19:42:47 at oracle.ovs.biz.resource.services.AbstractImportVirtualMachineService.register(AbstractImportVirtualMachineService.java:170)
11/11/21 19:42:47 at oracle.ovs.api.NeoResourceManagementImpl.registerTemplate(NeoResourceManagementImpl.java:828)
11/11/21 19:42:47 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
11/11/21 19:42:47 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
11/11/21 19:42:47 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
11/11/21 19:42:47 at java.lang.reflect.Method.invoke(Method.java:585)
11/11/21 19:42:47 at org.apache.commons.beanutils.MethodUtils.invokeExactMethod(MethodUtils.java:370)
11/11/21 19:42:47 at oracle.ovs.biz.resource.ResourceManager.TaskThread.execute(TaskThread.java:333)
11/11/21 19:42:47 at oracle.ovs.biz.resource.ResourceManager.TaskThread.run(TaskThread.java:261)
2011-11-21 19:42:51.095 NOTIFICATION [AcquireLock][ImgID:390.0]: Current Lock - VM_NO_LOCK
2011-11-21 19:42:51.103 NOTIFICATION [AcquireLock][ImgID:390.0]: Current Lock - VM_NO_LOCK , Time Gap - 33
2011-11-21 19:42:51.184 NOTIFICATION remove /OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13 succeed
2011-11-21 19:42:51.289 NOTIFICATION [ReleaseLock][ImgID:390.0]: Current Lock - VM_EXCLUSIVE_LOCK
2011-11-21 19:42:51.313 NOTIFICATION [IMPORT VIRTUAL MACHINE SERVICE][Virtual Machine Core Service][GOoF3poDOBgl13_qKWj7qoDOBgl13] deleted

///////////////////////////////////////////////

ovs_operation.log

"2011-11-21 18:37:46" WARNING=> rm_vm: cannot get real path vm('/OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13')
"2011-11-21 18:37:46" INFO=> new_async_task_ext: success. ->wget ('https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb', '/OVS/seed_pool/') => 1DF03CDE548B489CAB19F52B02A08602
"2011-11-21 18:37:46" INFO=> server('192.168.100.2') is selected as utility server
"2011-11-21 18:37:46" INFO=> directcall_in_asyncenv: success. utl_get_storage_repos [] => success:repos=/var/ovs/mount/EFE2206B166A473094B110586B8CB15A;free_space=433209
"2011-11-21 18:37:46" DEBUG=> wget cmd: cd '/var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/.wget/GOoF3poDOBgl13_qKWj7qoDOBgl13' && wget -o /tmp/wget-uDM_CM.log mirror continue tries=3 dns-timeout=30 connect-timeout=30 read-timeout=30 no-parent no-directories reject=*.htm* 'https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb/' no-check-certificate
"2011-11-21 18:37:46" INFO=> utl_move: success. /var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/.wget/GOoF3poDOBgl13_qKWj7qoDOBgl13 moved to /var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13
"2011-11-21 18:37:46" INFO=> utl_wget: success. url('https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb/') => path('/var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool'), name('GOoF3poDOBgl13_qKWj7qoDOBgl13')
"2011-11-21 18:37:46" INFO=> directcall_in_asyncenv: success. utl_wget ['https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb', '/var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/', True, 'GOoF3poDOBgl13_qKWj7qoDOBgl13', '', ''] => success
"2011-11-21 18:37:46" INFO=> wget: success. url('https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb') => path('/OVS/seed_pool/'), name('GOoF3poDOBgl13_qKWj7qoDOBgl13')
"2011-11-21 18:37:46" INFO=> directcall_in_asyncenv: success. wget ['https://192.168.100.1:9678/template/5eb76cfc50fc54796b9c3d56a6aff4cadb871c6a01e3f07544f2be25d34c12cb', '/OVS/seed_pool/', True] => success
"2011-11-21 18:37:57" INFO=> verify_image_v2v: /OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13
"2011-11-21 18:37:57" ERROR=> verify_image_v2v: failed! => Can't find source vm in the path /var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13
"2011-11-21 18:38:01" INFO=> utl_rm_vm: vm (/var/ovs/mount/EFE2206B166A473094B110586B8CB15A/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13) deleted!
"2011-11-21 18:38:01" INFO=> rm_vm: vm('/OVS/seed_pool/GOoF3poDOBgl13_qKWj7qoDOBgl13') => success


////////////////////////////////////////////////


Could someone please tell me what I should try to do to solve the issue?

Regards,
Serg