Hi All,
Being a newbie, I need some help in capturing my first Base Image.
I have VMware Server 2.0, with a free license, installed on the same
RHEL 5.8 hardware as my Management Node. I am not using the vSphere_SDK
software. I am only using SSH. I believe that, I do not need the SDK in
this situation. Is that true? My guest OS (winXP) is running, and I seem
to be able to ssh to the guest with out a password. I tried my VM Host
Profile with and without a password.
VM Host Profile
Select a profile to configure:
Name: VMware Server 2.x - local storage
Type: vmware
Image: no image
Repository Path: /vms/repository
Data Store Path: /vms/datastore1
VM Path: (empty)
Virtual Switch 0: HostOnly
Virtual Switch 1: Bridged
VM Disk: localdisk
Generate eth0 MAC: No
Generate eth1 MAC: No
Username: root
Password: *****
Confirm: ***** match
Yet, VIM_SSH.pm it seems to be throwing a failed to login error. Which I
think is my first major error message. I am assuming at this point, that
vmi_ssh is trying to sign into the VMware Server.
16:05:55|3559|12:12|image|VIM_SSH.pm:_get_datastore_info(490)|unable to
determine datastore names, unexpected output returned, VIM command
arguments: 'hostsvc/datastore/listsummary', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
Any ideas, anyone?
If I do need the vSphere_SDK for perl, what version do I need for VMware
Server 2.0?
A more complete log follows.
Thanks,
/Brian
--
--
Brian Hartlieb
System Administrator
TIS - Rensselaer at Hartford
Rensselaer Polytechnic Institute (RPI)
(860) 548-5459
har...@rpi.edu
[root@alpha-vcl ~]# ssh -o CheckHostIP=no -o StrictHostKeyChecking=no -o
BatchMode=no -i /etc/vcl/vcl.key 10.5.120.11
Warning: Permanently added '10.5.120.11' (RSA) to the list of known hosts.
Last login: Mon Apr 9 16:02:39 2012 from 10.5.120.1
root@winxp3 ~
$ exit
logout
Connection to 10.5.120.11 closed.
[root@alpha-vcl ~]# ssh 10.5.120.11
Warning: Permanently added '10.5.120.11' (RSA) to the list of known hosts.
Permission denied (publickey,keyboard-interactive).
[root@alpha-vcl ~]#
[root@alpha-vcl ~]# /usr/local/vcl/bin/vcld -setup
VCL Management Node Setup
----------------------------------------------------------------------------
Select a module to configure:
1. VCL Base Module
2. VCL Image State Module
3. Windows OS Module
[vcld]
Make a selection (1-3, 'c' to cancel): 2
----------------------------------------------------------------------------
Choose an operation:
1. Capture Base Image
[vcld/Image]
Make a selection (1, 'c' to cancel): 1
Enter the VCL login name or ID of the user who will own the image: [admin]:
User who will own the image: admin (ID: 1)
Enter the hostname or IP address of the computer to be captured: ('c' to
cancel): 10.5.120.11
Computer to be captured: vmguest-1 (ID: 2)
Provisioning module: provisioning_vmware
Install type: vmware
Select the OS to be captured (install type: vmware):
1. Generic Linux (VMware)
2. Windows 2003 Server (VMware)
3. Windows 7 (VMware)
4. Windows Server 2008 (VMware)
5. Windows Vista (VMware)
6. Windows XP (VMware)
[vcld/Image/Capture Base Image]
Make a selection (1-6, 'c' to cancel): 6
Selected OS: Windows XP (VMware)
Image architecture:
1. x86
2. x86_64
[vcld/Image/Capture Base Image]
Make a selection (1-2, 'c' to cancel): 1
Image architecture: x86
Use Sysprep:
1. Yes
2. No
[vcld/Image/Capture Base Image]
Make a selection (1-2, 'c' to cancel): 2
Use Sysprep: No
Enter the name of the image to be captured: ('c' to cancel): WinXP Base
Added new image to database: 'WinXP Base'
image.name: vmwarewinxp-WinXPBase19-v0
image.id: 19
imagerevision.id: 16
imagemeta.id: 15
resource.id: 32
----------------------------------------------------------------------------
Inserted imaging request to the database:
request ID: 12
reservation ID: 12
This process will now display the contents of the vcld.log file if the vcld
daemon is running. If you do not see many lines of additional output,
exit this
process, start the vcld daemon, and monitor the image capture process by
running
the command:
tail -f /var/log/vcld.log | grep '12:12'
----------------------------------------------------------------------------
2012-04-09 16:05:30|3552|utils.pm:setup_get_array_choice(9947)|choices
argument:
2012-04-09 16:05:32|3552|utils.pm:setup_get_array_choice(9947)|choices
argument:
2012-04-09 16:05:35|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:35
2012-04-09 16:05:40|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:40
2012-04-09 16:05:41|3552|utils.pm:insert_request(8358)|inserted new
reload request into request table, request id=12
2012-04-09 16:05:41|3552|utils.pm:insert_request(8389)|inserted new
reload request into reservation table, reservation id=12
2012-04-09 16:05:45|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:45
2012-04-09
16:05:45|3519|12:12|image|utils.pm:reservation_being_processed(8938)|computerloadlog
'begin' entry does NOT exist for reservation 12
2012-04-09 16:05:45|3519|12:12|image|utils.pm:run_command(9010)|executed
command: pgrep -fl 'vcld [0-9]+:12 ', pid: 3557, exit status: 1, output:
2012-04-09
16:05:45|3519|12:12|image|utils.pm:is_management_node_process_running(9192)|process
is NOT running, identifier: 'vcld [0-9]+:12 '
2012-04-09
16:05:45|3519|12:12|image|utils.pm:reservation_being_processed(8959)|reservation
is NOT currently being processed
2012-04-09 16:05:45|3519|12:12|image|vcld:main(278)|reservation 12 is
NOT already being processed
2012-04-09
16:05:45|3519|12:12|image|utils.pm:get_request_info(4520)|standalone
affiliation found: Local
2012-04-09 16:05:45|3519|12:12|image|vcld:main(283)|retrieved request
information from database
2012-04-09
16:05:45|3519|12:12|image|DataStructure.pm:is_parent_reservation(991)|returning
true: parent reservation ID for this request: 12
2012-04-09
16:05:45|3519|12:12|image|utils.pm:update_request_state(1991)|request 12
state updated to: pending, laststate to: image
2012-04-09
16:05:45|3519|12:12|image|utils.pm:insertloadlog(3875)|inserted
computer=2, begin, beginning to process, state is image
2012-04-09 16:05:45|3519|12:12|image|vcld:make_new_child(515)|loaded
VCL::image module
2012-04-09 16:05:45|3559|12:12|image|vcld:make_new_child(555)|vcld
environment variable set to 0 for this process
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'test' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'forimaging'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'reservation' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'userid' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'daterequested' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'RESERVATIONID' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'UPDATED'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'SUBIMAGE'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'CHECKTIME'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'state' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'laststate'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'PRELOADONLY' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'laststateid' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'user' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'id' key for
VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'PID' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'DURATION'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'PPID' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'datemodified' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'RESERVATIONCOUNT' key for VCL::image object from arguments
2012-04-09 16:05:45|3519|12:12|image|vcld:make_new_child(539)|current
number of forked kids: 1
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'end' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'stateid'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'PARENTIMAGE' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'checkuser'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'preload'
key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'NOTICEINTERVAL' key for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'start' key
for VCL::image object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'logid' key
for VCL::image object from arguments
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(361)|VCL::Module::OS::Linux::ManagementNode
module loaded
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(196)|VCL::Module::OS::Linux::ManagementNode
object created for image <not set>, address: 1802ab50
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{computer}{hostname}
|3559|12:12|image| computer_hostname = alpha-vcl.ewp.rpi.edu
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{computer}{NODENAME}
|3559|12:12|image| computer_node_name = alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated:
$self->request_data->{reservation}{0}{computer}{SHORTNAME}
|3559|12:12|image| computer_short_name = alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated:
$self->request_data->{reservation}{0}{computer}{IPaddress}
|3559|12:12|image| computer_ip_address = 129.5.80.51
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(366)|VCL::Module::OS::Linux::ManagementNode
OS object created, address: 1802ab50
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(192)|VCL::image
object created for state image, address: 17e256b0
2012-04-09 16:05:45|3559|12:12|image|State.pm:initialize(86)|obtained a
database handle for this state process, stored as $ENV{dbh}
2012-04-09 16:05:45|3559|12:12|image|State.pm:check_image_os(762)|no
corrections need to be made to image OS: vmwarewinxp
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:is_parent_reservation(991)|returning
true: parent reservation ID for this request: 12
2012-04-09
16:05:45|3559|12:12|image|utils.pm:rename_vcld_process(7098)|reservation
count: 1
2012-04-09
16:05:45|3559|12:12|image|utils.pm:rename_vcld_process(7117)|PARENTIMAGE: 1
2012-04-09
16:05:45|3559|12:12|image|utils.pm:rename_vcld_process(7118)|SUBIMAGE: 0
2012-04-09
16:05:45|3559|12:12|image|utils.pm:rename_vcld_process(7136)|renamed
process to 'vcld 12:12 image vmguest-1>alpha-vcl.ewp.rpi.edu
vmwarewinxp-WinXPBase19-v0 admin'
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:is_parent_reservation(991)|returning
true: parent reservation ID for this request: 12
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:is_parent_reservation(991)|returning
true: parent reservation ID for this request: 12
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_os_object(298)|VCL::Module::OS::Windows::Version_5::XP
module loaded
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(335)|management
node OS object has already been created, address: 1802ab50, returning 1
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(196)|VCL::Module::OS::Windows::Version_5::XP
object created for image vmwarewinxp-WinXPBase19-v0, address: 1804eae0
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_os_object(304)|VCL::Module::OS::Windows::Version_5::XP
OS object created for vmwarewinxp-WinXPBase19-v0, address: 1804eae0
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_provisioning_object(420)|VCL::Module::Provisioning::VMware::VMware
module loaded
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(335)|management
node OS object has already been created, address: 1802ab50, returning 1
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VMware
object created for computer vmguest-1, address: 18516a70
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:initialize(230)|initializing
VCL::Module::Provisioning::VMware::VMware object
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(613)|computer ID
argument was specified, retrieving data for computer ID: 1
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(643)|image ID
argument was specified: 4, DataStructure object will contain image
information for the production imagerevision of this image
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(660)|retrieved
data for imagerevision ID: 4
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(676)|retrieved
data for image ID: 4
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_datastructure(1190)|created
DataStructure object for VM host: alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:initialize(249)|attempting to create
OS object for the image currently loaded on the VM host: alpha-vcl
|3559|12:12|image| image name: noimage
|3559|12:12|image| OS module: VCL::Module::OS::Linux::UnixLab
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(613)|computer ID
argument was specified, retrieving data for computer ID: 1
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(643)|image ID
argument was specified: 4, DataStructure object will contain image
information for the production imagerevision of this image
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(660)|retrieved
data for imagerevision ID: 4
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(676)|retrieved
data for image ID: 4
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_datastructure(1190)|created
DataStructure object for VM host: alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_os_object(1232)|attempting
to load VM host OS module: VCL::Module::OS::Linux::UnixLab
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_os_object(1238)|VM host
OS module loaded: VCL::Module::OS::Linux::UnixLab
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(335)|management
node OS object has already been created, address: 1802ab50, returning 1
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(196)|VCL::Module::OS::Linux::UnixLab
object created for image noimage, address: 1888fe10
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_os_object(1244)|VM host
OS object created: VCL::Module::OS::Linux::UnixLab
2012-04-09
16:05:45|3559|12:12|image|OS.pm:is_ssh_responding(401)|alpha-vcl is
responding to SSH, port 22: open, port 24: closed
2012-04-09 16:05:45|3559|12:12|image|VMware.pm:initialize(254)|OS on VM
host alpha-vcl will be controlled using a
VCL::Module::OS::Linux::UnixLab OS object
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(613)|computer ID
argument was specified, retrieving data for computer ID: 1
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(643)|image ID
argument was specified: 4, DataStructure object will contain image
information for the production imagerevision of this image
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(660)|retrieved
data for imagerevision ID: 4
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(676)|retrieved
data for image ID: 4
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_datastructure(1190)|created
DataStructure object for VM host: alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_api_object(1293)|attempting
to load VMware control module:
VCL::Module::Provisioning::VMware::vSphere_SDK
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_api_object(1299)|loaded
VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'vmhost_data' key for VCL::Module::Provisioning::VMware::vSphere_SDK
object from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'vmhost_os'
key for VCL::Module::Provisioning::VMware::vSphere_SDK object from arguments
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(335)|management
node OS object has already been created, address: 1802ab50, returning 1
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(200)|VCL::Module::Provisioning::VMware::vSphere_SDK
object created for computer vmguest-1, address: 18882c50
2012-04-09
16:05:45|3559|12:12|image|vSphere_SDK.pm:initialize(1826)|vSphere SDK
for Perl does not appear to be installed on this managment node, unable
to load VMware vSphere SDK Perl modules
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_api_object(1313)|API
object could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(613)|computer ID
argument was specified, retrieving data for computer ID: 1
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(643)|image ID
argument was specified: 4, DataStructure object will contain image
information for the production imagerevision of this image
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(660)|retrieved
data for imagerevision ID: 4
2012-04-09
16:05:45|3559|12:12|image|DataStructure.pm:_initialize(676)|retrieved
data for image ID: 4
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_datastructure(1190)|created
DataStructure object for VM host: alpha-vcl
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_api_object(1293)|attempting
to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2012-04-09
16:05:45|3559|12:12|image|VMware.pm:get_vmhost_api_object(1299)|loaded
VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set
'vmhost_data' key for VCL::Module::Provisioning::VMware::VIM_SSH object
from arguments
2012-04-09 16:05:45|3559|12:12|image|Module.pm:new(172)|set 'vmhost_os'
key for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
2012-04-09
16:05:45|3559|12:12|image|Module.pm:create_mn_os_object(335)|management
node OS object has already been created, address: 1802ab50, returning 1
2012-04-09
16:05:45|3559|12:12|image|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VIM_SSH
object created for computer vmguest-1, address: 188b39a0
2012-04-09 16:05:46|3559|12:12|image|VIM_SSH.pm:initialize(138)|VIM
executable available on VM host: vmware-vim-cmd
2012-04-09
16:05:46|3559|12:12|image|VIM_SSH.pm:initialize(140)|VCL::Module::Provisioning::VMware::VIM_SSH
object initialized
2012-04-09
16:05:46|3559|12:12|image|VMware.pm:get_vmhost_api_object(1320)|created
API object: VCL::Module::Provisioning::VMware::VIM_SSH
2012-04-09 16:05:46|3559|12:12|image|VMware.pm:initialize(278)|VMware on
VM host alpha-vcl will be controlled using vim-cmd via SSH
2012-04-09 16:05:46|3559|12:12|image|VMware.pm:initialize(293)|VMware OS
and API objects created for VM host alpha-vcl:
|3559|12:12|image| VM host OS object type: VCL::Module::OS::Linux::UnixLab
|3559|12:12|image| VMware API object type:
VCL::Module::Provisioning::VMware::VIM_SSH
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:get_vmhost_product_name(5405)|VMware
product being used on VM host alpha-vcl.ewp.rpi.edu: 'VMware Server
2.0.2 build-203138'
2012-04-09 16:05:47|3559|12:12|image|VMware.pm:initialize(307)|product:
VMware Server 2.0.2 build-203138, OS object: VCL::Module::OS::Linux::UnixLab
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:get_vmx_base_directory_path(2745)|determined
vmx base directory path: /vms/datastore1
2012-04-09
16:05:47|3559|12:12|image|Linux.pm:file_exists(1404)|'/vms/datastore1'
exists on alpha-vcl, files: 0, directories: 1, links: 0
2012-04-09 16:05:47|3559|12:12|image|VMware.pm:initialize(324)|not
checking if vmdk base directory exists because it is the same as the vmx
base directory: /vms/datastore1
2012-04-09
16:05:47|3559|12:12|image|Module.pm:create_provisioning_object(426)|VCL::Module::Provisioning::VMware::VMware
provisioner object created for vmguest-1, address: 18516a70
2012-04-09 16:05:47|3559|12:12|image|State.pm:initialize(126)|returning 1
2012-04-09 16:05:47|3559|12:12|image|vcld:make_new_child(565)|VCL::image
object created and initialized
2012-04-09 16:05:47|3559|12:12|image|utils.pm:mail(1255)|SUCCESS --
Sending mail To: vcl_adminu...@ewp.rpi.edu, VCL IMAGE Creation Started:
vmwarewinxp-WinXPBase19-v0
2012-04-09 16:05:47|3559|12:12|image|Linux.pm:file_exists(1390)|file or
directory does not exist on alpha-vcl:
'/vms/datastore1/vmwarewinxp-WinXPBase19-v0/vmwarewinxp-WinXPBase19-v0.vmdk'
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:does_image_exist(3915)|image does
not exist in the non-persistent directory on the VM host
2012-04-09
16:05:47|3559|12:12|image|Linux.pm:file_exists(1404)|'/vms/repository'
exists on alpha-vcl, files: 0, directories: 1, links: 0
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:is_repository_mounted_on_vmhost(5485)|image
repository is mounted on VM host alpha-vcl.ewp.rpi.edu: /vms/repository
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:does_image_exist(3926)|checking if
vmdk file exists in image repository mounted on VM host:
alpha-vcl.ewp.rpi.edu:/vms/repository/vmwarewinxp-WinXPBase19-v0/vmwarewinxp-WinXPBase19-v0.vmdk
2012-04-09 16:05:47|3559|12:12|image|Linux.pm:file_exists(1390)|file or
directory does not exist on alpha-vcl:
'/vms/repository/vmwarewinxp-WinXPBase19-v0/vmwarewinxp-WinXPBase19-v0.vmdk'
2012-04-09
16:05:47|3559|12:12|image|VMware.pm:does_image_exist(3932)|vmdk file
does not exist in image repository mounted on VM host:
alpha-vcl.ewp.rpi.edu:/vms/repository/vmwarewinxp-WinXPBase19-v0/vmwarewinxp-WinXPBase19-v0.vmdk
2012-04-09 16:05:47|3559|12:12|image|image.pm:process(145)|image
vmwarewinxp-WinXPBase19-v0 does not exist in the repository
2012-04-09
16:05:47|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{12}{image}{lastupdate}
|3559|12:12|image| image_lastupdate = 2012-04-09 16:05:47
2012-04-09
16:05:47|3559|12:12|image|DataStructure.pm:_automethod(834)|data
structure updated:
$self->request_data->{reservation}{12}{imagerevision}{datecreated}
|3559|12:12|image| imagerevision_date_created = 2012-04-09 16:05:47
2012-04-09 16:05:47|3559|12:12|image|image.pm:process(161)|calling
provisioning module's capture() subroutine
2012-04-09
16:05:49|3559|12:12|image|OS.pm:is_ssh_responding(401)|vmguest-1 is
responding to SSH, port 22: open, port 24: closed
2012-04-09 16:05:50|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:50
2012-04-09
16:05:51|3559|12:12|image|OS.pm:is_ssh_responding(401)|vmguest-1 is
responding to SSH, port 22: open, port 24: closed
2012-04-09 16:05:52|3559|12:12|image|Windows.pm:is_64_bit(8108)|32-bit
Windows OS detected, PROCESSOR_IDENTIFIER: x86 Family 6 Model 44
Stepping 2, GenuineIntel
2012-04-09
16:05:52|3559|12:12|image|Windows.pm:get_system32_path(8152)|32-bit
Windows OS installed on vmguest-1, using C:/Windows/System32
2012-04-09
16:05:52|3559|12:12|image|Windows.pm:get_network_configuration(4949)|attempting
to retrieve network configuration information from vmguest-1
2012-04-09
16:05:52|3559|12:12|image|utils.pm:run_ssh_command(5380)|executing SSH
command on vmguest-1:
|3559|12:12|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o
StrictHostKeyChecking=no -l root -p 22 -x vmguest-1
'C:/Windows/System32/ipconfig.exe /all' 2>&1
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(4984)|found
interface: Local Area Connection
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(4984)|found
interface: Local Area Connection 2
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(5036)|saving
network configuration in $self->{network_configuration}
2012-04-09
16:05:53|3559|12:12|image|DataStructure.pm:get_computer_private_ip_address(1581)|attempting
to retrieve private IP address for computer: vmguest-1
2012-04-09
16:05:53|3559|12:12|image|DataStructure.pm:get_computer_private_ip_address(1585)|retrieved
contents of /etc/hosts on this management node, contains 18 lines
2012-04-09
16:05:53|3559|12:12|image|DataStructure.pm:get_computer_private_ip_address(1645)|returning
IP address from /etc/hosts file: 10.5.120.11
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(5075)|private
interface found: Local Area Connection, description: VMware Accelerated
AMD PCNet Adapter, address(es): 10.5.120.11
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_private_mac_address(5238)|returning
private MAC address: 00-50-56-1A-01-01
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(5040)|network
configuration has already been retrieved
2012-04-09
16:05:53|3559|12:12|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning
private IP address previously retrieved: 10.5.120.11
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(5075)|private
interface found: Local Area Connection, description: VMware Accelerated
AMD PCNet Adapter, address(es): 10.5.120.11
2012-04-09
16:05:53|3559|12:12|image|utils.pm:is_valid_ip_address(9266)|IP address
is valid: 129.5.120.48
2012-04-09
16:05:53|3559|12:12|image|utils.pm:is_public_ip_address(9412)|public IP
address: 129.5.120.48, returning 1
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_network_configuration(5107)|public
interface found with default gateway: Local Area Connection 2,
address(es): 129.5.120.48, default gateway: 129.5.120.1
2012-04-09
16:05:53|3559|12:12|image|Windows.pm:get_public_mac_address(5268)|returning
public MAC address: 00-50-56-1A-01-02
2012-04-09
16:05:53|3559|12:12|image|VMware.pm:get_vmx_file_paths(4331)|attempting
to find existing vmx files on the VM host
2012-04-09
16:05:53|3559|12:12|image|VMware.pm:get_vmx_base_directory_path(2745)|determined
vmx base directory path: /vms/datastore1
2012-04-09
16:05:53|3559|12:12|image|Linux.pm:find_files(2074)|attempting to find
files on alpha-vcl, base directory path: '/vms/datastore1/', pattern:
*.vmx, command: find "/vms/datastore1/" -iname "*.vmx"
2012-04-09 16:05:53|3559|12:12|image|Linux.pm:find_files(2092)|matching
file count: 2
2012-04-09
16:05:53|3559|12:12|image|VMware.pm:get_vmx_file_paths(4337)|found 2 vmx
files under /vms/datastore1
|3559|12:12|image| /vms/datastore1/Windows XP Base/Windows XP Base.vmx
|3559|12:12|image| /vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx
2012-04-09
16:05:53|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call
count: 1 (vmsvc/getallvms)
2012-04-09
16:05:54|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(208)|executed command
on VM host alpha-vcl: vmware-vim-cmd vmsvc/getallvms
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:54|3559|12:12|image|VIM_SSH.pm:_get_vm_list(246)|unable to
determine VM IDs, unexpected output returned, VIM command arguments:
'vmsvc/getallvms', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
|3559|12:12|image| ( 0) VIM_SSH.pm, _get_vm_list (line: 246)
|3559|12:12|image| (-1) VIM_SSH.pm, get_registered_vms (line: 826)
|3559|12:12|image| (-2) VMware.pm, get_vmx_file_paths (line: 4340)
|3559|12:12|image| (-3) VMware.pm, get_active_vmx_file_path (line: 774)
|3559|12:12|image| (-4) VMware.pm, capture (line: 467)
|3559|12:12|image| (-5) image.pm, process (line: 162)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:54|3559|12:12|image|VIM_SSH.pm:get_registered_vms(828)|unable to
retrieve registered VMs, failed to retrieve list of registered VMs and
their IDs
|3559|12:12|image| ( 0) VIM_SSH.pm, get_registered_vms (line: 828)
|3559|12:12|image| (-1) VMware.pm, get_vmx_file_paths (line: 4340)
|3559|12:12|image| (-2) VMware.pm, get_active_vmx_file_path (line: 774)
|3559|12:12|image| (-3) VMware.pm, capture (line: 467)
|3559|12:12|image| (-4) image.pm, process (line: 162)
|3559|12:12|image| (-5) vcld, make_new_child (line: 568)
2012-04-09
16:05:54|3559|12:12|image|VMware.pm:get_vmx_file_paths(4341)|found 0
registered vmx files
2012-04-09
16:05:54|3559|12:12|image|VMware.pm:get_vmx_file_paths(4346)|found 2 vmx
files on VM host
|3559|12:12|image| /vms/datastore1/Windows XP Base/Windows XP Base.vmx
|3559|12:12|image| /vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx
2012-04-09
16:05:54|3559|12:12|image|VMware.pm:get_active_vmx_file_path(775)|retrieved
vmx file paths currently residing on the VM host:
|3559|12:12|image| /vms/datastore1/Windows XP Base/Windows XP Base.vmx
|3559|12:12|image| /vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx
2012-04-09
16:05:54|3559|12:12|image|VMware.pm:get_active_vmx_file_path(782)|sorted
vmx file paths so that directories containing vmguest-1 are checked first:
|3559|12:12|image| /vms/datastore1/Windows XP Base/Windows XP Base.vmx
|3559|12:12|image| /vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx
2012-04-09
16:05:54|3559|12:12|image|VMware.pm:get_vmx_info(4405)|attempting to
retrieve info from vmx file: /vms/datastore1/Windows XP Base/Windows XP
Base.vmx
2012-04-09
16:05:54|3559|12:12|image|Linux.pm:get_file_contents(1626)|retrieved 49
lines from file on alpha-vcl: '/vms/datastore1/Windows XP Base/Windows
XP Base.vmx'
2012-04-09 16:05:54|3559|12:12|image|VMware.pm:get_vmx_info(4439)|vmx
file does not contain a computer_id value, attempting to determine
matching computer
2012-04-09
16:05:54|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call
count: 2 (hostsvc/datastore/listsummary)
2012-04-09 16:05:55|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:55
2012-04-09
16:05:55|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(208)|executed command
on VM host alpha-vcl: vmware-vim-cmd hostsvc/datastore/listsummary
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VIM_SSH.pm:_get_datastore_info(490)|unable to
determine datastore names, unexpected output returned, VIM command
arguments: 'hostsvc/datastore/listsummary', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
|3559|12:12|image| ( 0) VIM_SSH.pm, _get_datastore_info (line: 490)
|3559|12:12|image| (-1) VMware.pm, get_datastore_info (line: 5524)
|3559|12:12|image| (-2) VMware.pm, _get_datastore_name (line: 5825)
|3559|12:12|image| (-3) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-4) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-5) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VMware.pm:get_datastore_info(5527)|failed to
retrieve datastore info from VCL::Module::Provisioning::VMware::VIM_SSH
API object
|3559|12:12|image| ( 0) VMware.pm, get_datastore_info (line: 5527)
|3559|12:12|image| (-1) VMware.pm, _get_datastore_name (line: 5825)
|3559|12:12|image| (-2) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-3) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-4) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-5) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VMware.pm:_get_datastore_name(5848)|unable to
determine datastore name from path: '/vms/datastore1/Windows XP
Base/Windows XP Base.vmx', path does not begin with any of the datastore
paths:
|3559|12:12|image| ( 0) VMware.pm, _get_datastore_name (line: 5848)
|3559|12:12|image| (-1) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-2) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-3) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-4) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-5) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VMware.pm:_get_datastore_path(5640)|unable to
determine datastore path, failed to determine datastore name:
/vms/datastore1/Windows XP Base/Windows XP Base.vmx
|3559|12:12|image| ( 0) VMware.pm, _get_datastore_path (line: 5640)
|3559|12:12|image| (-1) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-2) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-3) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-4) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-5) VMware.pm, capture (line: 467)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VMware.pm:_get_parent_directory_name(5963)|unable
to determine parent directory name, path argument could not be converted
to a datastore path: '/vms/datastore1/Windows XP Base/Windows XP Base.vmx'
|3559|12:12|image| ( 0) VMware.pm, _get_parent_directory_name (line: 5963)
|3559|12:12|image| (-1) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-2) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-3) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-4) VMware.pm, capture (line: 467)
|3559|12:12|image| (-5) image.pm, process (line: 162)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:55|3559|12:12|image|VMware.pm:_get_vmx_file_path_computer_name(6150)|unable
to determine computer name from path '/vms/datastore1/Windows XP
Base/Windows XP Base.vmx', directory name could not be determined from path
|3559|12:12|image| ( 0) VMware.pm, _get_vmx_file_path_computer_name
(line: 6150)
|3559|12:12|image| (-1) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-2) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-3) VMware.pm, capture (line: 467)
|3559|12:12|image| (-4) image.pm, process (line: 162)
|3559|12:12|image| (-5) vcld, make_new_child (line: 568)
2012-04-09 16:05:55|3559|12:12|image|VMware.pm:get_vmx_info(4453)|unable
to determine computer name from vmx file path: '/vms/datastore1/Windows
XP Base/Windows XP Base.vmx'
2012-04-09
16:05:55|3559|12:12|image|VMware.pm:get_vmx_info(4462)|ignoring ide1:0,
filename property not set
2012-04-09 16:05:55|3559|12:12|image|VMware.pm:get_vmx_info(4484)|vmdk
path appears to be relative: Windows XP Base.vmdk, prepending the vmx
directory: /vms/datastore1/Windows XP Base/Windows XP Base.vmdk
2012-04-09
16:05:55|3559|12:12|image|VMware.pm:get_active_vmx_file_path(812)|comparing
MAC addresses
|3559|12:12|image| used by vmguest-1:
|3559|12:12|image| 0050561a0101
|3559|12:12|image| 0050561a0102
|3559|12:12|image| configured in Windows XP Base.vmx:
|3559|12:12|image| 000c29be1c01
|3559|12:12|image| 000c29be1c0b
|3559|12:12|image| 0050561a0101
|3559|12:12|image| 0050561a0102
2012-04-09
16:05:55|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call
count: 3 (vmsvc/getallvms)
2012-04-09
16:05:56|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(208)|executed command
on VM host alpha-vcl: vmware-vim-cmd vmsvc/getallvms
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:56|3559|12:12|image|VIM_SSH.pm:_get_vm_list(246)|unable to
determine VM IDs, unexpected output returned, VIM command arguments:
'vmsvc/getallvms', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
|3559|12:12|image| ( 0) VIM_SSH.pm, _get_vm_list (line: 246)
|3559|12:12|image| (-1) VIM_SSH.pm, get_registered_vms (line: 826)
|3559|12:12|image| (-2) VMware.pm, is_vm_registered (line: 3738)
|3559|12:12|image| (-3) VMware.pm, get_active_vmx_file_path (line: 821)
|3559|12:12|image| (-4) VMware.pm, capture (line: 467)
|3559|12:12|image| (-5) image.pm, process (line: 162)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:56|3559|12:12|image|VIM_SSH.pm:get_registered_vms(828)|unable to
retrieve registered VMs, failed to retrieve list of registered VMs and
their IDs
|3559|12:12|image| ( 0) VIM_SSH.pm, get_registered_vms (line: 828)
|3559|12:12|image| (-1) VMware.pm, is_vm_registered (line: 3738)
|3559|12:12|image| (-2) VMware.pm, get_active_vmx_file_path (line: 821)
|3559|12:12|image| (-3) VMware.pm, capture (line: 467)
|3559|12:12|image| (-4) image.pm, process (line: 162)
|3559|12:12|image| (-5) vcld, make_new_child (line: 568)
2012-04-09 16:05:56|3559|12:12|image|VMware.pm:is_vm_registered(3747)|VM
is not registered: '/vms/datastore1/Windows XP Base/Windows XP Base.vmx'
2012-04-09
16:05:56|3559|12:12|image|VMware.pm:get_active_vmx_file_path(822)|ignoring
Windows XP Base.vmx because the VM is not registered
2012-04-09
16:05:56|3559|12:12|image|VMware.pm:get_vmx_info(4405)|attempting to
retrieve info from vmx file: /vms/datastore1/Windows XP Base/t2/Windows
XP Base.vmx
2012-04-09
16:05:56|3559|12:12|image|Linux.pm:get_file_contents(1626)|retrieved 48
lines from file on alpha-vcl: '/vms/datastore1/Windows XP
Base/t2/Windows XP Base.vmx'
2012-04-09 16:05:56|3559|12:12|image|VMware.pm:get_vmx_info(4439)|vmx
file does not contain a computer_id value, attempting to determine
matching computer
2012-04-09
16:05:56|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call
count: 4 (hostsvc/datastore/listsummary)
2012-04-09
16:05:57|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(208)|executed command
on VM host alpha-vcl: vmware-vim-cmd hostsvc/datastore/listsummary
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VIM_SSH.pm:_get_datastore_info(490)|unable to
determine datastore names, unexpected output returned, VIM command
arguments: 'hostsvc/datastore/listsummary', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
|3559|12:12|image| ( 0) VIM_SSH.pm, _get_datastore_info (line: 490)
|3559|12:12|image| (-1) VMware.pm, get_datastore_info (line: 5524)
|3559|12:12|image| (-2) VMware.pm, _get_datastore_name (line: 5825)
|3559|12:12|image| (-3) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-4) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-5) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VMware.pm:get_datastore_info(5527)|failed to
retrieve datastore info from VCL::Module::Provisioning::VMware::VIM_SSH
API object
|3559|12:12|image| ( 0) VMware.pm, get_datastore_info (line: 5527)
|3559|12:12|image| (-1) VMware.pm, _get_datastore_name (line: 5825)
|3559|12:12|image| (-2) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-3) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-4) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-5) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VMware.pm:_get_datastore_name(5848)|unable to
determine datastore name from path: '/vms/datastore1/Windows XP
Base/t2/Windows XP Base.vmx', path does not begin with any of the
datastore paths:
|3559|12:12|image| ( 0) VMware.pm, _get_datastore_name (line: 5848)
|3559|12:12|image| (-1) VMware.pm, _get_datastore_path (line: 5638)
|3559|12:12|image| (-2) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-3) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-4) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-5) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VMware.pm:_get_datastore_path(5640)|unable to
determine datastore path, failed to determine datastore name:
/vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx
|3559|12:12|image| ( 0) VMware.pm, _get_datastore_path (line: 5640)
|3559|12:12|image| (-1) VMware.pm, _get_parent_directory_name (line: 5961)
|3559|12:12|image| (-2) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-3) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-4) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-5) VMware.pm, capture (line: 467)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VMware.pm:_get_parent_directory_name(5963)|unable
to determine parent directory name, path argument could not be converted
to a datastore path: '/vms/datastore1/Windows XP Base/t2/Windows XP
Base.vmx'
|3559|12:12|image| ( 0) VMware.pm, _get_parent_directory_name (line: 5963)
|3559|12:12|image| (-1) VMware.pm, _get_vmx_file_path_computer_name
(line: 6148)
|3559|12:12|image| (-2) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-3) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-4) VMware.pm, capture (line: 467)
|3559|12:12|image| (-5) image.pm, process (line: 162)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:57|3559|12:12|image|VMware.pm:_get_vmx_file_path_computer_name(6150)|unable
to determine computer name from path '/vms/datastore1/Windows XP
Base/t2/Windows XP Base.vmx', directory name could not be determined
from path
|3559|12:12|image| ( 0) VMware.pm, _get_vmx_file_path_computer_name
(line: 6150)
|3559|12:12|image| (-1) VMware.pm, get_vmx_info (line: 4441)
|3559|12:12|image| (-2) VMware.pm, get_active_vmx_file_path (line: 792)
|3559|12:12|image| (-3) VMware.pm, capture (line: 467)
|3559|12:12|image| (-4) image.pm, process (line: 162)
|3559|12:12|image| (-5) vcld, make_new_child (line: 568)
2012-04-09 16:05:57|3559|12:12|image|VMware.pm:get_vmx_info(4453)|unable
to determine computer name from vmx file path: '/vms/datastore1/Windows
XP Base/t2/Windows XP Base.vmx'
2012-04-09
16:05:57|3559|12:12|image|VMware.pm:get_vmx_info(4462)|ignoring ide1:0,
filename property not set
2012-04-09 16:05:57|3559|12:12|image|VMware.pm:get_vmx_info(4484)|vmdk
path appears to be relative: Windows XP Base.vmdk, prepending the vmx
directory: /vms/datastore1/Windows XP Base/t2/Windows XP Base.vmdk
2012-04-09
16:05:57|3559|12:12|image|VMware.pm:get_active_vmx_file_path(812)|comparing
MAC addresses
|3559|12:12|image| used by vmguest-1:
|3559|12:12|image| 0050561a0101
|3559|12:12|image| 0050561a0102
|3559|12:12|image| configured in Windows XP Base.vmx:
|3559|12:12|image| 000c29be1c01
|3559|12:12|image| 000c29be1c0b
|3559|12:12|image| 0050561a0101
2012-04-09
16:05:57|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call
count: 5 (vmsvc/getallvms)
2012-04-09
16:05:58|3559|12:12|image|VIM_SSH.pm:_run_vim_cmd(208)|executed command
on VM host alpha-vcl: vmware-vim-cmd vmsvc/getallvms
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|VIM_SSH.pm:_get_vm_list(246)|unable to
determine VM IDs, unexpected output returned, VIM command arguments:
'vmsvc/getallvms', output:
|3559|12:12|image| Failed to login: vim.fault.NoPermission
|3559|12:12|image| ( 0) VIM_SSH.pm, _get_vm_list (line: 246)
|3559|12:12|image| (-1) VIM_SSH.pm, get_registered_vms (line: 826)
|3559|12:12|image| (-2) VMware.pm, is_vm_registered (line: 3738)
|3559|12:12|image| (-3) VMware.pm, get_active_vmx_file_path (line: 821)
|3559|12:12|image| (-4) VMware.pm, capture (line: 467)
|3559|12:12|image| (-5) image.pm, process (line: 162)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|VIM_SSH.pm:get_registered_vms(828)|unable to
retrieve registered VMs, failed to retrieve list of registered VMs and
their IDs
|3559|12:12|image| ( 0) VIM_SSH.pm, get_registered_vms (line: 828)
|3559|12:12|image| (-1) VMware.pm, is_vm_registered (line: 3738)
|3559|12:12|image| (-2) VMware.pm, get_active_vmx_file_path (line: 821)
|3559|12:12|image| (-3) VMware.pm, capture (line: 467)
|3559|12:12|image| (-4) image.pm, process (line: 162)
|3559|12:12|image| (-5) vcld, make_new_child (line: 568)
2012-04-09 16:05:58|3559|12:12|image|VMware.pm:is_vm_registered(3747)|VM
is not registered: '/vms/datastore1/Windows XP Base/t2/Windows XP Base.vmx'
2012-04-09
16:05:58|3559|12:12|image|VMware.pm:get_active_vmx_file_path(822)|ignoring
Windows XP Base.vmx because the VM is not registered
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|VMware.pm:get_active_vmx_file_path(840)|did
not find any vmx files on the VM host containing a MAC address matching
vmguest-1
|3559|12:12|image| ( 0) VMware.pm, get_active_vmx_file_path (line: 840)
|3559|12:12|image| (-1) VMware.pm, capture (line: 467)
|3559|12:12|image| (-2) image.pm, process (line: 162)
|3559|12:12|image| (-3) vcld, make_new_child (line: 568)
|3559|12:12|image| (-4) vcld, main (line: 346)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|VMware.pm:capture(469)|failed to determine the
vmx file path actively being used by VM vmguest-1
|3559|12:12|image| ( 0) VMware.pm, capture (line: 469)
|3559|12:12|image| (-1) image.pm, process (line: 162)
|3559|12:12|image| (-2) vcld, make_new_child (line: 568)
|3559|12:12|image| (-3) vcld, main (line: 346)
|3559|12:12|image| ---- WARNING ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|image.pm:process(166)|vmwarewinxp-WinXPBase19-v0
image failed to be captured by provisioning module
|3559|12:12|image| ( 0) image.pm, process (line: 166)
|3559|12:12|image| (-1) vcld, make_new_child (line: 568)
|3559|12:12|image| (-2) vcld, main (line: 346)
2012-04-09
16:05:58|3559|12:12|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning
private IP address previously retrieved: 10.5.120.11
2012-04-09
16:05:58|3559|12:12|image|utils.pm:is_inblockrequest(6163)|zero rows
were returned from database select
2012-04-09
16:05:58|3559|12:12|image|DataStructure.pm:get_image_affiliation_name(2035)|image
owner id: 1
2012-04-09 16:05:58|3559|12:12|image|utils.pm:getnewdbh(2709)|database
requested (information_schema) does not match handle stored in $ENV{dbh}
(vcl:hcr08672.ewp.rpi.edu)
2012-04-09 16:05:58|3559|12:12|image|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2012-04-09
16:05:58|3559|12:12|image|DataStructure.pm:retrieve_user_data(1352)|attempting
to retrieve and store data for user: user.id = '1'
2012-04-09 16:05:58|3559|12:12|image|utils.pm:getnewdbh(2709)|database
requested (vcl) does not match handle stored in $ENV{dbh}
(information_schema:hcr08672.ewp.rpi.edu)
2012-04-09 16:05:58|3559|12:12|image|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2012-04-09
16:05:58|3559|12:12|image|DataStructure.pm:retrieve_user_data(1415)|data
has been retrieved for user: admin (id: 1)
2012-04-09 16:05:59|3559|12:12|image|utils.pm:mail(1255)|SUCCESS --
Sending mail To: vcl_adminu...@ewp.rpi.edu, PROBLEM --
12:12|image|image.pm|vmguest-1>alpha-vcl.ewp.rpi.edu|vmwarewinxp-WinXPBase19-v0|admin
|3559|12:12|image| ---- CRITICAL ----
|3559|12:12|image| 2012-04-09
16:05:58|3559|12:12|image|image.pm:reservation_failed(385)|vmwarewinxp-WinXPBase19-v0
image creation failed
|3559|12:12|image| ( 0) image.pm, reservation_failed (line: 385)
|3559|12:12|image| (-1) image.pm, process (line: 167)
|3559|12:12|image| (-2) vcld, make_new_child (line: 568)
|3559|12:12|image| (-3) vcld, main (line: 346)
2012-04-09 16:05:59|3559|12:12|image|utils.pm:mail(1255)|SUCCESS --
Sending mail To: root@localhost, VCL -- NOTICE DELAY Image Creation
WinXP Base
2012-04-09 16:05:59|3559|12:12|image|utils.pm:mail(1255)|SUCCESS --
Sending mail To: vcl_adminu...@ewp.rpi.edu, VCL -- NOTICE FAILED Image
Creation WinXP Base
2012-04-09
16:05:59|3559|12:12|image|utils.pm:update_request_state(1991)|request 12
state updated to: maintenance, laststate to: image
2012-04-09
16:05:59|3559|12:12|image|image.pm:reservation_failed(437)|request state
set to maintenance, laststate to image
2012-04-09
16:05:59|3559|12:12|image|utils.pm:update_computer_state(2033)|computer
2 state updated to: maintenance
2012-04-09
16:05:59|3559|12:12|image|image.pm:reservation_failed(445)|vmguest-1
state set to maintenance
2012-04-09
16:05:59|3559|12:12|image|image.pm:reservation_failed(452)|exiting
2012-04-09 16:05:59|3559|12:12|image|State.pm:DESTROY(829)|VCL::image
destructor called, address: 17e256b0
2012-04-09
16:05:59|3559|12:12|image|utils.pm:delete_computerloadlog_reservation(6742)|removing
computerloadlog entries matching loadstate = begin
2012-04-09
16:05:59|3559|12:12|image|utils.pm:delete_computerloadlog_reservation(6789)|deleted
rows from computerloadlog for reservation id=12
2012-04-09 16:05:59|3559|12:12|image|State.pm:DESTROY(848)|number of
database handles state process created: 3
2012-04-09 16:05:59|3559|12:12|image|State.pm:DESTROY(876)|VCL::image
process duration: 14 seconds
2012-04-09 16:05:59|3559|12:12|image|VIM_SSH.pm:DESTROY(1685)|vim-cmd
call count: 5
2012-04-09 16:05:59|3519|vcld:REAPER(718)|VCL process exited for
reservation 12, PID: 3559, signal: CHLD
2012-04-09 16:05:59|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:05:59
2012-04-09 16:06:04|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:06:04
2012-04-09 16:06:09|3519|vcld:main(167)|lastcheckin time updated for
management node 1: 2012-04-09 16:06:09
[root@alpha-vcl ~]#
--
--
Brian Hartlieb
System Administrator
TIS - Rensselaer at Hartford
Rensselaer Polytechnic Institute (RPI)
(860) 548-5459
har...@rpi.edu
