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)
