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
