Hi All, I am trying this in baby steps and running into few issues: One thing I have to say is your vcld.log is really amazing, it kind of walks you through the code precisely and yet complete.
I have few missing pieces that I want to identify and need your help here. I have inline questions starting with "#>>>" as below: 324 2010-03-17 13:02:45|19349|5:5|new|utils.pm:reservation_being_processed(9634)|computerloadlog 'begin' entry does NOT exist for reservation 5^M 325 2010-03-17 13:02:45|19349|5:5|new|utils.pm:reservation_being_processed(9686)|reservation is NOT currently being processed^M 326 2010-03-17 13:02:45|19349|5:5|new|vcld:main(276)|reservation 5 is NOT already being processed^M 327 ^M 328 |19349|5:5|new| ---- WARNING ---- ^M 329 |19349|5:5|new| 2010-03-17 13:02:45|19349|5:5|new|utils.pm:get_request_info(5218)|preferredimageid is not set for computer id=3^M 330 |19349|5:5|new| ( 0) utils.pm, notify (line: 737)^M 331 |19349|5:5|new| (-1) utils.pm, get_request_info (line: 5218)^M 332 |19349|5:5|new| (-2) vcld, main (line: 280)^M 333 ^M 334 2010-03-17 13:02:45|19349|5:5|new|utils.pm:get_request_info(5354)|standalone affiliation found: Local^M 335 2010-03-17 13:02:45|19349|5:5|new|utils.pm:get_management_node_info(6815)|management node info retrieved from database for colbert^M 336 2010-03-17 13:02:45|19349|5:5|new|vcld:main(281)|retrieved request information from database^M 337 2010-03-17 13:02:45|19349|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 338 2010-03-17 13:02:45|19349|5:5|new|utils.pm:update_request_state(2186)|request 5 state updated to: pending, laststate to: new^M 339 2010-03-17 13:02:45|19349|5:5|new|utils.pm:insertloadlog(4710)|inserted computer=3, begin, beginning to process, state is new^M 340 2010-03-17 13:02:45|19349|5:5|new|vcld:make_new_child(509)|loaded VCL::new module^M 341 2010-03-17 13:02:45|16651|5:5|new|vcld:make_new_child(582)|vcld environment variable set to 0 for this process^M 342 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(132)|constructor called, class=VCL::new^M 343 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(154)|VCL::new object created^M 344 2010-03-17 13:02:45|19349|5:5|new|vcld:make_new_child(566)|current number of forked kids: 1^M 345 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(85)|obtained a database handle for this state process, stored as $ENV{dbh}^M 346 2010-03-17 13:02:45|16651|5:5|new|State.pm:check_image_os(820)|no corrections need to be made, not an imaging request, returning 1^M 347 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 348 2010-03-17 13:02:45|16651|5:5|new|utils.pm:rename_vcld_process(7863)|reservation count: 1^M 349 2010-03-17 13:02:45|16651|5:5|new|utils.pm:rename_vcld_process(7882)|PARENTIMAGE: 1^M 350 2010-03-17 13:02:45|16651|5:5|new|utils.pm:rename_vcld_process(7883)|SUBIMAGE: 0^M 351 2010-03-17 13:02:45|16651|5:5|new|utils.pm:rename_vcld_process(7901)|renamed process to 'vcld VCL::new 5:5 new'^M 352 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 353 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 354 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(121)|attempting to load provisioning module: VCL::Module::Provisioning::esx^M 355 2010-03-17 13:02:45|16651|5:5|new|esx.pm:initialize(138)|esx vmware toolkit root path found: /usr/lib/vmware-vcli/apps^M 356 2010-03-17 13:02:45|16651|5:5|new|esx.pm:initialize(140)|vmware ESX module initialized^M 357 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(127)|VCL::Module::Provisioning::esx module loaded^M 358 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(132)|constructor called, class=VCL::Module::Provisioning::esx^M 359 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(154)|VCL::Module::Provisioning::esx object created^M 360 2010-03-17 13:02:45|16651|5:5|new|esx.pm:initialize(138)|esx vmware toolkit root path found: /usr/lib/vmware-vcli/apps 361 2010-03-17 13:02:45|16651|5:5|new|esx.pm:initialize(140)|vmware ESX module initialized^M 362 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(131)|VCL::Module::Provisioning::esx provisioner object created^M 363 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(145)|attempting to load OS module: VCL::Module::OS::Windows::Version_5::XP^M 364 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(151)|VCL::Module::OS::Windows::Version_5::XP module loaded^M 365 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(132)|constructor called, class=VCL::Module::OS::Windows::Version_5::XP^M 366 2010-03-17 13:02:45|16651|5:5|new|Module.pm:new(154)|VCL::Module::OS::Windows::Version_5::XP object created^M 367 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(154)|VCL::Module::OS::Windows::Version_5::XP OS object created^M 368 2010-03-17 13:02:45|16651|5:5|new|State.pm:initialize(169)|returning 1^M 369 2010-03-17 13:02:45|16651|5:5|new|vcld:make_new_child(591)|VCL::new object created and initialized^M 370 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 371 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1946)|attempting to retrieve current state of computer resxi-2 from the da tabase^M 372 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1977)|retrieved current state of computer resxi-2 from the database: avail able^M 373 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(697)|data structure updated: $self->request_data->{reservation}{5}{computer}{state}{na me}^M 374 |16651|5:5|new| computer_state_name = available^M 375 ^M 376 |16651|5:5|new| ---- WARNING ---- ^M 377 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_id: $self->request_data->{reservation}{5}{computer}{preferredimage}{id}^M 378 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 379 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 380 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 381 |16651|5:5|new| (-3) new.pm, process (line: 106)^M 382 |16651|5:5|new| (-4) vcld, make_new_child (line: 594)^M 383 |16651|5:5|new| (-5) vcld, main (line: 341)^M 384 ^M 385 ^M #>>> Not sure if I am missing something here. 386 |16651|5:5|new| ---- WARNING ---- ^M 387 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_name: $self->request_data->{reservation}{5}{computer}{preferredimage}{name}^M 388 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 389 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 390 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 391 |16651|5:5|new| (-3) new.pm, process (line: 107)^M 392 |16651|5:5|new| (-4) vcld, make_new_child (line: 594)^M 393 |16651|5:5|new| (-5) vcld, main (line: 341)^M 394 ^M 395 2010-03-17 13:02:45|16651|5:5|new|utils.pm:get_management_node_id(9364)|environment variable: 1^M 396 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(134)|reservation is parent = 1^M 397 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(135)|preload only = 0^M 398 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(136)|originating request state = new^M 399 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(137)|originating request laststate = new^M 400 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(138)|originating computer state = available^M 401 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(139)|originating computer type = virtualmachine^M 402 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 403 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1946)|attempting to retrieve current state of computer resxi-2 from the da tabase^M 404 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1977)|retrieved current state of computer resxi-2 from the database: avail able^M 405 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(697)|data structure updated: $self->request_data->{reservation}{5}{computer}{state}{na me}^M 406 |16651|5:5|new| computer_state_name = available^M 407 ^M 408 |16651|5:5|new| ---- WARNING ---- ^M 409 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_id: $self->request_data->{reservation}{5}{computer}{preferredimage}{id}^M 410 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 411 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 412 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 413 |16651|5:5|new| (-3) new.pm, computer_not_being_used (line: 750)^M 414 |16651|5:5|new| (-4) new.pm, process (line: 170)^M 415 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 416 |16651|5:5|new| (-6) vcld, main (line: 341)^M 417 ^M 418 ^M 419 |16651|5:5|new| ---- WARNING ---- ^M 420 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_name: $self->request_data->{reservation}{5}{computer}{preferredimage}{name}^M 421 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 422 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 423 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 424 |16651|5:5|new| (-3) new.pm, computer_not_being_used (line: 751)^M 425 |16651|5:5|new| (-4) new.pm, process (line: 170)^M 426 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 427 |16651|5:5|new| (-6) vcld, main (line: 341)^M 428 ^M 429 2010-03-17 13:02:45|16651|5:5|new|utils.pm:get_management_node_id(9364)|environment variable: 1^M 430 2010-03-17 13:02:45|16651|5:5|new|new.pm:computer_not_being_used(788)|resxi-2 state is available^M 431 2010-03-17 13:02:45|16651|5:5|new|new.pm:computer_not_being_used(798)|resxi-2 is available, its state is available^M 432 2010-03-17 13:02:45|16651|5:5|new|new.pm:process(170)|resxi-2 is not being used^M 433 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:is_parent_reservation(854)|returning true: parent reservation ID for this request: 5^M 434 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1946)|attempting to retrieve current state of computer resxi-2 from the da tabase^M 435 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:get_computer_state_name(1977)|retrieved current state of computer resxi-2 from the database: avail able^M 436 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(697)|data structure updated: $self->request_data->{reservation}{5}{computer}{state}{na me}^M 437 |16651|5:5|new| computer_state_name = available^M 438 ^M 439 |16651|5:5|new| ---- WARNING ---- ^M 440 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_id: $self->request_data->{reservation}{5}{computer}{preferredimage}{id}^M 441 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 442 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 443 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 444 |16651|5:5|new| (-3) new.pm, reload_image (line: 480)^M 445 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 446 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 447 |16651|5:5|new| (-6) vcld, main (line: 341)^M 448 ^M 449 ^M 450 |16651|5:5|new| ---- WARNING ---- ^M 451 |16651|5:5|new| 2010-03-17 13:02:45|16651|5:5|new|DataStructure.pm:_automethod(675)|corresponding data has not been initialized for get_computer_pref erredimage_name: $self->request_data->{reservation}{5}{computer}{preferredimage}{name}^M 452 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 453 |16651|5:5|new| (-1) DataStructure.pm, _automethod (line: 675)^M 454 |16651|5:5|new| (-2) Autoload.pm, __ANON__ (line: 80)^M 455 |16651|5:5|new| (-3) new.pm, reload_image (line: 481)^M 456 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 457 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 458 |16651|5:5|new| (-6) vcld, main (line: 341)^M 459 ^M 460 2010-03-17 13:02:45|16651|5:5|new|utils.pm:get_management_node_id(9364)|environment variable: 1^M 461 2010-03-17 13:02:45|16651|5:5|new|new.pm:reload_image(514)|calling VCL::Module::Provisioning::esx->node_status()^M 462 2010-03-17 13:02:45|16651|5:5|new|utils.pm:insertloadlog(4710)|inserted computer=3, statuscheck, checking status of node^M 463 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(787)|Entering node_status, checking status of resxi-2^M 464 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(788)|request_for_imaging: 0^M 465 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(789)|requeseted image name: vmwarewinxp-base7-v0^M 466 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(819)|checking if resxi-2 is pingable^M 467 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(822)|resxi-2 is pingable (1)^M 468 2010-03-17 13:02:45|16651|5:5|new|esx.pm:node_status(836)|Trying to ssh...^M 469 2010-03-17 13:02:45|16651|5:5|new|utils.pm:run_ssh_command(6180)|executing SSH command on resxi-2:^M 470 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x resxi-2 'uname -s' 2>&1^M 471 2010-03-17 13:02:46|16651|5:5|new|utils.pm:run_ssh_command(6262)|run_ssh_command output:^M 472 |16651|5:5|new| CYGWIN_NT-5.1^M 473 2010-03-17 13:02:46|16651|5:5|new|utils.pm:run_ssh_command(6276)|SSH command executed on resxi-2, returning (0, "CYGWIN_NT-5.1")^M 474 2010-03-17 13:02:46|16651|5:5|new|esx.pm:node_status(845)|SSH good, trying to query image name^M 475 2010-03-17 13:02:46|16651|5:5|new|utils.pm:run_ssh_command(6180)|executing SSH command on resxi-2:^M 476 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x resxi-2 'cat currentimage.txt' 2>&1^M 477 2010-03-17 13:02:47|16651|5:5|new|utils.pm:run_ssh_command(6262)|run_ssh_command output:^M 478 |16651|5:5|new| cat: currentimage.txt: No such file or directory^M #>>> currentimage.txt : Is this something that we have to create at anytime? I am thinking it is created automatically when a image is loaded for the first time. 479 2010-03-17 13:02:47|16651|5:5|new|utils.pm:run_ssh_command(6272)|SSH command executed on resxi-2, command:^M 480 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x resxi-2 'cat currentimage.txt' 2>&1^M 481 |16651|5:5|new| returning (1, "cat: currentimage.txt: No such...")^M 482 2010-03-17 13:02:47|16651|5:5|new|esx.pm:node_status(852)|Image name: cat: currentimage.txt: No such file or directory^M 483 2010-03-17 13:02:47|16651|5:5|new|esx.pm:node_status(861)|resxi-2 reports current image is currentimage= cat: currentimage.txt: No such file or direc tory requestedimagename= vmwarewinxp-base7-v0^M 484 2010-03-17 13:02:47|16651|5:5|new|esx.pm:node_status(874)|status set to RELOAD^M 485 2010-03-17 13:02:47|16651|5:5|new|esx.pm:node_status(882)|returning node status hash reference ($node_status->{status}=RELOAD)^M 486 2010-03-17 13:02:47|16651|5:5|new|new.pm:reload_image(529)|node_status returned a hash reference^M 487 2010-03-17 13:02:47|16651|5:5|new|new.pm:reload_image(534)|node_status hash reference contains key {status}=RELOAD^M 488 2010-03-17 13:02:47|16651|5:5|new|new.pm:reload_image(602)|node status is RELOAD, resxi-2 will be reloaded^M 489 2010-03-17 13:02:47|16651|5:5|new|utils.pm:insertloadlog(4710)|inserted computer=3, loadimageblade, resxi-2 must be reloaded with vmwarewinxp-base7-v 0^M 490 2010-03-17 13:02:47|16651|5:5|new|new.pm:reload_image(616)|calling VCL::Module::Provisioning::esx->does_image_exist()^M 491 Use of uninitialized value in concatenation (.) or string at^M 492 /usr/local/vcl/bin/../lib/VCL/Module/Provisioning/esx.pm line 907 (#1)^M 493 (W uninitialized) An undefined value was used as if it were already^M 494 defined. It was interpreted as a "" or a 0, but maybe it was a mistake.^M 495 To suppress this warning assign a defined value to your variables.^M 496 ^M 497 To help you figure out what was undefined, perl tells you what operation^M 498 you used the undefined value in. Note, however, that perl optimizes your^M 499 program and the operation displayed in the warning may not necessarily^M 500 appear literally in your program. For example, "that $foo" is^M 501 usually optimized into "that " . $foo, and the warning will refer to^M 502 the concatenation (.) operator, even though there is no . in your^M 503 program.^M #>>> Can we ignore this? 504 ^M 505 ^M 506 |16651|5:5|new| ---- WARNING ---- ^M 507 |16651|5:5|new| 2010-03-17 13:02:47|16651|5:5|new|vcld:warning_handler(636)|Use of uninitialized value in concatenation (.) or string at /usr/local/v cl/bin/../lib/VCL/Module/Provisioning/esx.pm line 907.^M 508 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 509 |16651|5:5|new| (-1) vcld, warning_handler (line: 636)^M 510 |16651|5:5|new| (-2) esx.pm, does_image_exist (line: 907)^M 511 |16651|5:5|new| (-3) new.pm, reload_image (line: 618)^M 512 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 513 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 514 |16651|5:5|new| (-6) vcld, main (line: 341)^M 515 ^M 516 2010-03-17 13:02:47|16651|5:5|new|utils.pm:run_ssh_command(6180)|executing SSH command on /install/image/nfs1:^M 517 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x /install/image/nfs1 'ls -1 /golden 2>&1' 2>&1^M #>>> This is where my real issues are: I realized reading the README for esx and esxthin, that I need to have a VCL mount point and a subdirectory /golden for my images But what I am missing here is why is it trying to ssh -x /install/image/nfs1 which is actually the Data Store path. Isn't it supposed to ssh to my VMhost machine. Also when does VCL code use the esxthin.pm, as opposed to esx.pm? 518 ^M 519 |16651|5:5|new| ---- WARNING ---- ^M 520 |16651|5:5|new| 2010-03-17 13:02:47|16651|5:5|new|utils.pm:run_ssh_command(6252)|attempt 1/3: failed to execute SSH command on /install/image/nfs1: l s -1 /golden 2>&1, exit status: 255, SSH exits with the exit status of the remote command or with 255 if an error occurred, output:^M 521 |16651|5:5|new| ssh output (ls -1 /gol...): ssh: /install/image/nfs1: Name or service not known^M 522 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 523 |16651|5:5|new| (-1) utils.pm, run_ssh_command (line: 6252)^M 524 |16651|5:5|new| (-2) esx.pm, does_image_exist (line: 910)^M 525 |16651|5:5|new| (-3) new.pm, reload_image (line: 618)^M 526 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 527 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 528 |16651|5:5|new| (-6) vcld, main (line: 341)^M 529 ^M 530 2010-03-17 13:02:47|16651|5:5|new|utils.pm:run_ssh_command(6172)|sleeping for 2 seconds before making next SSH attempt^M 531 2010-03-17 13:02:49|16651|5:5|new|utils.pm:run_ssh_command(6184)|attempt 2/3: executing SSH command on /install/image/nfs1:^M 532 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x /install/image/nfs1 'ls -1 /golden 2>&1' 2>&1^M 533 ^M 534 |16651|5:5|new| ---- WARNING ---- ^M 535 |16651|5:5|new| 2010-03-17 13:02:49|16651|5:5|new|utils.pm:run_ssh_command(6252)|attempt 2/3: failed to execute SSH command on /install/image/nfs1: l s -1 /golden 2>&1, exit status: 255, SSH exits with the exit status of the remote command or with 255 if an error occurred, output:^M 536 |16651|5:5|new| ssh output (ls -1 /gol...): ssh: /install/image/nfs1: Name or service not known^M 537 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 538 |16651|5:5|new| (-1) utils.pm, run_ssh_command (line: 6252)^M 539 |16651|5:5|new| (-2) esx.pm, does_image_exist (line: 910)^M 540 |16651|5:5|new| (-3) new.pm, reload_image (line: 618)^M 541 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 542 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 543 |16651|5:5|new| (-6) vcld, main (line: 341)^M 544 ^M 545 2010-03-17 13:02:49|16651|5:5|new|utils.pm:run_ssh_command(6172)|sleeping for 15 seconds before making next SSH attempt^M 546 2010-03-17 13:02:50|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:02:50^M 547 2010-03-17 13:02:55|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:02:55^M 548 2010-03-17 13:03:00|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:00^M 549 2010-03-17 13:03:04|16651|5:5|new|utils.pm:run_ssh_command(6184)|attempt 3/3: executing SSH command on /install/image/nfs1:^M 550 |16651|5:5|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x /install/image/nfs1 'ls -1 /golden 2>&1' 2>&1^M 551 ^M 552 |16651|5:5|new| ---- WARNING ---- ^M 553 |16651|5:5|new| 2010-03-17 13:03:04|16651|5:5|new|utils.pm:run_ssh_command(6252)|attempt 3/3: failed to execute SSH command on /install/image/nfs1: l s -1 /golden 2>&1, exit status: 255, SSH exits with the exit status of the remote command or with 255 if an error occurred, output:^M 554 |16651|5:5|new| ssh output (ls -1 /gol...): ssh: /install/image/nfs1: Name or service not known^M 555 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 556 |16651|5:5|new| (-1) utils.pm, run_ssh_command (line: 6252)^M 557 |16651|5:5|new| (-2) esx.pm, does_image_exist (line: 910)^M 558 |16651|5:5|new| (-3) new.pm, reload_image (line: 618)^M 559 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 560 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 561 |16651|5:5|new| (-6) vcld, main (line: 341)^M 562 ^M 563 ^M 564 |16651|5:5|new| ---- WARNING ---- ^M 565 |16651|5:5|new| 2010-03-17 13:03:04|16651|5:5|new|utils.pm:run_ssh_command(6285)|failed to run SSH command after 3 attempts, command: /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x /install/image/nfs1 'ls -1 /golden 2>&1' 2>&1, exit status: 255, output:^M 566 |16651|5:5|new| ssh output (ls -1 /gol...): ssh: /install/image/nfs1: Name or service not known^M 567 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 568 |16651|5:5|new| (-1) utils.pm, run_ssh_command (line: 6285)^M 569 |16651|5:5|new| (-2) esx.pm, does_image_exist (line: 910)^M 570 |16651|5:5|new| (-3) new.pm, reload_image (line: 618)^M 571 |16651|5:5|new| (-4) new.pm, process (line: 266)^M 572 |16651|5:5|new| (-5) vcld, make_new_child (line: 594)^M 573 |16651|5:5|new| (-6) vcld, main (line: 341)^M 574 ^M 575 No recipient addresses found in header^M 576 2010-03-17 13:03:04|16651|5:5|new|utils.pm:mail(1348)|SUCCESS -- Sending mail To: , PROBLEM -- esx.pm^M 577 ^M 578 |16651|5:5|new| ---- CRITICAL ---- ^M 579 |16651|5:5|new| 2010-03-17 13:03:04|16651|5:5|new|esx.pm:does_image_exist(922)|LS failed^M 580 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 581 |16651|5:5|new| (-1) esx.pm, does_image_exist (line: 922)^M 582 |16651|5:5|new| (-2) new.pm, reload_image (line: 618)^M 583 |16651|5:5|new| (-3) new.pm, process (line: 266)^M 584 |16651|5:5|new| (-4) vcld, make_new_child (line: 594)^M 585 |16651|5:5|new| (-5) vcld, main (line: 341)^M 586 ^M 587 2010-03-17 13:03:04|16651|5:5|new|new.pm:reload_image(623)|vmwarewinxp-base7-v0 does not exist on this management node^M 588 No recipient addresses found in header^M 589 2010-03-17 13:03:05|16651|5:5|new|utils.pm:mail(1348)|SUCCESS -- Sending mail To: , PROBLEM -- new.pm^M 590 ^M 591 |16651|5:5|new| ---- CRITICAL ---- ^M 592 |16651|5:5|new| 2010-03-17 13:03:04|16651|5:5|new|new.pm:reload_image(639)|unable to retrieve image from another management node, retrieve_image() is not implemented by VCL::Module::Provisioning::esx^M 593 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 594 |16651|5:5|new| (-1) new.pm, reload_image (line: 639)^M 595 |16651|5:5|new| (-2) new.pm, process (line: 266)^M 596 |16651|5:5|new| (-3) vcld, make_new_child (line: 594)^M 597 |16651|5:5|new| (-4) vcld, main (line: 341)^M 598 ^M 599 2010-03-17 13:03:05|16651|5:5|new|utils.pm:insertloadlog(4710)|inserted computer=3, failed, failed requested image does not exist on management node, retrieve_image() is not implemented^M 600 ^M 601 |16651|5:5|new| ---- WARNING ---- ^M 602 |16651|5:5|new| 2010-03-17 13:03:05|16651|5:5|new|new.pm:process(313)|failed to load resxi-2 with vmwarewinxp-base7-v0^M 603 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 604 |16651|5:5|new| (-1) new.pm, process (line: 313)^M 605 |16651|5:5|new| (-2) vcld, make_new_child (line: 594)^M 606 |16651|5:5|new| (-3) vcld, main (line: 341)^M 607 ^M 608 2010-03-17 13:03:05|16651|5:5|new|DataStructure.pm:get_computer_state_name(1946)|attempting to retrieve current state of computer resxi-2 from the da tabase^M 609 2010-03-17 13:03:05|16651|5:5|new|DataStructure.pm:get_computer_state_name(1977)|retrieved current state of computer resxi-2 from the database: avail able^M 610 2010-03-17 13:03:05|16651|5:5|new|DataStructure.pm:_automethod(697)|data structure updated: $self->request_data->{reservation}{5}{computer}{state}{na me}^M 611 |16651|5:5|new| computer_state_name = available^M 612 No recipient addresses found in header^M 613 2010-03-17 13:03:05|16651|5:5|new|utils.pm:mail(1348)|SUCCESS -- Sending mail To: , PROBLEM -- State.pm^M 614 ^M 615 |16651|5:5|new| ---- CRITICAL ---- ^M 616 |16651|5:5|new| 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(290)|reservation failed on resxi-2: process failed after trying to load or make available^M 617 |16651|5:5|new| ( 0) utils.pm, notify (line: 737)^M 618 |16651|5:5|new| (-1) State.pm, reservation_failed (line: 290)^M 619 |16651|5:5|new| (-2) new.pm, process (line: 316)^M 620 |16651|5:5|new| (-3) vcld, make_new_child (line: 594)^M 621 |16651|5:5|new| (-4) vcld, main (line: 341)^M 622 ^M 623 2010-03-17 13:03:05|16651|5:5|new|utils.pm:insertloadlog(4710)|inserted computer=3, failed, process failed after trying to load or make available^M 624 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(293)|inserted computerloadlog entry^M 625 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(301)|updated log ending value to 'failed', logid=3^M 626 2010-03-17 13:03:05|16651|5:5|new|utils.pm:update_computer_state(2228)|computer 3 state updated to: failed^M 627 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(312)|computer resxi-2 (3) state set to failed^M 628 2010-03-17 13:03:05|16651|5:5|new|utils.pm:update_request_state(2186)|request 5 state updated to: failed, laststate to: new^M 629 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(325)|set request state to 'failed'/'new'^M 630 2010-03-17 13:03:05|16651|5:5|new|utils.pm:is_inblockrequest(6972)|zero rows were returned from database select^M 631 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(343)|resxi-2 is NOT in blockcomputers table^M 632 2010-03-17 13:03:05|16651|5:5|new|State.pm:reservation_failed(346)|exiting 1^M 633 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(905)|destructor called, ref($self)=VCL::new^M 634 2010-03-17 13:03:05|16651|5:5|new|utils.pm:delete_computerloadlog_reservation(7551)|removing computerloadlog entries matching loadstate = begin^M 635 2010-03-17 13:03:05|16651|5:5|new|utils.pm:delete_computerloadlog_reservation(7598)|deleted rows from computerloadlog for reservation id=5^M 636 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(912)|removed computerloadlog rows with loadstate=begin for reservation^M 637 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(924)|number of database handles state process created: 1^M 638 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(933)|process has a database handle stored in $ENV{dbh}, attempting disconnect^M 639 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(935)|$ENV{dbh}: database disconnect successful^M 640 2010-03-17 13:03:05|16651|5:5|new|State.pm:DESTROY(949)|VCL::new process 16651 exiting^M 641 2010-03-17 13:03:05|19349|vcld:REAPER(744)|VCL process exited for reservation 5^M 642 2010-03-17 13:03:05|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:05^M 643 2010-03-17 13:03:10|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:10^M 644 2010-03-17 13:03:15|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:15^M 645 2010-03-17 13:03:20|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:20^M 646 2010-03-17 13:03:25|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:25^M 647 2010-03-17 13:03:30|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:30^M 648 2010-03-17 13:03:35|19349|vcld:main(165)|lastcheckin time updated for management node 1: 2010-03-17 13:03:35^M Thank you, Amit