Hi List.  As threatened, here's the tale of our attempt to capture our
first Windows image.  As with our Linux capture, it appears that the VM
disk image is being copied into our Data and Repository paths, but
something goes wrong later in the process, but the warnings we find in
the log are different for our Windows image than for the Linux one.

As before, I'll paste the full log from the "PROBLEM" mail below, but it
looks like this is significant:

 |19609|20:20|image| ---- WARNING ----
 |19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|VIM_SSH.pm:initialize(112)|required VM host OS 
subroutine is not implemented: execute
 |19609|20:20|image| ( 0) VIM_SSH.pm, initialize (line: 112)
 |19609|20:20|image| (-1) Module.pm, new (line: 207)
 |19609|20:20|image| (-2) VMware.pm, (eval) (line: 1303)
 |19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1303)
 |19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
 |19609|20:20|image| (-5) Module.pm, new (line: 207)
 2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1313)|API object 
could not be created: VCL::Module::Provisioning::VMware::VIM_SSH

This looks to me like there must be something missing, maybe within the
Windows VM itself?  Did we leave out a package somewhere?

Thanks,
-m
-- 
Michael Jinks :: mji...@uchicago.edu
University of Chicago IT Services

Complete log message follows:

VCL::image object could not be created and initialized
------------------------------------------------------------------------
time: 2012-06-19 14:36:58
caller: vcld:make_new_child(571)
( 0) vcld, make_new_child (line: 571)
(-1) vcld, main (line: 346)
------------------------------------------------------------------------
management node: pilot-lab.uchicago.edu
reservation PID: 19609
parent vcld PID: 2491

request ID: 20
reservation ID: 20
request state/laststate: image/image
request start time: 2012-06-19 14:36:50
request end time: 2012-06-19 15:36:50
for imaging: no
log ID: none

computer: vcl-win7-test
computer id: 8
computer type: virtualmachine
computer eth0 MAC address: <undefined>
computer eth1 MAC address: <undefined>
computer private IP address: 10.50.84.16
computer public IP address: 10.50.84.16
computer in block allocation: no
provisioning module: VCL::Module::Provisioning::VMware::VMware

vm host: <undefined>
vm host ID: <undefined>
vm host computer ID: <undefined>
vm profile: <undefined>
vm profile VM path: <undefined>
vm profile repository path: <undefined>
vm profile datastore path: <undefined>
vm profile disk type: <undefined>

image: vmwarewin7-win7vmimage27-v0
image display name: win7-vm-image
image ID: 27
image revision ID: 23
image size: 1450 MB
use Sysprep: no
root access: yes
image owner ID: 1
image owner affiliation: Local
image revision date created: 2012-06-19 14:36:50
image revision production: yes
OS module: VCL::Module::OS::Windows::Version_6::7

user: admin
user name: vcl admin
user ID: 1
user affiliation: Local
------------------------------------------------------------------------
RECENT LOG ENTRIES FOR THIS PROCESS:
|19609|20:20|image| (-1) Autoload.pm, __ANON__ (line: 80)
|19609|20:20|image| (-2) VMware.pm, get_vmhost_datastructure (line: 1161)
|19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1282)
|19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:_automethod(812)|corresponding data 
has not been initialized for get_vmhost_profile_image_id: 
$self->request_data->{reservation}{20}{computer}{vmhost}{vmprofile}{imageid}
|19609|20:20|image| ( 0) DataStructure.pm, _automethod (line: 812)
|19609|20:20|image| (-1) Autoload.pm, __ANON__ (line: 80)
|19609|20:20|image| (-2) VMware.pm, get_vmhost_datastructure (line: 1162)
|19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1282)
|19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_datastructure(1190)|created 
DataStructure object for VM host: vcl-win7-test
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1293)|attempting to 
load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1299)|loaded VMware 
control module: VCL::Module::Provisioning::VMware::VIM_SSH
2012-06-19 14:36:58|19609|20:20|image|Module.pm:new(172)|set 'vmhost_data' key 
for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
2012-06-19 14:36:58|19609|20:20|image|Module.pm:new(172)|set 'vmhost_os' key 
for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
2012-06-19 
14:36:58|19609|20:20|image|Module.pm:create_mn_os_object(335)|management node 
OS object has already been created, address: 37c3000, returning 1
2012-06-19 
14:36:58|19609|20:20|image|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VIM_SSH
 object created for computer vcl-win7-test, address: 25dc9b0
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|VIM_SSH.pm:initialize(112)|required VM host OS 
subroutine is not implemented: execute
|19609|20:20|image| ( 0) VIM_SSH.pm, initialize (line: 112)
|19609|20:20|image| (-1) Module.pm, new (line: 207)
|19609|20:20|image| (-2) VMware.pm, (eval) (line: 1303)
|19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1303)
|19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
2012-06-19 14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1313)|API 
object could not be created: VCL::Module::Provisioning::VMware::VIM_SSH
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:_automethod(812)|corresponding data 
has not been initialized for get_vmhost_computer_id: 
$self->request_data->{reservation}{20}{computer}{vmhost}{computerid}
|19609|20:20|image| ( 0) DataStructure.pm, _automethod (line: 812)
|19609|20:20|image| (-1) Autoload.pm, __ANON__ (line: 80)
|19609|20:20|image| (-2) VMware.pm, get_vmhost_datastructure (line: 1161)
|19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1282)
|19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:_automethod(812)|corresponding data 
has not been initialized for get_vmhost_profile_image_id: 
$self->request_data->{reservation}{20}{computer}{vmhost}{vmprofile}{imageid}
|19609|20:20|image| ( 0) DataStructure.pm, _automethod (line: 812)
|19609|20:20|image| (-1) Autoload.pm, __ANON__ (line: 80)
|19609|20:20|image| (-2) VMware.pm, get_vmhost_datastructure (line: 1162)
|19609|20:20|image| (-3) VMware.pm, get_vmhost_api_object (line: 1282)
|19609|20:20|image| (-4) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_datastructure(1190)|created 
DataStructure object for VM host: vcl-win7-test
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1293)|attempting to 
load VMware control module: VCL::Module::Provisioning::VMware::vmware_cmd
2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1299)|loaded VMware 
control module: VCL::Module::Provisioning::VMware::vmware_cmd
2012-06-19 14:36:58|19609|20:20|image|Module.pm:new(172)|set 'vmhost_data' key 
for VCL::Module::Provisioning::VMware::vmware_cmd object from arguments
2012-06-19 14:36:58|19609|20:20|image|Module.pm:new(172)|set 'vmhost_os' key 
for VCL::Module::Provisioning::VMware::vmware_cmd object from arguments
2012-06-19 
14:36:58|19609|20:20|image|Module.pm:create_mn_os_object(335)|management node 
OS object has already been created, address: 37c3000, returning 1
2012-06-19 
14:36:58|19609|20:20|image|Module.pm:new(200)|VCL::Module::Provisioning::VMware::vmware_cmd
 object created for computer vcl-win7-test, address: 25db108
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:get_vmhost_api_object(1309)|API object 
could not be created: VCL::Module::Provisioning::VMware::vmware_cmd, error:
|19609|20:20|image| Can't locate object method "execute" via package 
"VCL::Module::OS::Windows::Version_6::7" at 
/usr/local/vcl/bin/../lib/VCL/Module/Provisioning/VMware/vmware_cmd.pm line 101.
|19609|20:20|image| ( 0) VMware.pm, get_vmhost_api_object (line: 1309)
|19609|20:20|image| (-1) VMware.pm, initialize (line: 278)
|19609|20:20|image| (-2) Module.pm, new (line: 207)
|19609|20:20|image| (-3) Module.pm, create_provisioning_object (line: 423)
|19609|20:20|image| (-4) State.pm, initialize (line: 117)
|19609|20:20|image| (-5) Module.pm, new (line: 207)
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|VMware.pm:initialize(285)|failed to create an object 
to control VMware on VM host: vcl-win7-test
|19609|20:20|image| ( 0) VMware.pm, initialize (line: 285)
|19609|20:20|image| (-1) Module.pm, new (line: 207)
|19609|20:20|image| (-2) Module.pm, create_provisioning_object (line: 423)
|19609|20:20|image| (-3) State.pm, initialize (line: 117)
|19609|20:20|image| (-4) Module.pm, new (line: 207)
|19609|20:20|image| (-5) vcld, make_new_child (line: 564)
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|Module.pm:create_provisioning_object(431)|provisioning
 object could not be created, returning 0
|19609|20:20|image| ( 0) Module.pm, create_provisioning_object (line: 431)
|19609|20:20|image| (-1) State.pm, initialize (line: 117)
|19609|20:20|image| (-2) Module.pm, new (line: 207)
|19609|20:20|image| (-3) vcld, make_new_child (line: 564)
|19609|20:20|image| (-4) vcld, main (line: 346)
|19609|20:20|image| ---- WARNING ----
|19609|20:20|image| 2012-06-19 
14:36:58|19609|20:20|image|State.pm:initialize(118)|failed to create 
provisioning object
|19609|20:20|image| ( 0) State.pm, initialize (line: 118)
|19609|20:20|image| (-1) Module.pm, new (line: 207)
|19609|20:20|image| (-2) vcld, make_new_child (line: 564)
|19609|20:20|image| (-3) vcld, main (line: 346)
2012-06-19 14:36:58|19609|20:20|image|State.pm:DESTROY(829)|VCL::image 
destructor called, address: 35a4ae8
2012-06-19 
14:36:58|19609|20:20|image|utils.pm:delete_computerloadlog_reservation(6742)|removing
 computerloadlog entries matching loadstate = begin
2012-06-19 
14:36:58|19609|20:20|image|utils.pm:delete_computerloadlog_reservation(6789)|deleted
 rows from computerloadlog for reservation id=20
2012-06-19 14:36:58|19609|20:20|image|State.pm:DESTROY(848)|number of database 
handles state process created: 1
2012-06-19 14:36:58|19609|20:20|image|State.pm:DESTROY(876)|VCL::image process 
duration: 6 seconds
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:get_computer_private_ip_address(1581)|attempting
 to retrieve private IP address for computer: vcl-win7-test
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:get_computer_private_ip_address(1585)|retrieved
 contents of /etc/hosts on this management node, contains 18 lines
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:get_computer_private_ip_address(1645)|returning
 IP address from /etc/hosts file: 10.50.84.16
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2703)|unable to use 
database handle stored in $ENV{dbh}
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2760)|database handle 
stored in $ENV{dbh}
2012-06-19 14:36:58|19609|20:20|image|utils.pm:is_inblockrequest(6163)|zero 
rows were returned from database select
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:get_image_affiliation_name(2035)|image
 owner id: 1
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2709)|database 
requested (information_schema) does not match handle stored in $ENV{dbh} 
(vcl:128.135.107.122)
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2760)|database handle 
stored in $ENV{dbh}
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:retrieve_user_data(1352)|attempting 
to retrieve and store data for user: user.id = '1'
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2709)|database 
requested (vcl) does not match handle stored in $ENV{dbh} 
(information_schema:128.135.107.122)
2012-06-19 14:36:58|19609|20:20|image|utils.pm:getnewdbh(2760)|database handle 
stored in $ENV{dbh}
2012-06-19 
14:36:58|19609|20:20|image|DataStructure.pm:retrieve_user_data(1415)|data has 
been retrieved for user: admin (id: 1)

Reply via email to