4Zwmi3Ha

12011-08-09 10:35:14|24415|56405:56141|new|utils.pm:update_computer_imagename(6036)|successfully retreived image info for noimage
22011-08-09 10:35:14|24415|56405:56141|new|utils.pm:update_currentimage(6088)|updating computer 68: image=4, imagerevision=4
32011-08-09 10:35:14|24415|56405:56141|new|utils.pm:update_currentimage(6118)|updated currentimageid and imagerevision id for computer id 68
42011-08-09 10:35:14|24415|56405:56141|new|utils.pm:update_computer_imagename(6048)|successfully updated computerid= 68 image_id= 4 imagerevision_id= 4
52011-08-09 10:35:14|24415|56405:56141|new|VMware.pm:remove_existing_vms(1412)|set computer vmguest-64 current image to 'noimage'
62011-08-09 10:35:14|24415|56405:56141|new|VMware.pm:check_vmhost_disk_space(2041)|checking if enough space is available on VM host vclesxi22
72011-08-09 10:35:14|24415|56405:56141|new|VMware.pm:is_vmx_vmdk_volume_shared(1943)|vmx and vmdk base directory paths are identical: '/vmfs/volumes/netappfiler02-sata1', they are on the same volume
82011-08-09 10:35:15|24415|56405:56141|new|Linux.pm:get_available_space(1696)|space available on volume on vclesxi22 containing '/vmfs/volumes/netappfiler02-sata1': 3,164,176,338,944 bytes, 3,017,593.7 MB, 2,946.87 GB, 2.88 TB
92011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_vm_additional_vmx_bytes_required(4700)|1610612736 additional bytes required for VM vmem file
102011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_vm_additional_vmx_bytes_required(4705)|no additional space required for REDO files because VM disk mode is persistent
112011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_vm_additional_vmx_bytes_required(4716)|estimate of additional space required for the vmx directory:
12|24415|56405:56141|new| vmem/vswp file: 1,610,612,736 bytes, 1,536.0 MB, 1.50 GB
13|24415|56405:56141|new| redo files: 0 bytes, 0.0 MB, 0.00 GB
14|24415|56405:56141|new| total: 1,610,612,736 bytes, 1,536.0 MB, 1.50 GB
152011-08-09 10:35:15|24415|56405:56141|new|Linux.pm:file_exists(1390)|file or directory does not exist on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk'
162011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_repository_vmdk_base_directory_path(3597)|repository path is not configured in the VM profile
172011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_image_size_bytes(3835)|image repository path is not configured in the VM profile, image size will NOT be retrieved from image repository
182011-08-09 10:35:15|24415|56405:56141|new|Linux.pm:get_file_size(2022)|size of '/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6*.vmdk' on vclesxi22:
19|24415|56405:56141|new| used: 13,697,025,103 bytes, 13,062.5 MB, 12.76 GB
20|24415|56405:56141|new| allocated: 13,723,996,160 bytes, 13,088.2 MB, 12.78 GB
212011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_image_size_bytes(3841)|retrieved the size of the image from the datastore on the VM host: 13,697,025,103
222011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_image_size_bytes(3871)|size of vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 image:
23|24415|56405:56141|new| 13,697,025,103 bytes
24|24415|56405:56141|new| 13,063 MB
25|24415|56405:56141|new| 12.76 GB
262011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_vm_additional_vmdk_bytes_required(4654)|13697025103 additional bytes required because vmdk files do NOT already exist on VM host
272011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:get_vm_additional_vmdk_bytes_required(4662)|VM requires appoximately 13697025103 additional bytes (13,063 MB, 13 GB) of disk space on the VM host for the vmdk directory
282011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:check_vmhost_disk_space(2070)|enough space is available on shared vmx/vmdk volume on VM host vclesxi22: '/vmfs/volumes/netappfiler02-sata1'
29|24415|56405:56141|new| vmx additional space required:          1,610,612,736 bytes, 1,536.0 MB, 1.50 GB
30|24415|56405:56141|new| vmdk additional space required:         13,697,025,103 bytes, 13,062.5 MB, 12.76 GB
31|24415|56405:56141|new| total additional space required:        15,307,637,839 bytes, 14,598.5 MB, 14.26 GB
32|24415|56405:56141|new| shared vmx/vmdk volume available space: 3,164,176,338,944 bytes, 3,017,593.7 MB, 2,946.87 GB, 2.88 TB
332011-08-09 10:35:15|24415|56405:56141|new|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a133990, returning 1
342011-08-09 10:35:15|24415|56405:56141|new|Module.pm:new(203)|VCL::Module::Semaphore object created, address: 1b2d32e0
352011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(742)|attempting to open lockfile, maximum of 1200 seconds
362011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(759)|attempt 1: attempting to open lockfile
372011-08-09 10:35:15|24415|56405:56141|new|Semaphore.pm:open_lockfile(146)|opened and obtained an exclusive lock on file: /tmp/vmfs-volumes-netappfiler02-sata1-vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.lock
382011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(762)|attempting to open lockfile, code returned true
392011-08-09 10:35:15|24415|56405:56141|new|Module.pm:get_semaphore(844)|created Semaphore object, memory address: 1b2d32e0
402011-08-09 10:35:15|24415|56405:56141|new|Linux.pm:file_exists(1404)|'/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.vmdk' exists on vclesxi22, files: 1, directories: 0, links: 0
412011-08-09 10:35:15|24415|56405:56141|new|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a133990, returning 1
422011-08-09 10:35:15|24415|56405:56141|new|Module.pm:new(203)|VCL::Module::Semaphore object created, address: 1ad38c30
432011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(742)|attempting to open lockfile, maximum of 60 seconds
442011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(759)|attempt 1: attempting to open lockfile
452011-08-09 10:35:15|24415|56405:56141|new|Semaphore.pm:open_lockfile(146)|opened and obtained an exclusive lock on file: /tmp/vmfs-volumes-netappfiler02-sata1-vmguest-64_44-v6.lock
462011-08-09 10:35:15|24415|56405:56141|new|Module.pm:code_loop_timeout(762)|attempting to open lockfile, code returned true
472011-08-09 10:35:15|24415|56405:56141|new|Module.pm:get_semaphore(844)|created Semaphore object, memory address: 1ad38c30
482011-08-09 10:35:15|24415|56405:56141|new|Semaphore.pm:release_lockfile(248)|deleted file: /tmp/vmfs-volumes-netappfiler02-sata1-vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.lock
492011-08-09 10:35:15|24415|56405:56141|new|Semaphore.pm:DESTROY(281)|destroyed Semaphore object, memory address: 1b2d32e0
502011-08-09 10:35:15|24415|56405:56141|new|Linux.pm:file_exists(1390)|file or directory does not exist on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6'
512011-08-09 10:35:15|24415|56405:56141|new|VMware.pm:prepare_vmdk(1812)|VM is persistent and nonpersistent vmdk exists on the VM host vclesxi22, attempting to make a copy
522011-08-09 10:35:16|24415|56405:56141|new|VMware.pm:get_vmhost_product_name(5405)|VMware product being used on VM host vclesxi22: 'VMware ESXi 4.1.0 build-348481'
532011-08-09 10:35:16|24415|56405:56141|new|Linux.pm:file_exists(1404)|'/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.vmdk' exists on vclesxi22, files: 1, directories: 0, links: 0
542011-08-09 10:35:16|24415|56405:56141|new|Linux.pm:file_exists(1390)|file or directory does not exist on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk'
552011-08-09 10:35:16|24415|56405:56141|new|Linux.pm:create_directory(1520)|directory created on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6'
562011-08-09 10:35:16|24415|56405:56141|new|VMware.pm:copy_vmdk(4816)|attempting to copy virtual disk using vmkfstools, disk type: thin:
57|24415|56405:56141|new| '/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.vmdk' --> '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk'
582011-08-09 10:40:13|24415|56405:56141|new|VMware.pm:copy_vmdk(4840)|copied virtual disk on VM host using vmkfstools, destination disk type: thin:
59|24415|56405:56141|new| '/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.vmdk' --> '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk'
602011-08-09 10:40:13|24415|56405:56141|new|Linux.pm:get_file_size(2022)|size of '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6*.vmdk' on vclesxi22:
61|24415|56405:56141|new| used: 21,474,837,033 bytes, 20,480.0 MB, 20.00 GB
62|24415|56405:56141|new| allocated: 13,684,682,752 bytes, 13,050.7 MB, 12.74 GB
632011-08-09 10:40:13|24415|56405:56141|new|VMware.pm:copy_vmdk(4960)|copied vmdk on VM host vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6/vmwarewinxp-SPSSPASWStatisticsAmos1844-v6.vmdk' --> '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk'
64|24415|56405:56141|new| time to copy: 4:57 (297 seconds)
65|24415|56405:56141|new| ---
66|24415|56405:56141|new| bits copied:  171,798,696,264 (171798696264)
67|24415|56405:56141|new| bytes copied: 21,474,837,033 (21474837033)
68|24415|56405:56141|new| MB copied:    20,480.0
69|24415|56405:56141|new| GB copied:    20.00
70|24415|56405:56141|new| ---
71|24415|56405:56141|new| B/m:    4,338,350,916
72|24415|56405:56141|new| MB/m:   4,137.4
73|24415|56405:56141|new| GB/m:   4.04
74|24415|56405:56141|new| ---
75|24415|56405:56141|new| B/s:    72,305,849
76|24415|56405:56141|new| MB/s:   69.0
77|24415|56405:56141|new| GB/s:   0.07
78|24415|56405:56141|new| ---
79|24415|56405:56141|new| Mbit/s: 551.6
80|24415|56405:56141|new| Gbit/s: 0.54
812011-08-09 10:40:13|24415|56405:56141|new|VMware.pm:prepare_vmdk(1814)|copied vmdk from nonpersistent to persistent directory on VM host vclesxi22
822011-08-09 10:40:13|24415|56405:56141|new|Semaphore.pm:release_lockfile(248)|deleted file: /tmp/vmfs-volumes-netappfiler02-sata1-vmguest-64_44-v6.lock
832011-08-09 10:40:13|24415|56405:56141|new|Semaphore.pm:DESTROY(281)|destroyed Semaphore object, memory address: 1ad38c30
842011-08-09 10:40:13|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, transfervm, copied vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 to vmguest-64
852011-08-09 10:40:13|24415|56405:56141|new|VMware.pm:get_vm_os_configuration(4210)|retrieved default VM configuration for OS: xp-x86
86|24415|56405:56141|new| : {
87|24415|56405:56141|new| :   "ethernet-virtualDev" => "vlance",
88|24415|56405:56141|new| :   "guestOS" => "winXPPro",
89|24415|56405:56141|new| :   "scsi-virtualDev" => "busLogic"
90|24415|56405:56141|new| : }
912011-08-09 10:40:13|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 43 (hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6")
922011-08-09 10:40:14|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6"
932011-08-09 10:40:14|24415|56405:56141|new|VIM_SSH.pm:get_virtual_disk_controller_type(1445)|retrieved controller type for vmguest-64_44-v6.vmdk: 'IDE'
942011-08-09 10:40:14|24415|56405:56141|new|VMware.pm:get_vm_disk_adapter_type(4065)|retrieved VM disk adapter type from api object: IDE
952011-08-09 10:40:14|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 44 (hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6")
962011-08-09 10:40:14|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6"
972011-08-09 10:40:14|24415|56405:56141|new|VIM_SSH.pm:get_virtual_disk_hardware_version(1593)|retrieved hardware version for vmguest-64_44-v6.vmdk: '4'
982011-08-09 10:40:14|24415|56405:56141|new|VMware.pm:get_vm_virtual_hardware_version(4112)|retrieved hardware version from api object: 4
992011-08-09 10:40:15|24415|56405:56141|new|VMware.pm:get_vmhost_product_name(5405)|VMware product being used on VM host vclesxi22: 'VMware ESXi 4.1.0 build-348481'
1002011-08-09 10:40:15|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 45 (hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6")
1012011-08-09 10:40:15|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd hostsvc/datastorebrowser/searchsubfolders 0 "[netappfiler02-sata1] vmguest-64_44-v6"
1022011-08-09 10:40:15|24415|56405:56141|new|VIM_SSH.pm:get_virtual_disk_controller_type(1445)|retrieved controller type for vmguest-64_44-v6.vmdk: 'IDE'
1032011-08-09 10:40:15|24415|56405:56141|new|VMware.pm:get_vm_disk_adapter_type(4065)|retrieved VM disk adapter type from api object: IDE
1042011-08-09 10:40:15|24415|56405:56141|new|VMware.pm:get_vm_virtual_hardware_version(4143)|overriding hardware version 4 --> 7, IDE adapters cannot be used on ESX unless the hardware version is 7 or higher, VMware product: 'VMware ESXi 4.1.0 build-348481', vmdk adapter type: IDE, vmdk hardware version: 4
1052011-08-09 10:40:15|24415|56405:56141|new|VMware.pm:get_vmhost_product_name(5405)|VMware product being used on VM host vclesxi22: 'VMware ESXi 4.1.0 build-348481'
106|24415|56405:56141|new| ---- WARNING ---- 
107|24415|56405:56141|new| 2011-08-09 10:40:15|24415|56405:56141|new|DataStructure.pm:_automethod(812)|corresponding data has not been initialized for get_reservation_password: $self->request_data->{reservation}{56141}{pw}
108|24415|56405:56141|new| ( 0) DataStructure.pm, _automethod (line: 812)
109|24415|56405:56141|new| (-1) Autoload.pm, __ANON__ (line: 80)
110|24415|56405:56141|new| (-2) VMware.pm, prepare_vmx (line: 1466)
111|24415|56405:56141|new| (-3) VMware.pm, load (line: 394)
112|24415|56405:56141|new| (-4) new.pm, reload_image (line: 618)
113|24415|56405:56141|new| (-5) new.pm, process (line: 248)
1142011-08-09 10:40:16|24415|56405:56141|new|Linux.pm:create_directory(1524)|directory already exists on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6'
1152011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1502)|vm info:
116|24415|56405:56141|new| display name: vmguest-64:vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 (persistent)
117|24415|56405:56141|new| image ID: 44
118|24415|56405:56141|new| imagerevision ID: 249
119|24415|56405:56141|new| vmx path: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx
120|24415|56405:56141|new| vmx directory name: vmguest-64_44-v6
121|24415|56405:56141|new| vmx directory path: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6
122|24415|56405:56141|new| vmdk file path: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk
123|24415|56405:56141|new| persistent: 1
124|24415|56405:56141|new| computer ID: 68
125|24415|56405:56141|new| computer name: vmguest-64
126|24415|56405:56141|new| image name: vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
127|24415|56405:56141|new| guest OS: winXPPro
128|24415|56405:56141|new| virtual hardware version: 7
129|24415|56405:56141|new| RAM: 1536
130|24415|56405:56141|new| CPU count: 1
131|24415|56405:56141|new| ethernet adapter type: vlance
132|24415|56405:56141|new| virtual switch 0: VLAN-private
133|24415|56405:56141|new| eth0 MAC address: 00:50:56:2a:3b:80
134|24415|56405:56141|new| virtual switch 1: VLAN-public
135|24415|56405:56141|new| eth1 MAC address: 00:50:56:2a:3b:81
136|24415|56405:56141|new| disk adapter type: IDE
137|24415|56405:56141|new| disk mode: independent-persistent
138|24415|56405:56141|new| disk write through: TRUE
1392011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1689)|image project is: vcl, additional network adapters will not be configured
1402011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1692)|vmx parameters:
141|24415|56405:56141|new| : {
142|24415|56405:56141|new| :   "#computer_id" => 68,
143|24415|56405:56141|new| :   "#image_id" => 44,
144|24415|56405:56141|new| :   "#imagerevision_id" => 249,
145|24415|56405:56141|new| :   ".encoding" => "UTF-8",
146|24415|56405:56141|new| :   "MemTrimRate" => 0,
147|24415|56405:56141|new| :   "config.version" => 8,
148|24415|56405:56141|new| :   "disk.locking" => "false",
149|24415|56405:56141|new| :   "displayName" => "vmguest-64:vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 (persistent)",
150|24415|56405:56141|new| :   "ethernet0.address" => "00:50:56:2a:3b:80",
151|24415|56405:56141|new| :   "ethernet0.addressType" => "static",
152|24415|56405:56141|new| :   "ethernet0.connectionType" => "custom",
153|24415|56405:56141|new| :   "ethernet0.networkName" => "VLAN-private",
154|24415|56405:56141|new| :   "ethernet0.present" => "TRUE",
155|24415|56405:56141|new| :   "ethernet0.virtualDev" => "vlance",
156|24415|56405:56141|new| :   "ethernet1.address" => "00:50:56:2a:3b:81",
157|24415|56405:56141|new| :   "ethernet1.addressType" => "static",
158|24415|56405:56141|new| :   "ethernet1.connectionType" => "custom",
159|24415|56405:56141|new| :   "ethernet1.networkName" => "VLAN-public",
160|24415|56405:56141|new| :   "ethernet1.present" => "TRUE",
161|24415|56405:56141|new| :   "ethernet1.virtualDev" => "vlance",
162|24415|56405:56141|new| :   "floppy0.present" => "FALSE",
163|24415|56405:56141|new| :   "guestOS" => "winXPPro",
164|24415|56405:56141|new| :   "gui.exitOnCLIHLT" => "TRUE",
165|24415|56405:56141|new| :   "ide0:0.fileName" => "/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmdk",
166|24415|56405:56141|new| :   "ide0:0.mode" => "independent-persistent",
167|24415|56405:56141|new| :   "ide0:0.present" => "TRUE",
168|24415|56405:56141|new| :   "ide0:0.sharedBus" => "none",
169|24415|56405:56141|new| :   "ide0:0.writeThrough" => "TRUE",
170|24415|56405:56141|new| :   "mainMem.useNamedFile" => "FALSE",
171|24415|56405:56141|new| :   "memsize" => 1536,
172|24415|56405:56141|new| :   "msg.autoAnswer" => "TRUE",
173|24415|56405:56141|new| :   "numvcpus" => 1,
174|24415|56405:56141|new| :   "pciBridge0.present" => "TRUE",
175|24415|56405:56141|new| :   "pciBridge4.functions" => 8,
176|24415|56405:56141|new| :   "pciBridge4.present" => "TRUE",
177|24415|56405:56141|new| :   "pciBridge4.virtualDev" => "pcieRootPort",
178|24415|56405:56141|new| :   "pciBridge5.functions" => 8,
179|24415|56405:56141|new| :   "pciBridge5.present" => "TRUE",
180|24415|56405:56141|new| :   "pciBridge5.virtualDev" => "pcieRootPort",
181|24415|56405:56141|new| :   "pciBridge6.functions" => 8,
182|24415|56405:56141|new| :   "pciBridge6.present" => "TRUE",
183|24415|56405:56141|new| :   "pciBridge6.virtualDev" => "pcieRootPort",
184|24415|56405:56141|new| :   "pciBridge7.functions" => 8,
185|24415|56405:56141|new| :   "pciBridge7.present" => "TRUE",
186|24415|56405:56141|new| :   "pciBridge7.virtualDev" => "pcieRootPort",
187|24415|56405:56141|new| :   "powerType.powerOff" => "soft",
188|24415|56405:56141|new| :   "powerType.powerOn" => "hard",
189|24415|56405:56141|new| :   "powerType.reset" => "soft",
190|24415|56405:56141|new| :   "powerType.suspend" => "hard",
191|24415|56405:56141|new| :   "sched.mem.pshare.enable" => "FALSE",
192|24415|56405:56141|new| :   "snapshot.disabled" => "TRUE",
193|24415|56405:56141|new| :   "svga.autodetect" => "TRUE",
194|24415|56405:56141|new| :   "toolScripts.afterPowerOn" => "FALSE",
195|24415|56405:56141|new| :   "toolScripts.afterResume" => "FALSE",
196|24415|56405:56141|new| :   "toolScripts.beforePowerOff" => "FALSE",
197|24415|56405:56141|new| :   "toolScripts.beforeSuspend" => "FALSE",
198|24415|56405:56141|new| :   "tools.remindInstall" => "FALSE",
199|24415|56405:56141|new| :   "tools.syncTime" => "FALSE",
200|24415|56405:56141|new| :   "uuid.action" => "keep",
201|24415|56405:56141|new| :   "virtualHW.version" => 7,
202|24415|56405:56141|new| :   "vmci0.present" => "TRUE"
203|24415|56405:56141|new| : }
2042011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1703)|created temporary vmx file: /tmp/vmguest-64_44-v6.vmx
2052011-08-09 10:40:16|24415|56405:56141|new|Linux.pm:create_directory(1524)|directory already exists on vclesxi22: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6'
2062011-08-09 10:40:16|24415|56405:56141|new|utils.pm:run_scp_command(5600)|attempting to copy file via SCP: '/tmp/vmguest-64_44-v6.vmx' --> 'vclesxi22:"/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx"'
2072011-08-09 10:40:16|24415|56405:56141|new|utils.pm:run_scp_command(5636)|copied file via SCP: '/tmp/vmguest-64_44-v6.vmx' --> 'vclesxi22:"/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx"'
2082011-08-09 10:40:16|24415|56405:56141|new|Linux.pm:copy_file_to(1859)|copied file from management node to vclesxi22: '/tmp/vmguest-64_44-v6.vmx' --> vclesxi22:'/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx'
2092011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1715)|created vmx file on VM host: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx
2102011-08-09 10:40:16|24415|56405:56141|new|VMware.pm:prepare_vmx(1718)|deleted temporary vmx file: /tmp/vmguest-64_44-v6.vmx
2112011-08-09 10:40:16|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, vmsetupconfig, prepared vmx file
2122011-08-09 10:40:16|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 46 (vmsvc/getallvms)
2132011-08-09 10:40:17|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/getallvms
2142011-08-09 10:40:17|24415|56405:56141|new|VIM_SSH.pm:get_registered_vms(835)|found 17 registered VMs
2152011-08-09 10:40:17|24415|56405:56141|new|VMware.pm:is_vm_registered(3747)|VM is not registered: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx'
2162011-08-09 10:40:17|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 47 (solo/registervm "/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx")
2172011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd solo/registervm "/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx"
2182011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 48 (vmsvc/getallvms)
2192011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/getallvms
2202011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:get_registered_vms(835)|found 18 registered VMs
2212011-08-09 10:40:18|24415|56405:56141|new|VMware.pm:is_vm_registered(3742)|VM is registered: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx
2222011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:vm_register(1105)|registered VM: '/vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx'
2232011-08-09 10:40:18|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 49 (vmsvc/getallvms)
2242011-08-09 10:40:19|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/getallvms
2252011-08-09 10:40:19|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 50 (vmsvc/power.on 560)
2262011-08-09 10:40:20|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/power.on 560
2272011-08-09 10:40:20|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 51 (vmsvc/getallvms)
2282011-08-09 10:40:20|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/getallvms
2292011-08-09 10:40:20|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 52 (vmsvc/get.tasklist 560)
2302011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vmsvc/get.tasklist 560
2312011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:_wait_for_task(748)|checking status of task: haTask-560-vim.VirtualMachine.powerOn-7851
2322011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 53 (vimsvc/task_info haTask-560-vim.VirtualMachine.powerOn-7851)
2332011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd vimsvc/task_info haTask-560-vim.VirtualMachine.powerOn-7851
2342011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:_wait_for_task(771)|task completed successfully: haTask-560-vim.VirtualMachine.powerOn-7851
2352011-08-09 10:40:21|24415|56405:56141|new|VIM_SSH.pm:vm_power_on(970)|powered on VM: /vmfs/volumes/netappfiler02-sata1/vmguest-64_44-v6/vmguest-64_44-v6.vmx
2362011-08-09 10:40:21|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, startvm, registered and powered on vmguest-64
2372011-08-09 10:40:21|24415|56405:56141|new|Windows.pm:post_load(583)|beginning Windows post-load tasks on vmguest-64
2382011-08-09 10:40:22|24415|56405:56141|new|OS.pm:is_ssh_responding(386)|vmguest-64 is NOT responding to SSH, ports 22 or 24 are both closed
2392011-08-09 10:40:22|24415|56405:56141|new|OS.pm:wait_for_response(457)|waiting 15 seconds for vmguest-64 to boot
2402011-08-09 10:40:37|24415|56405:56141|new|OS.pm:wait_for_response(459)|waited 15 seconds for vmguest-64 to boot
2412011-08-09 10:40:37|24415|56405:56141|new|OS.pm:wait_for_response(463)|waiting for vmguest-64 to respond to SSH, maximum of 900 seconds
2422011-08-09 10:40:37|24415|56405:56141|new|Module.pm:code_loop_timeout(742)|waiting for vmguest-64 to respond to SSH, maximum of 900 seconds
2432011-08-09 10:40:37|24415|56405:56141|new|Module.pm:code_loop_timeout(759)|attempt 1: waiting for vmguest-64 to respond to SSH
2442011-08-09 10:40:37|24415|56405:56141|new|OS.pm:is_ssh_responding(386)|vmguest-64 is NOT responding to SSH, ports 22 or 24 are both closed
2452011-08-09 10:40:37|24415|56405:56141|new|Module.pm:code_loop_timeout(755)|attempt 1: code returned false, seconds elapsed/remaining: 0/900, sleeping for 8 seconds
2462011-08-09 10:40:45|24415|56405:56141|new|Module.pm:code_loop_timeout(759)|attempt 2: waiting for vmguest-64 to respond to SSH
2472011-08-09 10:40:46|24415|56405:56141|new|OS.pm:is_ssh_responding(386)|vmguest-64 is NOT responding to SSH, ports 22 or 24 are both closed
2482011-08-09 10:40:46|24415|56405:56141|new|Module.pm:code_loop_timeout(755)|attempt 2: code returned false, seconds elapsed/remaining: 9/891, sleeping for 8 seconds
2492011-08-09 10:40:54|24415|56405:56141|new|Module.pm:code_loop_timeout(759)|attempt 3: waiting for vmguest-64 to respond to SSH
2502011-08-09 10:40:54|24415|56405:56141|new|OS.pm:is_ssh_responding(386)|vmguest-64 is NOT responding to SSH, ports 22 or 24 are both closed
2512011-08-09 10:40:54|24415|56405:56141|new|Module.pm:code_loop_timeout(755)|attempt 3: code returned false, seconds elapsed/remaining: 17/883, sleeping for 8 
252
253It lookes for ssh for 4 minutes So I cut that out
254
25508-09 10:44:21|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
256|24415|56405:56141|new| SESSIONNAME USERNAME ID STATE TYPE DEVICE
257|24415|56405:56141|new| >console 0 Conn wdcon
258|24415|56405:56141|new| rdp-tcp 65536 Listen rdpwd
2592011-08-09 10:44:21|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "SESSIONNAME USERNAME ID STATE ...")
2602011-08-09 10:44:21|24415|56405:56141|new|Windows.pm:user_logged_in(8378)|root does NOT appear to be logged in on vmguest-64
2612011-08-09 10:44:21|24415|56405:56141|new|Windows.pm:wait_for_logoff(8441)|root is NOT logged in to vmguest-64, returning 1
2622011-08-09 10:44:21|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
263|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/qwinsta.exe' 2>&1
2642011-08-09 10:44:26|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
265|24415|56405:56141|new| SESSIONNAME USERNAME ID STATE TYPE DEVICE
266|24415|56405:56141|new| >console 0 Conn wdcon
267|24415|56405:56141|new| rdp-tcp 65536 Listen rdpwd
2682011-08-09 10:44:26|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "SESSIONNAME USERNAME ID STATE ...")
269|24415|56405:56141|new| ---- WARNING ---- 
270|24415|56405:56141|new| 2011-08-09 10:44:38|24415|56405:56141|new|Windows.pm:set_file_owner(1398)|error occurred setting root as the owner of /home/root, error output:
271|24415|56405:56141|new| /usr/bin/chown: cannot read directory `/home/root/.ssh': Permission denied
272|24415|56405:56141|new| failed to change ownership of `/home/root/.ssh' to root
273|24415|56405:56141|new| ( 0) Windows.pm, set_file_owner (line: 1398)
274|24415|56405:56141|new| (-1) Windows.pm, post_load (line: 625)
275|24415|56405:56141|new| (-2) VMware.pm, load (line: 415)
276|24415|56405:56141|new| (-3) new.pm, reload_image (line: 618)
277|24415|56405:56141|new| (-4) new.pm, process (line: 248)
278|24415|56405:56141|new| (-5) vcld, make_new_child (line: 568)
279|24415|56405:56141|new| ---- WARNING ---- 
280|24415|56405:56141|new| 2011-08-09 10:44:38|24415|56405:56141|new|Windows.pm:post_load(625)|unable to set root as the owner of /home/root
281|24415|56405:56141|new| ( 0) Windows.pm, post_load (line: 625)
282|24415|56405:56141|new| (-1) VMware.pm, load (line: 415)
283|24415|56405:56141|new| (-2) new.pm, reload_image (line: 618)
284|24415|56405:56141|new| (-3) new.pm, process (line: 248)
285|24415|56405:56141|new| (-4) vcld, make_new_child (line: 568)
286|24415|56405:56141|new| (-5) vcld, main (line: 346)
2872011-08-09 10:44:38|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
288|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/sc.exe config sshd start= auto' 2>&1
2892011-08-09 10:44:43|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
290|24415|56405:56141|new| [SC] ChangeServiceConfig SUCCESS
2912011-08-09 10:44:43|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "[SC] ChangeServiceConfig SUCCE...")
2922011-08-09 10:44:43|24415|56405:56141|new|Windows.pm:set_service_startup_mode(3636)|sshd service startup mode set to auto
2932011-08-09 10:44:43|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
2942011-08-09 10:44:43|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
2952011-08-09 10:44:43|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
2962011-08-09 10:44:43|24415|56405:56141|new|Windows.pm:get_private_ip_address(5299)|returning private IP address: 10.10.10.144
2972011-08-09 10:44:43|24415|56405:56141|new|OS.pm:update_ssh_known_hosts(502)|retrieved private IP address for vmguest-64 using OS module: 10.10.10.144
2982011-08-09 10:44:43|24415|56405:56141|new|OS.pm:update_ssh_known_hosts(533)|removing line from /root/.ssh/known_hosts matching computer name: vmguest-64
299|24415|56405:56141|new| vmguest-64 ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEAvpCFHmQOPeSkfSv8D6Rz/WGubaCtZdljOSy0KU/TKNp55ZvqcNhGidqBZZ8M/ZgaE4RHDERBWrRUMsqz8++NcE+s8Qw5uEsqLb8g/ID3uvCUFGVxTb060broXWjFvXED1FPpbsNH6Yrym2wuQ/ELP+Tbq1Yyn0Lh5xx+mhVXnYFY2qZ1w84bGO2d0IcMm5w/d1orec9RJZVDGT97F6dTfwHkCvfNzUcmi9rauFd8VK6AoaktGH/ZhuJAf1hnRmiocF3LKCojG58WucdfvZKj4f/JSy0ssuKhG2yRWV0IAp6xsbIvwK5XL6XpOsJrmThkSsUcapAcqYYcCu6y9fUYqw==
3002011-08-09 10:44:43|24415|56405:56141|new|OS.pm:update_ssh_known_hosts(537)|removing line from /root/.ssh/known_hosts matching computer private IP address:10.10.10.144
301|24415|56405:56141|new| 10.10.10.144 ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEAvpCFHmQOPeSkfSv8D6Rz/WGubaCtZdljOSy0KU/TKNp55ZvqcNhGidqBZZ8M/ZgaE4RHDERBWrRUMsqz8++NcE+s8Qw5uEsqLb8g/ID3uvCUFGVxTb060broXWjFvXED1FPpbsNH6Yrym2wuQ/ELP+Tbq1Yyn0Lh5xx+mhVXnYFY2qZ1w84bGO2d0IcMm5w/d1orec9RJZVDGT97F6dTfwHkCvfNzUcmi9rauFd8VK6AoaktGH/ZhuJAf1hnRmiocF3LKCojG58WucdfvZKj4f/JSy0ssuKhG2yRWV0IAp6xsbIvwK5XL6XpOsJrmThkSsUcapAcqYYcCu6y9fUYqw==
3022011-08-09 10:44:43|24415|56405:56141|new|OS.pm:update_ssh_known_hosts(550)|removed lines from /root/.ssh/known_hosts matching vmguest-64 or 10.10.10.144
3032011-08-09 10:44:44|24415|56405:56141|new|utils.pm:run_command(9010)|executed command: ssh-keyscan -t rsa 'vmguest-64' '10.10.10.144' 2>&1 | grep -v '^#' >> /root/.ssh/known_hosts, pid: 26677, exit status: 0, output:
3042011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3052011-08-09 10:44:44|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3062011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3072011-08-09 10:44:44|24415|56405:56141|new|utils.pm:is_valid_ip_address(9266)|IP address is valid: 137.145.56.235
3082011-08-09 10:44:44|24415|56405:56141|new|utils.pm:is_public_ip_address(9412)|public IP address: 137.145.56.235, returning 1
3092011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_network_configuration(5107)|public interface found with default gateway: Local Area Connection 2, address(es): 137.145.56.235, default gateway: 137.145.56.1
3102011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_public_interface_name(5207)|returning public interface name: Local Area Connection 2
3112011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:firewall_enable_rdp_private(4770)|RDP will be disabled on public interface: Local Area Connection 2
3122011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3132011-08-09 10:44:44|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3142011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3152011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:get_private_interface_name(5177)|returning private interface name: Local Area Connection
3162011-08-09 10:44:44|24415|56405:56141|new|Windows.pm:firewall_enable_rdp_private(4786)|RDP will be enabled on private interface: Local Area Connection
3172011-08-09 10:44:44|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
318|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/reg.exe ADD "HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Terminal Server" /t REG_DWORD /v fDenyTSConnections /d 0 /f ; C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 3389 interface = "Local Area Connection 2" ;netsh.exe firewall delete portopening protocol = TCP port = 3389 profile = ALL ;C:/Windows/System32/netsh.exe firewall set portopening name = "Remote Desktop" protocol = TCP port = 3389 mode = ENABLE interface = "Local Area Connection"' 2>&1
3192011-08-09 10:44:53|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
320|24415|56405:56141|new| The operation completed successfully
321|24415|56405:56141|new| Ok.
322|24415|56405:56141|new| Ok.
323|24415|56405:56141|new| Ok.
3242011-08-09 10:44:53|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The operation completed succes...")
3252011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:firewall_enable_rdp_private(4814)|configured firewall to allow RDP on private interface
3262011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3272011-08-09 10:44:53|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3282011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3292011-08-09 10:44:53|24415|56405:56141|new|utils.pm:is_valid_ip_address(9266)|IP address is valid: 137.145.56.235
3302011-08-09 10:44:53|24415|56405:56141|new|utils.pm:is_public_ip_address(9412)|public IP address: 137.145.56.235, returning 1
3312011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_network_configuration(5107)|public interface found with default gateway: Local Area Connection 2, address(es): 137.145.56.235, default gateway: 137.145.56.1
3322011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_public_interface_name(5207)|returning public interface name: Local Area Connection 2
3332011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:firewall_enable_ssh_private(4617)|SSH will be disabled on public interface: Local Area Connection 2
3342011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3352011-08-09 10:44:53|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3362011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3372011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:get_private_interface_name(5177)|returning private interface name: Local Area Connection
3382011-08-09 10:44:53|24415|56405:56141|new|Windows.pm:firewall_enable_ssh_private(4633)|SSH will be enabled on private interface: Local Area Connection
3392011-08-09 10:44:53|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
340|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 interface = "Local Area Connection 2" ;C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 profile = ALL ;C:/Windows/System32/netsh.exe firewall set portopening name = "Cygwin SSHD" protocol = TCP port = 22 mode = ENABLE interface = "Local Area Connection"' 2>&1
3412011-08-09 10:45:02|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
342|24415|56405:56141|new| Ok.
343|24415|56405:56141|new| Ok.
344|24415|56405:56141|new| Ok.
3452011-08-09 10:45:02|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "Ok. Ok. Ok.")
3462011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:firewall_enable_ssh_private(4661)|configured firewall to allow SSH on private interface
3472011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3482011-08-09 10:45:02|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3492011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3502011-08-09 10:45:02|24415|56405:56141|new|utils.pm:is_valid_ip_address(9266)|IP address is valid: 137.145.56.235
3512011-08-09 10:45:02|24415|56405:56141|new|utils.pm:is_public_ip_address(9412)|public IP address: 137.145.56.235, returning 1
3522011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_network_configuration(5107)|public interface found with default gateway: Local Area Connection 2, address(es): 137.145.56.235, default gateway: 137.145.56.1
3532011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_public_interface_name(5207)|returning public interface name: Local Area Connection 2
3542011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:firewall_enable_ping_private(4363)|ping will be disabled on public interface: Local Area Connection 2
3552011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3562011-08-09 10:45:02|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3572011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3582011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:get_private_interface_name(5177)|returning private interface name: Local Area Connection
3592011-08-09 10:45:02|24415|56405:56141|new|Windows.pm:firewall_enable_ping_private(4379)|ping will be enabled on private interface: Local Area Connection
3602011-08-09 10:45:02|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
361|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/netsh.exe firewall set icmpsetting type = 8 mode = DISABLE interface = "Local Area Connection 2" ;C:/Windows/System32/netsh.exe firewall set icmpsetting type = 8 mode = DISABLE profile = ALL ;C:/Windows/System32/netsh.exe firewall set icmpsetting type = 8 mode = ENABLE interface = "Local Area Connection"' 2>&1
3622011-08-09 10:45:11|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
363|24415|56405:56141|new| Ok.
364|24415|56405:56141|new| Ok.
365|24415|56405:56141|new| Ok.
3662011-08-09 10:45:11|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "Ok. Ok. Ok.")
3672011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:firewall_enable_ping_private(4405)|configured firewall to allow ping on private interface
3682011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:get_public_default_gateway(5392)|IP configuration mode in use: dynamicDHCP
3692011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
3702011-08-09 10:45:11|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
3712011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
3722011-08-09 10:45:11|24415|56405:56141|new|utils.pm:is_valid_ip_address(9266)|IP address is valid: 137.145.56.235
3732011-08-09 10:45:11|24415|56405:56141|new|utils.pm:is_public_ip_address(9412)|public IP address: 137.145.56.235, returning 1
3742011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5107)|public interface found with default gateway: Local Area Connection 2, address(es): 137.145.56.235, default gateway: 137.145.56.1
3752011-08-09 10:45:11|24415|56405:56141|new|Windows.pm:get_public_default_gateway(5402)|returning default gateway currently in use on vmguest-64: 137.145.56.1
3762011-08-09 10:45:11|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
377|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'route delete 0.0.0.0' 2>&1
3782011-08-09 10:45:16|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
3792011-08-09 10:45:16|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "")
3802011-08-09 10:45:16|24415|56405:56141|new|Windows.pm:delete_default_routes(7850)|deleted all default routes
3812011-08-09 10:45:16|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
382|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'route -p ADD 0.0.0.0 MASK 0.0.0.0 137.145.56.1 METRIC 1' 2>&1
3832011-08-09 10:45:21|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
3842011-08-09 10:45:21|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "")
3852011-08-09 10:45:21|24415|56405:56141|new|Windows.pm:set_public_default_route(7919)|added persistent route to public default gateway: 137.145.56.1
3862011-08-09 10:45:21|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
387|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/taskkill.exe /IM d4.exe /F 2>/dev/null ; C:/Windows/System32/w32tm.exe /register ; C:/Windows/System32/net.exe start w32time 2>/dev/null ; C:/Windows/System32/w32tm.exe /config /manualpeerlist:"time.nist.gov time-a.nist.gov time-b.nist.gov time.windows.com" /syncfromflags:manual /update ; C:/Windows/System32/net.exe stop w32time && C:/Windows/System32/net.exe start w32time ; C:/Windows/System32/w32tm.exe /resync /nowait' 2>&1
3882011-08-09 10:45:29|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
389|24415|56405:56141|new| W32Time successfully registered.
390|24415|56405:56141|new| The command completed successfully.
391|24415|56405:56141|new| The Windows Time service is stopping.
392|24415|56405:56141|new| The Windows Time service was stopped successfully.
393|24415|56405:56141|new| The Windows Time service is starting.
394|24415|56405:56141|new| The Windows Time service was started successfully.
395|24415|56405:56141|new| Sending resync command to local computer...
396|24415|56405:56141|new| The command completed successfully.
3972011-08-09 10:45:29|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "W32Time successfully registere...")
3982011-08-09 10:45:29|24415|56405:56141|new|Windows.pm:configure_time_synchronization(8026)|configured and synchronized Windows time
3992011-08-09 10:45:29|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
400|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/sc.exe config w32time start= auto' 2>&1
4012011-08-09 10:45:34|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
402|24415|56405:56141|new| [SC] ChangeServiceConfig SUCCESS
4032011-08-09 10:45:34|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "[SC] ChangeServiceConfig SUCCE...")
4042011-08-09 10:45:34|24415|56405:56141|new|Windows.pm:set_service_startup_mode(3636)|w32time service startup mode set to auto
4052011-08-09 10:45:34|24415|56405:56141|new|Windows.pm:configure_time_synchronization(8039)|set w32time service startup mode to auto
4062011-08-09 10:45:34|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
407|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/reg.exe add "HKCR\CLSID\{20D04FE0-3AEA-1069-A2D8-08002B30309D}" /v LocalizedString /t REG_EXPAND_SZ /d "CSUEB  SPSS PASW Statistics & Amos 18" /f' 2>&1
4082011-08-09 10:45:40|24415|56405:56141|new|Windows.pm:set_my_computer_name(4276)|my computer name changed to 'CSUEB  SPSS PASW Statistics & Amos 18'
4092011-08-09 10:45:45|24415|56405:56141|new|Windows.pm:search_and_replace_in_files(6259)|no files to process, base directory does not exist: $SYSTEMDRIVE/Sysprep
4102011-08-09 10:47:19|24415|56405:56141|new|Windows.pm:search_and_replace_in_files(6271)|found files matching pattern 'vclPassword' in C:/Cygwin/home/root/VCL:
411|24415|56405:56141|new| C:/Cygwin/home/root/VCL/Scripts/autologon_enable.cmd
4122011-08-09 10:47:24|24415|56405:56141|new|Windows.pm:search_and_replace_in_files(6298)|replaced 'vclPassword' with 'WINDOWS_ROOT_PASSWORD' in C:/Cygwin/home/root/VCL/Scripts/autologon_enable.cmd
4132011-08-09 10:47:24|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
414|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'unix2dos C:/Cygwin/home/root/VCL/Scripts/autologon_enable.cmd' 2>&1
4152011-08-09 10:47:29|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
416|24415|56405:56141|new| C:/Cygwin/home/root/VCL/Scripts/autologon_enable.cmd: done.
4172011-08-09 10:47:29|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "C:/Cygwin/home/root/VCL/Script...")
4182011-08-09 10:47:29|24415|56405:56141|new|Windows.pm:run_unix2dos(6189)|ran unix2dos on C:/Cygwin/home/root/VCL/Scripts/autologon_enable.cmd
4192011-08-09 10:47:29|24415|56405:56141|new|Windows.pm:set_password(1905)|setting password of root to ZZgfGw on vmguest-64
4202011-08-09 10:47:29|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
421|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/net.exe user root 'ZZgfGw'' 2>&1
4222011-08-09 10:47:34|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
423|24415|56405:56141|new| The command completed successfully.
4242011-08-09 10:47:34|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The command completed successf...")
4252011-08-09 10:47:34|24415|56405:56141|new|Windows.pm:set_password(1907)|password changed to 'ZZgfGw' for user 'root' on vmguest-64
4262011-08-09 10:47:34|24415|56405:56141|new|Windows.pm:set_password(1921)|root account password changed, must also change sshd service credentials
4272011-08-09 10:47:34|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
428|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/sc.exe config sshd obj= ".\root" password= "ZZgfGw"' 2>&1
4292011-08-09 10:47:39|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
430|24415|56405:56141|new| [SC] ChangeServiceConfig SUCCESS
4312011-08-09 10:47:39|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "[SC] ChangeServiceConfig SUCCE...")
4322011-08-09 10:47:39|24415|56405:56141|new|Windows.pm:set_service_credentials(3795)|changed logon credentials for 'sshd' service to root (ZZgfGw) on vmguest-64
4332011-08-09 10:47:39|24415|56405:56141|new|Windows.pm:set_password(1929)|changing passwords for scheduled tasks
4342011-08-09 10:47:45|24415|56405:56141|new|Windows.pm:set_password(1931)|queried scheduled tasks on vmguest-64
4352011-08-09 10:47:45|24415|56405:56141|new|Windows.pm:set_password(1982)|changed password for user: root
4362011-08-09 10:47:45|24415|56405:56141|new|Windows.pm:set_password(1905)|setting password of Administrator to MNKFGg on vmguest-64
4372011-08-09 10:47:45|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
438|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/net.exe user Administrator 'MNKFGg'' 2>&1
4392011-08-09 10:47:50|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
440|24415|56405:56141|new| The command completed successfully.
4412011-08-09 10:47:50|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The command completed successf...")
4422011-08-09 10:47:50|24415|56405:56141|new|Windows.pm:set_password(1907)|password changed to 'MNKFGg' for user 'Administrator' on vmguest-64
4432011-08-09 10:47:50|24415|56405:56141|new|Windows.pm:set_password(1929)|changing passwords for scheduled tasks
4442011-08-09 10:47:55|24415|56405:56141|new|Windows.pm:set_password(1931)|queried scheduled tasks on vmguest-64
4452011-08-09 10:47:55|24415|56405:56141|new|Windows.pm:set_password(1982)|changed password for user: Administrator
4462011-08-09 10:47:55|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
447|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/powercfg.exe /QUERY' 2>&1
4482011-08-09 10:48:00|24415|56405:56141|new|Version_5.pm:disable_sleep(686)|retrieved power scheme name: 'Home/Office Desk'
4492011-08-09 10:48:00|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
450|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /monitor-timeout-ac 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /monitor-timeout-dc 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /disk-timeout-ac 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /disk-timeout-dc 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /standby-timeout-ac 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /standby-timeout-dc 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /hibernate-timeout-ac 0 ; C:/Windows/System32/powercfg.exe /CHANGE "Home/Office Desk" /hibernate-timeout-dc 0' 2>&1
4512011-08-09 10:48:06|24415|56405:56141|new|Version_5.pm:disable_sleep(709)|disabled sleep
4522011-08-09 10:48:06|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
453|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'sed -i -e '/vcld_post_load.*/d' currentimage.txt && echo >> currentimage.txt && echo "vcld_post_load=success (Tue Aug  9 10:48:06 2011)" >> currentimage.txt && sed -i -e '/^[\s\r\n]*$/d' currentimage.txt && unix2dos currentimage.txt' 2>&1
4542011-08-09 10:48:11|24415|56405:56141|new|OS.pm:set_vcld_post_load_status(768)|added line to currentimage.txt on vmguest-64: 'vcld_post_load=success (Tue Aug  9 10:48:06 2011)'
4552011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:post_load(808)|returning 1
4562011-08-09 10:48:11|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, loadimagecomplete, performed OS post-load tasks on vmguest-64
4572011-08-09 10:48:11|24415|56405:56141|new|new.pm:reload_image(619)|vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 was successfully reloaded on vmguest-64
4582011-08-09 10:48:11|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, loadimagecomplete, vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 was successfully reloaded on vmguest-64
4592011-08-09 10:48:11|24415|56405:56141|new|new.pm:reload_image(628)|node ready: successfully reloaded vmguest-64 with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
4602011-08-09 10:48:11|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, nodeready, vmguest-64 was reloaded with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
4612011-08-09 10:48:11|24415|56405:56141|new|utils.pm:update_currentimage(6088)|updating computer 68: image=44, imagerevision=249
4622011-08-09 10:48:11|24415|56405:56141|new|utils.pm:update_currentimage(6118)|updated currentimageid and imagerevision id for computer id 68
4632011-08-09 10:48:11|24415|56405:56141|new|new.pm:reload_image(633)|updated computer table for vmguest-64: currentimageid=44
4642011-08-09 10:48:11|24415|56405:56141|new|new.pm:reload_image(640)|returning 1
4652011-08-09 10:48:11|24415|56405:56141|new|new.pm:process(248)|vmguest-64 is loaded with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
4662011-08-09 10:48:11|24415|56405:56141|new|new.pm:process(341)|vmguest-64 next image is already set to vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
4672011-08-09 10:48:11|24415|56405:56141|new|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
4682011-08-09 10:48:11|24415|56405:56141|new|new.pm:reserve_computer(881)|user_standalone=1, image OS type=windows
4692011-08-09 10:48:11|24415|56405:56141|new|OS.pm:update_public_ip_address(595)|IP configuration is set to dynamicDHCP, attempting to retrieve dynamic public IP address from vmguest-64
4702011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved
4712011-08-09 10:48:11|24415|56405:56141|new|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.10.10.144
4722011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: AMD PCNET Family PCI Ethernet Adapter #2, address(es): 10.10.10.144
4732011-08-09 10:48:11|24415|56405:56141|new|utils.pm:is_valid_ip_address(9266)|IP address is valid: 137.145.56.235
4742011-08-09 10:48:11|24415|56405:56141|new|utils.pm:is_public_ip_address(9412)|public IP address: 137.145.56.235, returning 1
4752011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:get_network_configuration(5107)|public interface found with default gateway: Local Area Connection 2, address(es): 137.145.56.235, default gateway: 137.145.56.1
4762011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:get_public_ip_address(5363)|returning public IP address: 137.145.56.235
4772011-08-09 10:48:11|24415|56405:56141|new|OS.pm:update_public_ip_address(600)|retrieved public IP address from vmguest-64 using the OS module: 137.145.56.235
4782011-08-09 10:48:11|24415|56405:56141|new|utils.pm:update_computer_address(6258)|computer 68 IP address 137.145.56.235 updated in database
4792011-08-09 10:48:11|24415|56405:56141|new|OS.pm:update_public_ip_address(616)|updated dynamic public IP address in computer table for vmguest-64, 137.145.56.235
4802011-08-09 10:48:11|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, dynamicDHCPaddress, updated dynamic public IP address in computer table for vmguest-64, 137.145.56.235
4812011-08-09 10:48:11|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, info, node ready adding user account
4822011-08-09 10:48:11|24415|56405:56141|new|utils.pm:update_request_password(2116)|password updated for reservation_id 56141
4832011-08-09 10:48:11|24415|56405:56141|new|new.pm:reserve_computer(906)|updated password in the reservation table
4842011-08-09 10:48:11|24415|56405:56141|new|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{56141}{pw}
485|24415|56405:56141|new| reservation_password = HSZSGf
4862011-08-09 10:48:11|24415|56405:56141|new|new.pm:reserve_computer(920)|calling OS module's reserve() subroutine
4872011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:reserve(832)|beginning Windows reserve tasks
4882011-08-09 10:48:11|24415|56405:56141|new|Windows.pm:set_password(1905)|setting password of Administrator to HSZSGf on vmguest-64
4892011-08-09 10:48:11|24415|56405:56141|new|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
490|24415|56405:56141|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/net.exe user Administrator 'HSZSGf'' 2>&1
4912011-08-09 10:48:16|24415|56405:56141|new|utils.pm:run_ssh_command(5464)|run_ssh_command output:
492|24415|56405:56141|new| The command completed successfully.
4932011-08-09 10:48:16|24415|56405:56141|new|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The command completed successf...")
4942011-08-09 10:48:16|24415|56405:56141|new|Windows.pm:set_password(1907)|password changed to 'HSZSGf' for user 'Administrator' on vmguest-64
4952011-08-09 10:48:16|24415|56405:56141|new|Windows.pm:set_password(1929)|changing passwords for scheduled tasks
4962011-08-09 10:48:21|24415|56405:56141|new|Windows.pm:set_password(1931)|queried scheduled tasks on vmguest-64
4972011-08-09 10:48:21|24415|56405:56141|new|Windows.pm:set_password(1982)|changed password for user: Administrator
4982011-08-09 10:48:21|24415|56405:56141|new|Windows.pm:reserve(851)|returning 1
4992011-08-09 10:48:21|24415|56405:56141|new|new.pm:reserve_computer(921)|OS module successfully reserved resources for this reservation
5002011-08-09 10:48:22|24415|56405:56141|new|utils.pm:mail(1255)|SUCCESS -- Sending mail To: alexander.patterson@csueastbay.edu, VCL -- CSUEB SPSS PASW Statistics & Amos 18 imaging reservation
5012011-08-09 10:48:22|24415|56405:56141|new|new.pm:reserve_computer(1017)|IMTYPE_name= none calling notify_via
5022011-08-09 10:48:22|24415|56405:56141|new|new.pm:reserve_computer(1087)|updated sublog 20092 for node vmguest-64 IPaddress 137.145.57.70
5032011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(363)|vmguest-64 with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 successfully reserved
5042011-08-09 10:48:22|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, reserved, vmguest-64 successfully reserved with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
5052011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(375)|inserted computerloadlog entry, load state=reserved
5062011-08-09 10:48:22|24415|56405:56141|new|utils.pm:update_computer_state(2033)|computer 68 state updated to: reserved
5072011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(399)|vmguest-64 state set to 'reserved'
5082011-08-09 10:48:22|24415|56405:56141|new|utils.pm:update_request_state(1991)|request 56405 state updated to: reserved, laststate to: new
5092011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(408)|request state set to 'reserved'/'new'
5102011-08-09 10:48:22|24415|56405:56141|new|utils.pm:insertloadlog(3875)|inserted computer=68, info, vmguest-64 successfully set to reserved with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
5112011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(421)|inserted computerloadlog entry: vmguest-64 successfully set to reserved with vmwarewinxp-SPSSPASWStatisticsAmos1844-v6
5122011-08-09 10:48:22|24415|56405:56141|new|new.pm:process(428)|exiting
5132011-08-09 10:48:22|24415|56405:56141|new|State.pm:DESTROY(829)|VCL::new destructor called, address: 1a6808f0
5142011-08-09 10:48:22|24415|56405:56141|new|utils.pm:delete_computerloadlog_reservation(6742)|removing computerloadlog entries matching loadstate = begin
5152011-08-09 10:48:22|24415|56405:56141|new|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=56141
5162011-08-09 10:48:22|24415|56405:56141|new|State.pm:DESTROY(848)|number of database handles state process created: 1
5172011-08-09 10:48:22|24415|56405:56141|new|State.pm:DESTROY(876)|VCL::new process duration: 1501 seconds
5182011-08-09 10:48:22|24415|56405:56141|new|VIM_SSH.pm:DESTROY(1685)|vim-cmd call count: 53
5192011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:reservation_being_processed(8938)|computerloadlog 'begin' entry does NOT exist for reservation 56141
5202011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:run_command(9010)|executed command: pgrep -fl 'vcld [0-9]+:56141 ', pid: 27029, exit status: 1, output:
5212011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:is_management_node_process_running(9192)|process is NOT running, identifier: 'vcld [0-9]+:56141 '
5222011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:reservation_being_processed(8959)|reservation is NOT currently being processed
5232011-08-09 10:48:22|11998|56405:56141|reserved|vcld:main(278)|reservation 56141 is NOT already being processed
5242011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:get_request_info(4520)|standalone affiliation found: CSUEB
5252011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:get_request_info(4527)|found NULL uid setting standalone flag: wv4973, uid: NULL
5262011-08-09 10:48:22|11998|56405:56141|reserved|vcld:main(283)|retrieved request information from database
5272011-08-09 10:48:22|11998|56405:56141|reserved|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
5282011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:update_request_state(1991)|request 56405 state updated to: pending, laststate to: reserved
5292011-08-09 10:48:22|11998|56405:56141|reserved|utils.pm:insertloadlog(3875)|inserted computer=68, begin, beginning to process, state is reserved
5302011-08-09 10:48:22|11998|56405:56141|reserved|vcld:make_new_child(515)|loaded VCL::reserved module
5312011-08-09 10:48:22|11998|56405:56141|reserved|vcld:make_new_child(539)|current number of forked kids: 1
5322011-08-09 10:48:22|27043|56405:56141|reserved|vcld:make_new_child(555)|vcld environment variable set to 0 for this process
5332011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'test' key for VCL::reserved object from arguments
5342011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'forimaging' key for VCL::reserved object from arguments
5352011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'reservation' key for VCL::reserved object from arguments
5362011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'userid' key for VCL::reserved object from arguments
5372011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'daterequested' key for VCL::reserved object from arguments
5382011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'RESERVATIONID' key for VCL::reserved object from arguments
5392011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'UPDATED' key for VCL::reserved object from arguments
5402011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'SUBIMAGE' key for VCL::reserved object from arguments
5412011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'CHECKTIME' key for VCL::reserved object from arguments
5422011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'state' key for VCL::reserved object from arguments
5432011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'laststate' key for VCL::reserved object from arguments
5442011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'PRELOADONLY' key for VCL::reserved object from arguments
5452011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'laststateid' key for VCL::reserved object from arguments
5462011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'user' key for VCL::reserved object from arguments
5472011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'id' key for VCL::reserved object from arguments
5482011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'PID' key for VCL::reserved object from arguments
5492011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'DURATION' key for VCL::reserved object from arguments
5502011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'PPID' key for VCL::reserved object from arguments
5512011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'datemodified' key for VCL::reserved object from arguments
5522011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'RESERVATIONCOUNT' key for VCL::reserved object from arguments
5532011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'end' key for VCL::reserved object from arguments
5542011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'stateid' key for VCL::reserved object from arguments
5552011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'PARENTIMAGE' key for VCL::reserved object from arguments
5562011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'checkuser' key for VCL::reserved object from arguments
5572011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'preload' key for VCL::reserved object from arguments
5582011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'NOTICEINTERVAL' key for VCL::reserved object from arguments
5592011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'start' key for VCL::reserved object from arguments
5602011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'logid' key for VCL::reserved object from arguments
5612011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(361)|VCL::Module::OS::Linux::ManagementNode module loaded
5622011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(196)|VCL::Module::OS::Linux::ManagementNode object created for image <not set>, address: 1a4cbf70
5632011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{hostname}
564|27043|56405:56141|reserved| computer_hostname = vclnfs01.calstate.edu
5652011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{NODENAME}
566|27043|56405:56141|reserved| computer_node_name = vclnfs01
5672011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{SHORTNAME}
568|27043|56405:56141|reserved| computer_short_name = vclnfs01
5692011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{IPaddress}
570|27043|56405:56141|reserved| computer_ip_address = 137.145.56.10
5712011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(366)|VCL::Module::OS::Linux::ManagementNode OS object created, address: 1a4cbf70
5722011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(192)|VCL::reserved object created for state reserved, address: 1a6def50
5732011-08-09 10:48:22|27043|56405:56141|reserved|State.pm:initialize(86)|obtained a database handle for this state process, stored as $ENV{dbh}
5742011-08-09 10:48:22|27043|56405:56141|reserved|State.pm:check_image_os(743)|no corrections need to be made, not an imaging request, returning 1
5752011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
5762011-08-09 10:48:22|27043|56405:56141|reserved|utils.pm:rename_vcld_process(7098)|reservation count: 1
5772011-08-09 10:48:22|27043|56405:56141|reserved|utils.pm:rename_vcld_process(7117)|PARENTIMAGE: 1
5782011-08-09 10:48:22|27043|56405:56141|reserved|utils.pm:rename_vcld_process(7118)|SUBIMAGE: 0
5792011-08-09 10:48:22|27043|56405:56141|reserved|utils.pm:rename_vcld_process(7136)|renamed process to 'vcld 56405:56141 reserved vmguest-64>vclesxi22 vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 wv4973 (imaging)'
5802011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
5812011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
5822011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_os_object(298)|VCL::Module::OS::Windows::Version_5::XP module loaded
5832011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a4cbf70, returning 1
5842011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(196)|VCL::Module::OS::Windows::Version_5::XP object created for image vmwarewinxp-SPSSPASWStatisticsAmos1844-v6, address: 1a6793c0
5852011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_os_object(304)|VCL::Module::OS::Windows::Version_5::XP OS object created for vmwarewinxp-SPSSPASWStatisticsAmos1844-v6, address: 1a6793c0
5862011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_provisioning_object(420)|VCL::Module::Provisioning::VMware::VMware module loaded
5872011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a4cbf70, returning 1
5882011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VMware object created for computer vmguest-64, address: 1a85fba0
5892011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:initialize(230)|initializing VCL::Module::Provisioning::VMware::VMware object
5902011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
5912011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
5922011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
5932011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
5942011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
5952011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:initialize(249)|attempting to create OS object for the image currently loaded on the VM host: vclesxi22
596|27043|56405:56141|reserved| image name: noimage
597|27043|56405:56141|reserved| OS module: VCL::Module::OS::Linux::UnixLab
5982011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
5992011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
6002011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
6012011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
6022011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
6032011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_os_object(1232)|attempting to load VM host OS module: VCL::Module::OS::Linux::UnixLab
6042011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_os_object(1238)|VM host OS module loaded: VCL::Module::OS::Linux::UnixLab
6052011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a4cbf70, returning 1
6062011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(196)|VCL::Module::OS::Linux::UnixLab object created for image noimage, address: 1b0db5d0
6072011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_os_object(1244)|VM host OS object created: VCL::Module::OS::Linux::UnixLab
6082011-08-09 10:48:22|27043|56405:56141|reserved|OS.pm:is_ssh_responding(401)|vclesxi22 is responding to SSH, port 22: open, port 24: closed
6092011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:initialize(254)|OS on VM host vclesxi22 will be controlled using a VCL::Module::OS::Linux::UnixLab OS object
6102011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
6112011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
6122011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
6132011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
6142011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
6152011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1293)|attempting to load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
6162011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1299)|loaded VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
6172011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'vmhost_data' key for VCL::Module::Provisioning::VMware::vSphere_SDK object from arguments
6182011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'vmhost_os' key for VCL::Module::Provisioning::VMware::vSphere_SDK object from arguments
6192011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a4cbf70, returning 1
6202011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(200)|VCL::Module::Provisioning::VMware::vSphere_SDK object created for computer vmguest-64, address: 1b0db7e0
6212011-08-09 10:48:22|27043|56405:56141|reserved|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
6222011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1313)|API object could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK
6232011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
6242011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
6252011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
6262011-08-09 10:48:22|27043|56405:56141|reserved|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
6272011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
6282011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1293)|attempting to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
6292011-08-09 10:48:22|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1299)|loaded VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
6302011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'vmhost_data' key for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
6312011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(172)|set 'vmhost_os' key for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
6322011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a4cbf70, returning 1
6332011-08-09 10:48:22|27043|56405:56141|reserved|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VIM_SSH object created for computer vmguest-64, address: 1b1085c0
6342011-08-09 10:48:23|27043|56405:56141|reserved|VIM_SSH.pm:initialize(138)|VIM executable available on VM host: vim-cmd
6352011-08-09 10:48:23|27043|56405:56141|reserved|VIM_SSH.pm:initialize(140)|VCL::Module::Provisioning::VMware::VIM_SSH object initialized
6362011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:get_vmhost_api_object(1320)|created API object: VCL::Module::Provisioning::VMware::VIM_SSH
6372011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:initialize(278)|VMware on VM host vclesxi22 will be controlled using vim-cmd via SSH
6382011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:initialize(293)|VMware OS and API objects created for VM host vclesxi22:
639|27043|56405:56141|reserved| VM host OS object type: VCL::Module::OS::Linux::UnixLab
640|27043|56405:56141|reserved| VMware API object type: VCL::Module::Provisioning::VMware::VIM_SSH
6412011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:get_vmhost_product_name(5405)|VMware product being used on VM host vclesxi22: 'VMware ESXi 4.1.0 build-348481'
6422011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:initialize(307)|product: VMware ESXi 4.1.0 build-348481, OS object: VCL::Module::OS::Linux::UnixLab
6432011-08-09 10:48:23|27043|56405:56141|reserved|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 1 (hostsvc/datastore/listsummary)
6442011-08-09 10:48:23|27043|56405:56141|reserved|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd hostsvc/datastore/listsummary
6452011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:get_datastore_info(5531)|retrieved datastore info from VM host:
646|27043|56405:56141|reserved| netappfiler02-sata1
647|27043|56405:56141|reserved| vclesxi22-local-vmfs
6482011-08-09 10:48:23|27043|56405:56141|reserved|VMware.pm:get_vmx_base_directory_path(2745)|determined vmx base directory path: /vmfs/volumes/netappfiler02-sata1
6492011-08-09 10:48:24|27043|56405:56141|reserved|Linux.pm:file_exists(1404)|'/vmfs/volumes/netappfiler02-sata1' exists on vclesxi22, files: 0, directories: 0, links: 1
6502011-08-09 10:48:24|27043|56405:56141|reserved|VMware.pm:initialize(324)|not checking if vmdk base directory exists because it is the same as the vmx base directory: /vmfs/volumes/netappfiler02-sata1
6512011-08-09 10:48:24|27043|56405:56141|reserved|Module.pm:create_provisioning_object(426)|VCL::Module::Provisioning::VMware::VMware provisioner object created for vmguest-64, address: 1a85fba0
6522011-08-09 10:48:24|27043|56405:56141|reserved|State.pm:initialize(126)|returning 1
6532011-08-09 10:48:24|27043|56405:56141|reserved|vcld:make_new_child(565)|VCL::reserved object created and initialized
6542011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(116)|updated log table, set loaded time to now for id:20092
6552011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(131)|imagemeta user group membership count = 0
6562011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(151)|computer info: id=68, type=virtualmachine, hostname=vmguest-64
6572011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(152)|user info: login_id id=wv4973, standalone=1
6582011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(153)|imagemeta checkuser set to: 1
6592011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(154)|formimaging set to: 1
6602011-08-09 10:48:24|27043|56405:56141|reserved|reserved.pm:process(165)|begin checking for user acknowledgement
6612011-08-09 10:48:24|27043|56405:56141|reserved|utils.pm:insertloadlog(3875)|inserted computer=68, info, reserved: waiting for user acknowledgement
6622011-08-09 10:48:24|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6632011-08-09 10:48:29|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6642011-08-09 10:48:34|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6652011-08-09 10:48:39|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6662011-08-09 10:48:44|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6672011-08-09 10:48:49|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6682011-08-09 10:48:54|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6692011-08-09 10:48:59|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6702011-08-09 10:49:04|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6712011-08-09 10:49:09|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6722011-08-09 10:49:09|27043|56405:56141|reserved|reserved.pm:process(237)|attempt 10 of 180, user has not acknowleged
6732011-08-09 10:49:14|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6742011-08-09 10:49:19|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6752011-08-09 10:49:24|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6762011-08-09 10:49:29|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6772011-08-09 10:49:34|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6782011-08-09 10:49:39|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6792011-08-09 10:49:44|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6802011-08-09 10:49:49|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6812011-08-09 10:49:54|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1093)|reservation remote IP is not defined
6822011-08-09 10:49:59|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1106)|retrieved remote IP for reservation 56141: 134.154.213.182
6832011-08-09 10:49:59|27043|56405:56141|reserved|reserved.pm:process(183)|user acknowledged, remote IP: 134.154.213.182
6842011-08-09 10:49:59|27043|56405:56141|reserved|reserved.pm:process(197)|calling VCL::Module::OS::Windows::Version_5::XP::grant_access() subroutine
6852011-08-09 10:50:04|27043|56405:56141|reserved|OS.pm:is_ssh_responding(401)|vmguest-64 is responding to SSH, port 22: open, port 24: closed
6862011-08-09 10:50:09|27043|56405:56141|reserved|Windows.pm:is_64_bit(8108)|32-bit Windows OS detected, PROCESSOR_IDENTIFIER: x86 Family 6 Model 26 Stepping 5, GenuineIntel
6872011-08-09 10:50:09|27043|56405:56141|reserved|Windows.pm:get_system32_path(8152)|32-bit Windows OS installed on vmguest-64, using C:/Windows/System32
6882011-08-09 10:50:09|27043|56405:56141|reserved|DataStructure.pm:get_reservation_remote_ip(1106)|retrieved remote IP for reservation 56141: 134.154.213.182
6892011-08-09 10:50:09|27043|56405:56141|reserved|Windows.pm:grant_access(932)|RDP will be allowed from 134.154.213.182/16 on vmguest-64
6902011-08-09 10:50:09|27043|56405:56141|reserved|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
691|27043|56405:56141|reserved| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/reg.exe ADD "HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Terminal Server" /t REG_DWORD /v fDenyTSConnections /d 0 /f ; C:/Windows/System32/netsh.exe firewall set portopening name = "Remote Desktop" protocol = TCP port = 3389 mode = ENABLE scope = CUSTOM addresses = 134.154.213.182/16' 2>&1
6922011-08-09 10:50:16|27043|56405:56141|reserved|utils.pm:run_ssh_command(5464)|run_ssh_command output:
693|27043|56405:56141|reserved| The operation completed successfully
694|27043|56405:56141|reserved| Ok.
6952011-08-09 10:50:16|27043|56405:56141|reserved|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The operation completed succes...")
6962011-08-09 10:50:16|27043|56405:56141|reserved|Windows.pm:firewall_enable_rdp(4724)|configured firewall to allow RDP from 134.154.213.182/16
6972011-08-09 10:50:16|27043|56405:56141|reserved|Windows.pm:grant_access(939)|firewall was configured to allow RDP access from 134.154.213.182/16 on vmguest-64
6982011-08-09 10:50:16|27043|56405:56141|reserved|Windows.pm:grant_access(949)|imaging request, making sure Administrator account is enabled
6992011-08-09 10:50:16|27043|56405:56141|reserved|Windows.pm:enable_user(2022)|enabling user Administrator on vmguest-64
7002011-08-09 10:50:16|27043|56405:56141|reserved|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
701|27043|56405:56141|reserved| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'C:/Windows/System32/net.exe user Administrator /ACTIVE:YES' 2>&1
7022011-08-09 10:50:21|27043|56405:56141|reserved|utils.pm:run_ssh_command(5464)|run_ssh_command output:
703|27043|56405:56141|reserved| The command completed successfully.
7042011-08-09 10:50:21|27043|56405:56141|reserved|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "The command completed successf...")
7052011-08-09 10:50:21|27043|56405:56141|reserved|Windows.pm:enable_user(2024)|user Administrator enabled on vmguest-64
7062011-08-09 10:50:21|27043|56405:56141|reserved|Windows.pm:grant_access(950)|Administrator account is enabled for imaging request
7072011-08-09 10:50:21|27043|56405:56141|reserved|Windows.pm:delete_files_by_pattern(1254)|attempting to delete files under C:/Windows/System32/GroupPolicy/User/Scripts/ matching pattern .*VCL.*cmd, max depth: 2
7082011-08-09 10:50:21|27043|56405:56141|reserved|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
709|27043|56405:56141|reserved| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 '/bin/find.exe "C:/Windows/System32/GroupPolicy/User/Scripts/" -mindepth 1 -maxdepth 2 -iregex ".*VCL.*cmd" -exec chown -R root {} \; -exec chmod -R 777 {} \; -exec rm -rvf {} \;' 2>&1
7102011-08-09 10:50:26|27043|56405:56141|reserved|Windows.pm:delete_files_by_pattern(1290)|0/0 files deleted deleted under 'C:/Windows/System32/GroupPolicy/User/Scripts/' matching '.*VCL.*cmd'
7112011-08-09 10:50:26|27043|56405:56141|reserved|Windows.pm:grant_access(964)|access has been granted for reservation on vmguest-64
7122011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(198)|OS access has been granted on vmguest-64
7132011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(228)|VCL::Module::OS::Windows::Version_5::XP->post_reserve() not implemented by VCL::Module::OS::Windows::Version_5::XP
7142011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(290)|reservation is for image creation skipping user connection check
7152011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(299)|retval_conn = connected
7162011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(310)|134.154.213.182 connected to vmguest-64
7172011-08-09 10:50:26|27043|56405:56141|reserved|utils.pm:insertloadlog(3875)|inserted computer=68, connected, reserved: user connected to remote machine
7182011-08-09 10:50:26|27043|56405:56141|reserved|utils.pm:update_request_state(1991)|request 56405 state updated to: inuse, laststate to: reserved
7192011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(315)|setting request into inuse state
7202011-08-09 10:50:26|27043|56405:56141|reserved|utils.pm:update_computer_state(2033)|computer 68 state updated to: inuse
7212011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(323)|setting computerid 68 into inuse state
7222011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(331)|updated lastcheck time for reservation 56141
7232011-08-09 10:50:26|27043|56405:56141|reserved|reserved.pm:process(338)|exiting
7242011-08-09 10:50:26|27043|56405:56141|reserved|State.pm:DESTROY(829)|VCL::reserved destructor called, address: 1a6def50
7252011-08-09 10:50:26|27043|56405:56141|reserved|utils.pm:delete_computerloadlog_reservation(6742)|removing computerloadlog entries matching loadstate = begin
7262011-08-09 10:50:26|27043|56405:56141|reserved|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=56141
7272011-08-09 10:50:26|27043|56405:56141|reserved|State.pm:DESTROY(848)|number of database handles state process created: 1
7282011-08-09 10:50:26|27043|56405:56141|reserved|State.pm:DESTROY(876)|VCL::reserved process duration: 124 seconds
7292011-08-09 10:50:26|27043|56405:56141|reserved|VIM_SSH.pm:DESTROY(1685)|vim-cmd call count: 1
730|28405|56405:56141|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'netsh firewall show portopening enable' 2>&1
7312011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:run_ssh_command(5464)|run_ssh_command output:
732|28405|56405:56141|inuse| Port configuration for Domain profile:
733|28405|56405:56141|inuse| Port Protocol Mode Name
734|28405|56405:56141|inuse| -------------------------------------------------------------------
735|28405|56405:56141|inuse| 139 TCP Disable NetBIOS Session Service
736|28405|56405:56141|inuse| Scope: LocalSubNet
737|28405|56405:56141|inuse| 445 TCP Disable SMB over TCP
738|28405|56405:56141|inuse| Scope: LocalSubNet
739|28405|56405:56141|inuse| 137 UDP Disable NetBIOS Name Service
740|28405|56405:56141|inuse| Scope: LocalSubNet
741|28405|56405:56141|inuse| 138 UDP Disable NetBIOS Datagram Service
742|28405|56405:56141|inuse| Scope: LocalSubNet
743|28405|56405:56141|inuse| 1900 UDP Disable SSDP Component of UPnP Framework
744|28405|56405:56141|inuse| Scope: LocalSubNet
745|28405|56405:56141|inuse| 2869 TCP Disable UPnP Framework over TCP
746|28405|56405:56141|inuse| Scope: LocalSubNet
747|28405|56405:56141|inuse| 3389 TCP Disable Remote Desktop
748|28405|56405:56141|inuse| Scope: *
749|28405|56405:56141|inuse| Port configuration for Standard profile:
750|28405|56405:56141|inuse| Port Protocol Mode Name
751|28405|56405:56141|inuse| -------------------------------------------------------------------
752|28405|56405:56141|inuse| 139 TCP Enable NetBIOS Session Service
753|28405|56405:56141|inuse| Scope: LocalSubNet
754|28405|56405:56141|inuse| 445 TCP Enable SMB over TCP
755|28405|56405:56141|inuse| Scope: LocalSubNet
756|28405|56405:56141|inuse| 137 UDP Enable NetBIOS Name Service
757|28405|56405:56141|inuse| Scope: LocalSubNet
758|28405|56405:56141|inuse| 138 UDP Enable NetBIOS Datagram Service
759|28405|56405:56141|inuse| Scope: LocalSubNet
760|28405|56405:56141|inuse| 1900 UDP Enable SSDP Component of UPnP Framework
761|28405|56405:56141|inuse| Scope: LocalSubNet
762|28405|56405:56141|inuse| 2869 TCP Enable UPnP Framework over TCP
763|28405|56405:56141|inuse| Scope: LocalSubNet
764|28405|56405:56141|inuse| 3389 TCP Enable Remote Desktop
765|28405|56405:56141|inuse| Scope: 134.154.0.0/255.255.0.0
766|28405|56405:56141|inuse| Port configuration for Local Area Connection:
767|28405|56405:56141|inuse| Port Protocol Mode Name
768|28405|56405:56141|inuse| -------------------------------------------------------------------
769|28405|56405:56141|inuse| 3389 TCP Enable Remote Desktop
770|28405|56405:56141|inuse| 220 TCP Disable Internet Mail Access Protocol Version 3 (IMAP3)
771|28405|56405:56141|inuse| 110 TCP Disable Post-Office Protocol Version 3 (POP3)
772|28405|56405:56141|inuse| 443 TCP Disable Secure Web Server (HTTPS)
773|28405|56405:56141|inuse| 143 TCP Disable Internet Mail Access Protocol Version 4 (IMAP4)
774|28405|56405:56141|inuse| 25 TCP Disable Internet Mail Server (SMTP)
775|28405|56405:56141|inuse| 80 TCP Disable Web Server (HTTP)
776|28405|56405:56141|inuse| 22 TCP Enable Cygwin SSHD
777|28405|56405:56141|inuse| 23 TCP Disable Telnet Server
778|28405|56405:56141|inuse| 21 TCP Disable FTP Server
779|28405|56405:56141|inuse| Port configuration for Local Area Connection 2:
780|28405|56405:56141|inuse| Port Protocol Mode Name
781|28405|56405:56141|inuse| -------------------------------------------------------------------
782|28405|56405:56141|inuse| 3389 TCP Disable Remote Desktop
783|28405|56405:56141|inuse| 110 TCP Disable Post-Office Protocol Version 3 (POP3)
784|28405|56405:56141|inuse| 80 TCP Disable Web Server (HTTP)
785|28405|56405:56141|inuse| 443 TCP Disable Secure Web Server (HTTPS)
786|28405|56405:56141|inuse| 23 TCP Disable Telnet Server
787|28405|56405:56141|inuse| 22 TCP Disable Cygwin SSHD
788|28405|56405:56141|inuse| 25 TCP Disable Internet Mail Server (SMTP)
789|28405|56405:56141|inuse| 143 TCP Disable Internet Mail Access Protocol Version 4 (IMAP4)
790|28405|56405:56141|inuse| 220 TCP Disable Internet Mail Access Protocol Version 3 (IMAP3)
791|28405|56405:56141|inuse| 21 TCP Disable FTP Server
7922011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "Port configuration for Domain ...")
7932011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:firewall_compare_update(7445)|firewall_compare_update scope of ipaddess matches no change needed
7942011-08-09 11:04:33|28405|56405:56141|inuse|inuse.pm:process(166)|forimaging flag is set to 1, skipping user connection check
7952011-08-09 11:04:33|28405|56405:56141|inuse|inuse.pm:_check_imaging_request(893)|checking if request is imaging or if forimaging flag has changed
7962011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:is_request_imaging(2302)|forimaging=1, currentstate=pending, laststate=inuse
7972011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:update_request_state(1991)|request 56405 state updated to: inuse, laststate to: inuse
7982011-08-09 11:04:33|28405|56405:56141|inuse|inuse.pm:process(209)|request state set back to inuse
7992011-08-09 11:04:33|28405|56405:56141|inuse|inuse.pm:process(222)|updated lastcheck time for this reservation to 2011-08-09 11:04:33
8002011-08-09 11:04:33|28405|56405:56141|inuse|inuse.pm:process(228)|exiting
8012011-08-09 11:04:33|28405|56405:56141|inuse|State.pm:DESTROY(829)|VCL::inuse destructor called, address: 1a188270
8022011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6742)|removing computerloadlog entries matching loadstate = begin
8032011-08-09 11:04:33|28405|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=56141
8042011-08-09 11:04:33|28405|56405:56141|inuse|State.pm:DESTROY(848)|number of database handles state process created: 1
8052011-08-09 11:04:33|28405|56405:56141|inuse|State.pm:DESTROY(876)|VCL::inuse process duration: 9 seconds
8062011-08-09 11:04:33|28405|56405:56141|inuse|VIM_SSH.pm:DESTROY(1685)|vim-cmd call count: 1
8072011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:reservation_being_processed(8938)|computerloadlog 'begin' entry does NOT exist for reservation 56141
8082011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:run_command(9010)|executed command: pgrep -fl 'vcld [0-9]+:56141 ', pid: 28764, exit status: 1, output:
8092011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:is_management_node_process_running(9192)|process is NOT running, identifier: 'vcld [0-9]+:56141 '
8102011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:reservation_being_processed(8959)|reservation is NOT currently being processed
8112011-08-09 11:09:06|11998|56405:56141|inuse|vcld:main(278)|reservation 56141 is NOT already being processed
8122011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:get_request_info(4520)|standalone affiliation found: CSUEB
8132011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:get_request_info(4527)|found NULL uid setting standalone flag: wv4973, uid: NULL
8142011-08-09 11:09:06|11998|56405:56141|inuse|vcld:main(283)|retrieved request information from database
8152011-08-09 11:09:06|11998|56405:56141|inuse|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
8162011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:update_request_state(1991)|request 56405 state updated to: pending, laststate to: inuse
8172011-08-09 11:09:06|11998|56405:56141|inuse|utils.pm:insertloadlog(3875)|inserted computer=68, begin, beginning to process, state is inuse
8182011-08-09 11:09:06|11998|56405:56141|inuse|vcld:make_new_child(515)|loaded VCL::inuse module
8192011-08-09 11:09:06|11998|56405:56141|inuse|vcld:make_new_child(539)|current number of forked kids: 1
8202011-08-09 11:09:06|28778|56405:56141|inuse|vcld:make_new_child(555)|vcld environment variable set to 0 for this process
8212011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'test' key for VCL::inuse object from arguments
8222011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'forimaging' key for VCL::inuse object from arguments
8232011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'reservation' key for VCL::inuse object from arguments
8242011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'userid' key for VCL::inuse object from arguments
8252011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'daterequested' key for VCL::inuse object from arguments
8262011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'RESERVATIONID' key for VCL::inuse object from arguments
8272011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'UPDATED' key for VCL::inuse object from arguments
8282011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'SUBIMAGE' key for VCL::inuse object from arguments
8292011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'CHECKTIME' key for VCL::inuse object from arguments
8302011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'state' key for VCL::inuse object from arguments
8312011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'laststate' key for VCL::inuse object from arguments
8322011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'PRELOADONLY' key for VCL::inuse object from arguments
8332011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'laststateid' key for VCL::inuse object from arguments
8342011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'user' key for VCL::inuse object from arguments
8352011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'id' key for VCL::inuse object from arguments
8362011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'PID' key for VCL::inuse object from arguments
8372011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'DURATION' key for VCL::inuse object from arguments
8382011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'PPID' key for VCL::inuse object from arguments
8392011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'datemodified' key for VCL::inuse object from arguments
8402011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'RESERVATIONCOUNT' key for VCL::inuse object from arguments
8412011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'end' key for VCL::inuse object from arguments
8422011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'stateid' key for VCL::inuse object from arguments
8432011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'PARENTIMAGE' key for VCL::inuse object from arguments
8442011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'checkuser' key for VCL::inuse object from arguments
8452011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'preload' key for VCL::inuse object from arguments
8462011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'NOTICEINTERVAL' key for VCL::inuse object from arguments
8472011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'start' key for VCL::inuse object from arguments
8482011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(172)|set 'logid' key for VCL::inuse object from arguments
8492011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_mn_os_object(361)|VCL::Module::OS::Linux::ManagementNode module loaded
8502011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(196)|VCL::Module::OS::Linux::ManagementNode object created for image <not set>, address: 1a1c11a0
8512011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{hostname}
852|28778|56405:56141|inuse| computer_hostname = vclnfs01.calstate.edu
8532011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{NODENAME}
854|28778|56405:56141|inuse| computer_node_name = vclnfs01
8552011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{SHORTNAME}
856|28778|56405:56141|inuse| computer_short_name = vclnfs01
8572011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_automethod(834)|data structure updated: $self->request_data->{reservation}{0}{computer}{IPaddress}
858|28778|56405:56141|inuse| computer_ip_address = 137.145.56.10
8592011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_mn_os_object(366)|VCL::Module::OS::Linux::ManagementNode OS object created, address: 1a1c11a0
8602011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(192)|VCL::inuse object created for state inuse, address: 1a6ca480
8612011-08-09 11:09:06|28778|56405:56141|inuse|State.pm:initialize(86)|obtained a database handle for this state process, stored as $ENV{dbh}
8622011-08-09 11:09:06|28778|56405:56141|inuse|State.pm:check_image_os(743)|no corrections need to be made, not an imaging request, returning 1
8632011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
8642011-08-09 11:09:06|28778|56405:56141|inuse|utils.pm:rename_vcld_process(7098)|reservation count: 1
8652011-08-09 11:09:06|28778|56405:56141|inuse|utils.pm:rename_vcld_process(7117)|PARENTIMAGE: 1
8662011-08-09 11:09:06|28778|56405:56141|inuse|utils.pm:rename_vcld_process(7118)|SUBIMAGE: 0
8672011-08-09 11:09:06|28778|56405:56141|inuse|utils.pm:rename_vcld_process(7136)|renamed process to 'vcld 56405:56141 inuse vmguest-64>vclesxi22 vmwarewinxp-SPSSPASWStatisticsAmos1844-v6 wv4973 (imaging)'
8682011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
8692011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
8702011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_os_object(298)|VCL::Module::OS::Windows::Version_5::XP module loaded
8712011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a1c11a0, returning 1
8722011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(196)|VCL::Module::OS::Windows::Version_5::XP object created for image vmwarewinxp-SPSSPASWStatisticsAmos1844-v6, address: 1a52e260
8732011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_os_object(304)|VCL::Module::OS::Windows::Version_5::XP OS object created for vmwarewinxp-SPSSPASWStatisticsAmos1844-v6, address: 1a52e260
8742011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_provisioning_object(420)|VCL::Module::Provisioning::VMware::VMware module loaded
8752011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a1c11a0, returning 1
8762011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VMware object created for computer vmguest-64, address: 1a860330
8772011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:initialize(230)|initializing VCL::Module::Provisioning::VMware::VMware object
8782011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
8792011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
8802011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
8812011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
8822011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
8832011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:initialize(249)|attempting to create OS object for the image currently loaded on the VM host: vclesxi22
884|28778|56405:56141|inuse| image name: noimage
885|28778|56405:56141|inuse| OS module: VCL::Module::OS::Linux::UnixLab
8862011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
8872011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
8882011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
8892011-08-09 11:09:06|28778|56405:56141|inuse|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
8902011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
8912011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:get_vmhost_os_object(1232)|attempting to load VM host OS module: VCL::Module::OS::Linux::UnixLab
8922011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:get_vmhost_os_object(1238)|VM host OS module loaded: VCL::Module::OS::Linux::UnixLab
8932011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a1c11a0, returning 1
8942011-08-09 11:09:06|28778|56405:56141|inuse|Module.pm:new(196)|VCL::Module::OS::Linux::UnixLab object created for image noimage, address: 1b0e57d0
8952011-08-09 11:09:06|28778|56405:56141|inuse|VMware.pm:get_vmhost_os_object(1244)|VM host OS object created: VCL::Module::OS::Linux::UnixLab
8962011-08-09 11:09:07|28778|56405:56141|inuse|OS.pm:is_ssh_responding(401)|vclesxi22 is responding to SSH, port 22: open, port 24: closed
8972011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:initialize(254)|OS on VM host vclesxi22 will be controlled using a VCL::Module::OS::Linux::UnixLab OS object
8982011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
8992011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
9002011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
9012011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
9022011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
9032011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1293)|attempting to load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
9042011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1299)|loaded VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
9052011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(172)|set 'vmhost_data' key for VCL::Module::Provisioning::VMware::vSphere_SDK object from arguments
9062011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(172)|set 'vmhost_os' key for VCL::Module::Provisioning::VMware::vSphere_SDK object from arguments
9072011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a1c11a0, returning 1
9082011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(200)|VCL::Module::Provisioning::VMware::vSphere_SDK object created for computer vmguest-64, address: 1b0db630
9092011-08-09 11:09:07|28778|56405:56141|inuse|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
9102011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1313)|API object could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK
9112011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(613)|computer ID argument was specified, retrieving data for computer ID: 4
9122011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(643)|image ID argument was specified: 4, DataStructure object will contain image information for the production imagerevision of this image
9132011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(660)|retrieved data for imagerevision ID: 4
9142011-08-09 11:09:07|28778|56405:56141|inuse|DataStructure.pm:_initialize(676)|retrieved data for image ID: 4
9152011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_datastructure(1190)|created DataStructure object for VM host: vclesxi22
9162011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1293)|attempting to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
9172011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1299)|loaded VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
9182011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(172)|set 'vmhost_data' key for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
9192011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(172)|set 'vmhost_os' key for VCL::Module::Provisioning::VMware::VIM_SSH object from arguments
9202011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:create_mn_os_object(335)|management node OS object has already been created, address: 1a1c11a0, returning 1
9212011-08-09 11:09:07|28778|56405:56141|inuse|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VIM_SSH object created for computer vmguest-64, address: 1b10a720
9222011-08-09 11:09:07|28778|56405:56141|inuse|VIM_SSH.pm:initialize(138)|VIM executable available on VM host: vim-cmd
9232011-08-09 11:09:07|28778|56405:56141|inuse|VIM_SSH.pm:initialize(140)|VCL::Module::Provisioning::VMware::VIM_SSH object initialized
9242011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_api_object(1320)|created API object: VCL::Module::Provisioning::VMware::VIM_SSH
9252011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:initialize(278)|VMware on VM host vclesxi22 will be controlled using vim-cmd via SSH
9262011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:initialize(293)|VMware OS and API objects created for VM host vclesxi22:
927|28778|56405:56141|inuse| VM host OS object type: VCL::Module::OS::Linux::UnixLab
928|28778|56405:56141|inuse| VMware API object type: VCL::Module::Provisioning::VMware::VIM_SSH
9292011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:get_vmhost_product_name(5405)|VMware product being used on VM host vclesxi22: 'VMware ESXi 4.1.0 build-348481'
9302011-08-09 11:09:07|28778|56405:56141|inuse|VMware.pm:initialize(307)|product: VMware ESXi 4.1.0 build-348481, OS object: VCL::Module::OS::Linux::UnixLab
9312011-08-09 11:09:07|28778|56405:56141|inuse|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd call count: 1 (hostsvc/datastore/listsummary)
9322011-08-09 11:09:08|28778|56405:56141|inuse|VIM_SSH.pm:_run_vim_cmd(208)|executed command on VM host vclesxi22: vim-cmd hostsvc/datastore/listsummary
9332011-08-09 11:09:08|28778|56405:56141|inuse|VMware.pm:get_datastore_info(5531)|retrieved datastore info from VM host:
934|28778|56405:56141|inuse| netappfiler02-sata1
935|28778|56405:56141|inuse| vclesxi22-local-vmfs
9362011-08-09 11:09:08|28778|56405:56141|inuse|VMware.pm:get_vmx_base_directory_path(2745)|determined vmx base directory path: /vmfs/volumes/netappfiler02-sata1
9372011-08-09 11:09:08|28778|56405:56141|inuse|Linux.pm:file_exists(1404)|'/vmfs/volumes/netappfiler02-sata1' exists on vclesxi22, files: 0, directories: 0, links: 1
9382011-08-09 11:09:08|28778|56405:56141|inuse|VMware.pm:initialize(324)|not checking if vmdk base directory exists because it is the same as the vmx base directory: /vmfs/volumes/netappfiler02-sata1
9392011-08-09 11:09:08|28778|56405:56141|inuse|Module.pm:create_provisioning_object(426)|VCL::Module::Provisioning::VMware::VMware provisioner object created for vmguest-64, address: 1a860330
9402011-08-09 11:09:08|28778|56405:56141|inuse|State.pm:initialize(126)|returning 1
9412011-08-09 11:09:08|28778|56405:56141|inuse|vcld:make_new_child(565)|VCL::inuse object created and initialized
9422011-08-09 11:09:08|28778|56405:56141|inuse|DataStructure.pm:get_reservation_remote_ip(1106)|retrieved remote IP for reservation 56141: 134.154.213.182
9432011-08-09 11:09:08|28778|56405:56141|inuse|DataStructure.pm:is_parent_reservation(991)|returning true: parent reservation ID for this request: 56141
9442011-08-09 11:09:08|28778|56405:56141|inuse|inuse.pm:_check_imaging_request(893)|checking if request is imaging or if forimaging flag has changed
9452011-08-09 11:09:08|28778|56405:56141|inuse|utils.pm:is_request_imaging(2302)|forimaging=1, currentstate=pending, laststate=inuse
9462011-08-09 11:09:08|28778|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6759)|removing computerloadlog entries NOT matching loadstate = begin
9472011-08-09 11:09:08|28778|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=56141
9482011-08-09 11:09:08|28778|56405:56141|inuse|inuse.pm:process(133)|rows removed from computerloadlog table for reservation 56141
9492011-08-09 11:09:08|28778|56405:56141|inuse|inuse.pm:process(141)|updated lastcheck time for reservation 56141
9502011-08-09 11:09:08|28778|56405:56141|inuse|inuse.pm:process(152)|beginning to poll
9512011-08-09 11:09:08|28778|56405:56141|inuse|utils.pm:run_ssh_command(5380)|executing SSH command on vmguest-64:
952|28778|56405:56141|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -o StrictHostKeyChecking=no -l root -p 22 -x vmguest-64 'netsh firewall show portopening enable' 2>&1
9532011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:run_ssh_command(5464)|run_ssh_command output:
954|28778|56405:56141|inuse| Port configuration for Domain profile:
955|28778|56405:56141|inuse| Port Protocol Mode Name
956|28778|56405:56141|inuse| -------------------------------------------------------------------
957|28778|56405:56141|inuse| 139 TCP Disable NetBIOS Session Service
958|28778|56405:56141|inuse| Scope: LocalSubNet
959|28778|56405:56141|inuse| 445 TCP Disable SMB over TCP
960|28778|56405:56141|inuse| Scope: LocalSubNet
961|28778|56405:56141|inuse| 137 UDP Disable NetBIOS Name Service
962|28778|56405:56141|inuse| Scope: LocalSubNet
963|28778|56405:56141|inuse| 138 UDP Disable NetBIOS Datagram Service
964|28778|56405:56141|inuse| Scope: LocalSubNet
965|28778|56405:56141|inuse| 1900 UDP Disable SSDP Component of UPnP Framework
966|28778|56405:56141|inuse| Scope: LocalSubNet
967|28778|56405:56141|inuse| 2869 TCP Disable UPnP Framework over TCP
968|28778|56405:56141|inuse| Scope: LocalSubNet
969|28778|56405:56141|inuse| 3389 TCP Disable Remote Desktop
970|28778|56405:56141|inuse| Scope: *
971|28778|56405:56141|inuse| Port configuration for Standard profile:
972|28778|56405:56141|inuse| Port Protocol Mode Name
973|28778|56405:56141|inuse| -------------------------------------------------------------------
974|28778|56405:56141|inuse| 139 TCP Enable NetBIOS Session Service
975|28778|56405:56141|inuse| Scope: LocalSubNet
976|28778|56405:56141|inuse| 445 TCP Enable SMB over TCP
977|28778|56405:56141|inuse| Scope: LocalSubNet
978|28778|56405:56141|inuse| 137 UDP Enable NetBIOS Name Service
979|28778|56405:56141|inuse| Scope: LocalSubNet
980|28778|56405:56141|inuse| 138 UDP Enable NetBIOS Datagram Service
981|28778|56405:56141|inuse| Scope: LocalSubNet
982|28778|56405:56141|inuse| 1900 UDP Enable SSDP Component of UPnP Framework
983|28778|56405:56141|inuse| Scope: LocalSubNet
984|28778|56405:56141|inuse| 2869 TCP Enable UPnP Framework over TCP
985|28778|56405:56141|inuse| Scope: LocalSubNet
986|28778|56405:56141|inuse| 3389 TCP Enable Remote Desktop
987|28778|56405:56141|inuse| Scope: 134.154.0.0/255.255.0.0
988|28778|56405:56141|inuse| Port configuration for Local Area Connection:
989|28778|56405:56141|inuse| Port Protocol Mode Name
990|28778|56405:56141|inuse| -------------------------------------------------------------------
991|28778|56405:56141|inuse| 3389 TCP Enable Remote Desktop
992|28778|56405:56141|inuse| 220 TCP Disable Internet Mail Access Protocol Version 3 (IMAP3)
993|28778|56405:56141|inuse| 110 TCP Disable Post-Office Protocol Version 3 (POP3)
994|28778|56405:56141|inuse| 443 TCP Disable Secure Web Server (HTTPS)
995|28778|56405:56141|inuse| 143 TCP Disable Internet Mail Access Protocol Version 4 (IMAP4)
996|28778|56405:56141|inuse| 25 TCP Disable Internet Mail Server (SMTP)
997|28778|56405:56141|inuse| 80 TCP Disable Web Server (HTTP)
998|28778|56405:56141|inuse| 22 TCP Enable Cygwin SSHD
999|28778|56405:56141|inuse| 23 TCP Disable Telnet Server
1000|28778|56405:56141|inuse| 21 TCP Disable FTP Server
1001|28778|56405:56141|inuse| Port configuration for Local Area Connection 2:
1002|28778|56405:56141|inuse| Port Protocol Mode Name
1003|28778|56405:56141|inuse| -------------------------------------------------------------------
1004|28778|56405:56141|inuse| 3389 TCP Disable Remote Desktop
1005|28778|56405:56141|inuse| 110 TCP Disable Post-Office Protocol Version 3 (POP3)
1006|28778|56405:56141|inuse| 80 TCP Disable Web Server (HTTP)
1007|28778|56405:56141|inuse| 443 TCP Disable Secure Web Server (HTTPS)
1008|28778|56405:56141|inuse| 23 TCP Disable Telnet Server
1009|28778|56405:56141|inuse| 22 TCP Disable Cygwin SSHD
1010|28778|56405:56141|inuse| 25 TCP Disable Internet Mail Server (SMTP)
1011|28778|56405:56141|inuse| 143 TCP Disable Internet Mail Access Protocol Version 4 (IMAP4)
1012|28778|56405:56141|inuse| 220 TCP Disable Internet Mail Access Protocol Version 3 (IMAP3)
1013|28778|56405:56141|inuse| 21 TCP Disable FTP Server
10142011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:run_ssh_command(5478)|SSH command executed on vmguest-64, returning (0, "Port configuration for Domain ...")
10152011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:firewall_compare_update(7445)|firewall_compare_update scope of ipaddess matches no change needed
10162011-08-09 11:09:16|28778|56405:56141|inuse|inuse.pm:process(166)|forimaging flag is set to 1, skipping user connection check
10172011-08-09 11:09:16|28778|56405:56141|inuse|inuse.pm:_check_imaging_request(893)|checking if request is imaging or if forimaging flag has changed
10182011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:is_request_imaging(2302)|forimaging=1, currentstate=pending, laststate=inuse
10192011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:update_request_state(1991)|request 56405 state updated to: inuse, laststate to: inuse
10202011-08-09 11:09:16|28778|56405:56141|inuse|inuse.pm:process(209)|request state set back to inuse
10212011-08-09 11:09:16|28778|56405:56141|inuse|inuse.pm:process(222)|updated lastcheck time for this reservation to 2011-08-09 11:09:16
10222011-08-09 11:09:16|28778|56405:56141|inuse|inuse.pm:process(228)|exiting
10232011-08-09 11:09:16|28778|56405:56141|inuse|State.pm:DESTROY(829)|VCL::inuse destructor called, address: 1a6ca480
10242011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6742)|removing computerloadlog entries matching loadstate = begin
10252011-08-09 11:09:16|28778|56405:56141|inuse|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=56141
10262011-08-09 11:09:16|28778|56405:56141|inuse|State.pm:DESTROY(848)|number of database handles state process created: 1
10272011-08-09 11:09:16|28778|56405:56141|inuse|State.pm:DESTROY(876)|VCL::inuse process duration: 10 seconds
10282011-08-09 11:09:16|28778|56405:56141|inuse|VIM_SSH.pm:DESTROY(1685)|vim-cmd call count: 1
1029
1030
1031NOW I WILL DO A IMAGE CREATE!