You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@vcl.apache.org by Michael Jinks <mj...@uchicago.edu> on 2012/06/20 01:53:45 UTC
Windows capture fails
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 :: mjinks@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)
Re: Windows capture fails
Posted by Aaron Peeler <aa...@ncsu.edu>.
Hi Michael and team,
Could you share your vmware host server and vmware profile information
that you have stored in your setup? Based on the log output there
might be some missing information or it's not setup correctly.
Since this is a public list, if there are any public IP address or
anything important feel free to obscure that info or send to me
privately.
Thanks,
Aaron
On Wed, Jun 20, 2012 at 10:01 AM, Michael Jinks <mj...@uchicago.edu> wrote:
> We're using 2.2.1. When I downloaded the package it was the only
> release I could find without going to svn.
>
>
> On Wed, Jun 20, 2012 at 08:48:01AM -0400, Aaron Peeler wrote:
>> Hello Michael,
>>
>> Which version are you using? VCL 2.2.1 or the pre-release of 2.3? The
>> execute subroutine is not implemented is concerning.
>>
>> Thanks,
>> Aaron
>>
>> On Tue, Jun 19, 2012 at 7:53 PM, Michael Jinks <mj...@uchicago.edu> wrote:
>> > 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 :: mjinks@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)
>> >
>>
>>
>>
>> --
>> Aaron Peeler
>> Program Manager
>> Virtual Computing Lab
>> NC State University
>>
>> All electronic mail messages in connection with State business which
>> are sent to or received by this account are subject to the NC Public
>> Records Law and may be disclosed to third parties.
>
> --
> Michael Jinks :: mjinks@uchicago.edu :: 773-469-9688
> University of Chicago IT Services
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which
are sent to or received by this account are subject to the NC Public
Records Law and may be disclosed to third parties.
Re: Windows capture fails
Posted by Michael Jinks <mj...@uchicago.edu>.
We're using 2.2.1. When I downloaded the package it was the only
release I could find without going to svn.
On Wed, Jun 20, 2012 at 08:48:01AM -0400, Aaron Peeler wrote:
> Hello Michael,
>
> Which version are you using? VCL 2.2.1 or the pre-release of 2.3? The
> execute subroutine is not implemented is concerning.
>
> Thanks,
> Aaron
>
> On Tue, Jun 19, 2012 at 7:53 PM, Michael Jinks <mj...@uchicago.edu> wrote:
> > 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 :: mjinks@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)
> >
>
>
>
> --
> Aaron Peeler
> Program Manager
> Virtual Computing Lab
> NC State University
>
> All electronic mail messages in connection with State business which
> are sent to or received by this account are subject to the NC Public
> Records Law and may be disclosed to third parties.
--
Michael Jinks :: mjinks@uchicago.edu :: 773-469-9688
University of Chicago IT Services
Re: Windows capture fails
Posted by Aaron Peeler <aa...@ncsu.edu>.
Hello Michael,
Which version are you using? VCL 2.2.1 or the pre-release of 2.3? The
execute subroutine is not implemented is concerning.
Thanks,
Aaron
On Tue, Jun 19, 2012 at 7:53 PM, Michael Jinks <mj...@uchicago.edu> wrote:
> 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 :: mjinks@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)
>
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which
are sent to or received by this account are subject to the NC Public
Records Law and may be disclosed to third parties.