You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@vcl.apache.org by Alexander Patterson <al...@csueastbay.edu> on 2010/04/26 19:50:16 UTC

Image failing at resource ready

Hello,

I am getting an error one one of my new Images that was built in Vmware
Server.
I had to built it in Vmware Server due to it's Size.

19.1 GB

The Software is Adobe Creative Suite 4 Web Premium, It's Windows XP SP3
Firewall is off
SingleCore Image, i have built my other 30 that work the same way. This one
is not working.

I can SSH into the image. It works just fine when I load in in  vmware
server. When I try to load it into the system. I always get stuck at
resource ready.

resource ready(43)0:00/0:221:09
failed: process failed after trying to load or make available

It doesn't matter what Vmware guest it uses, all of them fail at the same
point.

Here is the Log


|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 'C:/Windows/System32/reg.exe add
"HKCR\CLSID\{20D04FE0-3AEA-1069-A2D8-08002B30309D}" /v LocalizedString /t
REG_EXPAND_SZ /d "Adobe Creative Suite 4 Web Premium" /f' 2>&1
2010-04-26
10:44:18|19812|2127:2121|new|Windows.pm:set_my_computer_name(3847)|my
computer name changed to 'Adobe Creative Suite 4 Web Premium'
2010-04-26
10:44:18|19812|2127:2121|new|Windows.pm:set_password(1640)|setting password
of root to Si2GJL on vmguest-25
2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-25:
|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 'net user root 'Si2GJL'' 2>&1
2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|19812|2127:2121|new| The command completed successfully.
2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6276)|SSH
command executed on vmguest-25, returning (0, "The command completed
successf...")
2010-04-26
10:44:18|19812|2127:2121|new|Windows.pm:set_password(1642)|password changed
to 'Si2GJL' for user 'root' on vmguest-25
2010-04-26 10:44:18|19812|2127:2121|new|Windows.pm:set_password(1656)|root
account password changed, must also change sshd service credentials
2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-25:
|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 '$SYSTEMROOT/System32/sc.exe config sshd obj= ".\root" password=
"Si2GJL"' 2>&1
2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|19812|2127:2121|new| [SC] ChangeServiceConfig SUCCESS
2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6276)|SSH
command executed on vmguest-25, returning (0, "[SC] ChangeServiceConfig
SUCCE...")
2010-04-26
10:44:19|19812|2127:2121|new|Windows.pm:set_service_credentials(3340)|changed
logon credentials for 'sshd' service to root (Si2GJL) on vmguest-25
2010-04-26
10:44:19|19812|2127:2121|new|Windows.pm:set_password(1664)|changing
passwords for scheduled tasks
2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-25:
|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 'schtasks.exe /Query /V /FO LIST' 2>&1
2010-04-26 10:44:19|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:19
2010-04-26
10:44:20|19812|2127:2121|new|Windows.pm:set_password(1666)|queried scheduled
tasks on vmguest-25
2010-04-26
10:44:20|19812|2127:2121|new|Windows.pm:set_password(1686)|password needs to
be updated for scheduled task:
User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}
|19812|2127:2121|new| Run As User: CSUVCLXP\root
2010-04-26
10:44:20|19812|2127:2121|new|Windows.pm:set_password(1686)|password needs to
be updated for scheduled task:
User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}
|19812|2127:2121|new| Run As User: CSUVCLXP\root
2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-25:
|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 'schtasks.exe /Change /RP "Si2GJL" /TN
"User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}"' 2>&1
2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|19812|2127:2121|new| ERROR: Unable to establish existence of the account
specified.
2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6272)|SSH
command executed on vmguest-25, command:
|19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-25 'schtasks.exe /Change /RP "Si2GJL" /TN
"User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}"' 2>&1
|19812|2127:2121|new| returning (1, "ERROR: Unable to establish exi...")

|19812|2127:2121|new| ---- WARNING ----
|19812|2127:2121|new| 2010-04-26
10:44:20|19812|2127:2121|new|Windows.pm:set_password(1698)|failed to change
password for scheduled task:
User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}, exit
status: 1, output:
|19812|2127:2121|new| ERROR: Unable to establish existence of the account
specified.
|19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
|19812|2127:2121|new| (-1) Windows.pm, set_password (line: 1698)
|19812|2127:2121|new| (-2) Windows.pm, post_load (line: 558)
|19812|2127:2121|new| (-3) new.pm, reload_image (line: 692)
|19812|2127:2121|new| (-4) new.pm, process (line: 266)
|19812|2127:2121|new| (-5) vcld, make_new_child (line: 594)
|19812|2127:2121|new| (-6) vcld, main (line: 341)


|19812|2127:2121|new| ---- WARNING ----
|19812|2127:2121|new| 2010-04-26
10:44:20|19812|2127:2121|new|Windows.pm:post_load(559)|failed to set random
root password
|19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
|19812|2127:2121|new| (-1) Windows.pm, post_load (line: 559)
|19812|2127:2121|new| (-2) new.pm, reload_image (line: 692)
|19812|2127:2121|new| (-3) new.pm, process (line: 266)
|19812|2127:2121|new| (-4) vcld, make_new_child (line: 594)
|19812|2127:2121|new| (-5) vcld, main (line: 341)

No recipient addresses found in header
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:mail(1348)|SUCCESS --
Sending mail To: , PROBLEM -- new.pm

|19812|2127:2121|new| ---- CRITICAL ----
|19812|2127:2121|new| 2010-04-26
10:44:20|19812|2127:2121|new|new.pm:reload_image(697)|failed
to perform OS post-load tasks for vmwarewinxp-AdobeCS4-v0 on vmguest-25,
returning
|19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
|19812|2127:2121|new| (-1) new.pm, reload_image (line: 697)
|19812|2127:2121|new| (-2) new.pm, process (line: 266)
|19812|2127:2121|new| (-3) vcld, make_new_child (line: 594)
|19812|2127:2121|new| (-4) vcld, main (line: 341)

2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:insertloadlog(4710)|inserted
computer=29, loadimagefailed, failed to perform OS post-load tasks for
vmwarewinxp-AdobeCS4-v0 on vmguest-25

|19812|2127:2121|new| ---- WARNING ----
|19812|2127:2121|new| 2010-04-26
10:44:21|19812|2127:2121|new|new.pm:process(313)|failed
to load vmguest-25 with vmwarewinxp-AdobeCS4-v0
|19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
|19812|2127:2121|new| (-1) new.pm, process (line: 313)
|19812|2127:2121|new| (-2) vcld, make_new_child (line: 594)
|19812|2127:2121|new| (-3) vcld, main (line: 341)

2010-04-26
10:44:21|19812|2127:2121|new|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vmguest-25 from the database
2010-04-26
10:44:21|19812|2127:2121|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vmguest-25 from the database: reloading
2010-04-26
10:44:21|19812|2127:2121|new|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{2121}{computer}{state}{name}
|19812|2127:2121|new| computer_state_name = reloading
No recipient addresses found in header
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:mail(1348)|SUCCESS --
Sending mail To: , PROBLEM -- State.pm

|19812|2127:2121|new| ---- CRITICAL ----
|19812|2127:2121|new| 2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(290)|reservation
failed on vmguest-25: process failed after trying to load or make available
|19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
|19812|2127:2121|new| (-1) State.pm, reservation_failed (line: 290)
|19812|2127:2121|new| (-2) new.pm, process (line: 316)
|19812|2127:2121|new| (-3) vcld, make_new_child (line: 594)
|19812|2127:2121|new| (-4) vcld, main (line: 341)

2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:insertloadlog(4710)|inserted
computer=29, failed, process failed after trying to load or make available
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(293)|inserted
computerloadlog entry
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(301)|updated log
ending value to 'failed', logid=1486
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:update_computer_state(2228)|computer
29 state updated to: failed
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(312)|computer
vmguest-25 (29) state set to failed
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:update_request_state(2186)|request
2127 state updated to: failed, laststate to: new
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(325)|set
request state to 'failed'/'new'
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:is_inblockrequest(6976)|1
rows were returned from database select
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(334)|vmguest-25 in
blockcomputers table
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(335)|removed
vmguest-25 from blockcomputers table
2010-04-26
10:44:21|19812|2127:2121|new|State.pm:reservation_failed(346)|exiting 1
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(905)|destructor
called, ref($self)=VCL::new
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:delete_computerloadlog_reservation(7551)|removing
computerloadlog entries matching loadstate = begin
2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:delete_computerloadlog_reservation(7598)|deleted
rows from computerloadlog for reservation id=2121
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(912)|removed
computerloadlog rows with loadstate=begin for reservation
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(924)|number of
database handles state process created: 1
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(933)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(935)|$ENV{dbh}:
database disconnect successful
2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(949)|VCL::new
process 19812 exiting
2010-04-26 10:44:21|8190|vcld:REAPER(744)|VCL process exited for reservation
2121
2010-04-26 10:44:21|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:21
2010-04-26 10:44:26|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:26
2010-04-26 10:44:27|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
for connection by ak565463 on vmguest-37, attempt 10
2010-04-26 10:44:27|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-37:
|19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-37 'netstat -an' 2>&1
2010-04-26 10:44:31|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:31
2010-04-26 10:44:36|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:36
2010-04-26 10:44:41|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:41
2010-04-26 10:44:46|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:46
2010-04-26 10:44:47|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
for connection by ak565463 on vmguest-37, attempt 11
2010-04-26 10:44:47|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-37:
|19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-37 'netstat -an' 2>&1
2010-04-26 10:44:51|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:51
2010-04-26 10:44:56|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:44:56
2010-04-26 10:45:01|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:45:01
2010-04-26 10:45:06|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:45:06
2010-04-26 10:45:08|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
for connection by ak565463 on vmguest-37, attempt 12
2010-04-26 10:45:08|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
SSH command on vmguest-37:
|19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vmguest-37 'netstat -an' 2>&1
2010-04-26 10:45:11|8190|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-04-26 10:45:11


StateEst/Act
TimeTotal
Timeconfirming image exists(22)0:04/0:100:10starting load process(40)0:06/
0:020:12creating configuration file(28)0:02/0:000:12starting virtual
machine(48)0:03/0:010:13running post configuration(9)19:31/0:340:47resource
ready(43)0:00/0:221:09
failed: process failed after trying to load or make available
-- 
Thanks,
Alex  Patterson

Re: Image failing at resource ready

Posted by Andy Kurth <an...@ncsu.edu>.
Hello,
This is occurring when the root account password is randomized when the image is 
loaded.  As part of the password change sequence, the code checks all of the 
scheduled tasks to determine if any are run under the credentials of the account 
whose password is being changed.  It it matches, the password to use when 
running the scheduled task is updated by running schtasks.exe.  The command is 
failing when trying to change the password for the horrifically named scheduled 
task:
User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}

The code probably needs to escape the special characters in the task name.  I 
have created issue VCL-331 to look at this:
https://issues.apache.org/jira/browse/VCL-331

 From what I can tell from Google, this task is normally associated with the IE 
RSS feed synchronization features.  I don't think it's related to CS4.  It will 
be best to simply remove this scheduled task from the image since it's running 
as root.  You will need to create a new revision of your image.  You don't need 
to recreate your image from scratch, but you will need to get an imaging 
reservation to the point where you can login.  There are a few ways to do this 
but the easiest will be to alter the code to comment out the line which is 
causing the reservation to fail:

-Edit /usr/local/vcl/lib/VCL/Module/OS/Windows.pm
-Find lines 1698 and 1699:
1698: notify($ERRORS{'WARNING'}, 0, "failed to change password for scheduled 
task: $task_name_to_update, exit status: $schtasks_change_exit_status, 
output:\n@{$schtasks_change_output}");
1699: return 0;
-Comment out line 1699: "return 0;"
-Restart vcld: /sbin/service vcld restart
-Make an imaging reservation for your CS4 image
-The image should load

Remove the User_Feed_Synchronization scheduled task:
-Open Control Panel -> Scheduled tasks
-Click Advanced -> View Hidden Tasks
-Delete the scheduled task
-Create a new revision

Hope this helps,
Andy

Alexander Patterson wrote:
> Hello,
> 
> I am getting an error one one of my new Images that was built in Vmware
> Server.
> I had to built it in Vmware Server due to it's Size.
> 
> 19.1 GB
> 
> The Software is Adobe Creative Suite 4 Web Premium, It's Windows XP SP3
> Firewall is off
> SingleCore Image, i have built my other 30 that work the same way. This one
> is not working.
> 
> I can SSH into the image. It works just fine when I load in in  vmware
> server. When I try to load it into the system. I always get stuck at
> resource ready.
> 
> resource ready(43)0:00/0:221:09
> failed: process failed after trying to load or make available
> 
> It doesn't matter what Vmware guest it uses, all of them fail at the same
> point.
> 
> Here is the Log
> 
> 
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 'C:/Windows/System32/reg.exe add
> "HKCR\CLSID\{20D04FE0-3AEA-1069-A2D8-08002B30309D}" /v LocalizedString /t
> REG_EXPAND_SZ /d "Adobe Creative Suite 4 Web Premium" /f' 2>&1
> 2010-04-26
> 10:44:18|19812|2127:2121|new|Windows.pm:set_my_computer_name(3847)|my
> computer name changed to 'Adobe Creative Suite 4 Web Premium'
> 2010-04-26
> 10:44:18|19812|2127:2121|new|Windows.pm:set_password(1640)|setting password
> of root to Si2GJL on vmguest-25
> 2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-25:
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 'net user root 'Si2GJL'' 2>&1
> 2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
> output:
> |19812|2127:2121|new| The command completed successfully.
> 2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6276)|SSH
> command executed on vmguest-25, returning (0, "The command completed
> successf...")
> 2010-04-26
> 10:44:18|19812|2127:2121|new|Windows.pm:set_password(1642)|password changed
> to 'Si2GJL' for user 'root' on vmguest-25
> 2010-04-26 10:44:18|19812|2127:2121|new|Windows.pm:set_password(1656)|root
> account password changed, must also change sshd service credentials
> 2010-04-26 10:44:18|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-25:
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 '$SYSTEMROOT/System32/sc.exe config sshd obj= ".\root" password=
> "Si2GJL"' 2>&1
> 2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
> output:
> |19812|2127:2121|new| [SC] ChangeServiceConfig SUCCESS
> 2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6276)|SSH
> command executed on vmguest-25, returning (0, "[SC] ChangeServiceConfig
> SUCCE...")
> 2010-04-26
> 10:44:19|19812|2127:2121|new|Windows.pm:set_service_credentials(3340)|changed
> logon credentials for 'sshd' service to root (Si2GJL) on vmguest-25
> 2010-04-26
> 10:44:19|19812|2127:2121|new|Windows.pm:set_password(1664)|changing
> passwords for scheduled tasks
> 2010-04-26 10:44:19|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-25:
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 'schtasks.exe /Query /V /FO LIST' 2>&1
> 2010-04-26 10:44:19|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:19
> 2010-04-26
> 10:44:20|19812|2127:2121|new|Windows.pm:set_password(1666)|queried scheduled
> tasks on vmguest-25
> 2010-04-26
> 10:44:20|19812|2127:2121|new|Windows.pm:set_password(1686)|password needs to
> be updated for scheduled task:
> User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}
> |19812|2127:2121|new| Run As User: CSUVCLXP\root
> 2010-04-26
> 10:44:20|19812|2127:2121|new|Windows.pm:set_password(1686)|password needs to
> be updated for scheduled task:
> User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}
> |19812|2127:2121|new| Run As User: CSUVCLXP\root
> 2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-25:
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 'schtasks.exe /Change /RP "Si2GJL" /TN
> "User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}"' 2>&1
> 2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6262)|run_ssh_command
> output:
> |19812|2127:2121|new| ERROR: Unable to establish existence of the account
> specified.
> 2010-04-26 10:44:20|19812|2127:2121|new|utils.pm:run_ssh_command(6272)|SSH
> command executed on vmguest-25, command:
> |19812|2127:2121|new| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-25 'schtasks.exe /Change /RP "Si2GJL" /TN
> "User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}"' 2>&1
> |19812|2127:2121|new| returning (1, "ERROR: Unable to establish exi...")
> 
> |19812|2127:2121|new| ---- WARNING ----
> |19812|2127:2121|new| 2010-04-26
> 10:44:20|19812|2127:2121|new|Windows.pm:set_password(1698)|failed to change
> password for scheduled task:
> User_Feed_Synchronization-{166B89A0-2CB2-4FF1-9D77-F86D0023D535}, exit
> status: 1, output:
> |19812|2127:2121|new| ERROR: Unable to establish existence of the account
> specified.
> |19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
> |19812|2127:2121|new| (-1) Windows.pm, set_password (line: 1698)
> |19812|2127:2121|new| (-2) Windows.pm, post_load (line: 558)
> |19812|2127:2121|new| (-3) new.pm, reload_image (line: 692)
> |19812|2127:2121|new| (-4) new.pm, process (line: 266)
> |19812|2127:2121|new| (-5) vcld, make_new_child (line: 594)
> |19812|2127:2121|new| (-6) vcld, main (line: 341)
> 
> 
> |19812|2127:2121|new| ---- WARNING ----
> |19812|2127:2121|new| 2010-04-26
> 10:44:20|19812|2127:2121|new|Windows.pm:post_load(559)|failed to set random
> root password
> |19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
> |19812|2127:2121|new| (-1) Windows.pm, post_load (line: 559)
> |19812|2127:2121|new| (-2) new.pm, reload_image (line: 692)
> |19812|2127:2121|new| (-3) new.pm, process (line: 266)
> |19812|2127:2121|new| (-4) vcld, make_new_child (line: 594)
> |19812|2127:2121|new| (-5) vcld, main (line: 341)
> 
> No recipient addresses found in header
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:mail(1348)|SUCCESS --
> Sending mail To: , PROBLEM -- new.pm
> 
> |19812|2127:2121|new| ---- CRITICAL ----
> |19812|2127:2121|new| 2010-04-26
> 10:44:20|19812|2127:2121|new|new.pm:reload_image(697)|failed
> to perform OS post-load tasks for vmwarewinxp-AdobeCS4-v0 on vmguest-25,
> returning
> |19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
> |19812|2127:2121|new| (-1) new.pm, reload_image (line: 697)
> |19812|2127:2121|new| (-2) new.pm, process (line: 266)
> |19812|2127:2121|new| (-3) vcld, make_new_child (line: 594)
> |19812|2127:2121|new| (-4) vcld, main (line: 341)
> 
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:insertloadlog(4710)|inserted
> computer=29, loadimagefailed, failed to perform OS post-load tasks for
> vmwarewinxp-AdobeCS4-v0 on vmguest-25
> 
> |19812|2127:2121|new| ---- WARNING ----
> |19812|2127:2121|new| 2010-04-26
> 10:44:21|19812|2127:2121|new|new.pm:process(313)|failed
> to load vmguest-25 with vmwarewinxp-AdobeCS4-v0
> |19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
> |19812|2127:2121|new| (-1) new.pm, process (line: 313)
> |19812|2127:2121|new| (-2) vcld, make_new_child (line: 594)
> |19812|2127:2121|new| (-3) vcld, main (line: 341)
> 
> 2010-04-26
> 10:44:21|19812|2127:2121|new|DataStructure.pm:get_computer_state_name(1946)|attempting
> to retrieve current state of computer vmguest-25 from the database
> 2010-04-26
> 10:44:21|19812|2127:2121|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
> current state of computer vmguest-25 from the database: reloading
> 2010-04-26
> 10:44:21|19812|2127:2121|new|DataStructure.pm:_automethod(697)|data
> structure updated:
> $self->request_data->{reservation}{2121}{computer}{state}{name}
> |19812|2127:2121|new| computer_state_name = reloading
> No recipient addresses found in header
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:mail(1348)|SUCCESS --
> Sending mail To: , PROBLEM -- State.pm
> 
> |19812|2127:2121|new| ---- CRITICAL ----
> |19812|2127:2121|new| 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(290)|reservation
> failed on vmguest-25: process failed after trying to load or make available
> |19812|2127:2121|new| ( 0) utils.pm, notify (line: 737)
> |19812|2127:2121|new| (-1) State.pm, reservation_failed (line: 290)
> |19812|2127:2121|new| (-2) new.pm, process (line: 316)
> |19812|2127:2121|new| (-3) vcld, make_new_child (line: 594)
> |19812|2127:2121|new| (-4) vcld, main (line: 341)
> 
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:insertloadlog(4710)|inserted
> computer=29, failed, process failed after trying to load or make available
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(293)|inserted
> computerloadlog entry
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(301)|updated log
> ending value to 'failed', logid=1486
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:update_computer_state(2228)|computer
> 29 state updated to: failed
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(312)|computer
> vmguest-25 (29) state set to failed
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:update_request_state(2186)|request
> 2127 state updated to: failed, laststate to: new
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(325)|set
> request state to 'failed'/'new'
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:is_inblockrequest(6976)|1
> rows were returned from database select
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(334)|vmguest-25 in
> blockcomputers table
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(335)|removed
> vmguest-25 from blockcomputers table
> 2010-04-26
> 10:44:21|19812|2127:2121|new|State.pm:reservation_failed(346)|exiting 1
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(905)|destructor
> called, ref($self)=VCL::new
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:delete_computerloadlog_reservation(7551)|removing
> computerloadlog entries matching loadstate = begin
> 2010-04-26 10:44:21|19812|2127:2121|new|utils.pm:delete_computerloadlog_reservation(7598)|deleted
> rows from computerloadlog for reservation id=2121
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(912)|removed
> computerloadlog rows with loadstate=begin for reservation
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(924)|number of
> database handles state process created: 1
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(933)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(935)|$ENV{dbh}:
> database disconnect successful
> 2010-04-26 10:44:21|19812|2127:2121|new|State.pm:DESTROY(949)|VCL::new
> process 19812 exiting
> 2010-04-26 10:44:21|8190|vcld:REAPER(744)|VCL process exited for reservation
> 2121
> 2010-04-26 10:44:21|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:21
> 2010-04-26 10:44:26|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:26
> 2010-04-26 10:44:27|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
> for connection by ak565463 on vmguest-37, attempt 10
> 2010-04-26 10:44:27|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-37:
> |19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-37 'netstat -an' 2>&1
> 2010-04-26 10:44:31|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:31
> 2010-04-26 10:44:36|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:36
> 2010-04-26 10:44:41|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:41
> 2010-04-26 10:44:46|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:46
> 2010-04-26 10:44:47|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
> for connection by ak565463 on vmguest-37, attempt 11
> 2010-04-26 10:44:47|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-37:
> |19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-37 'netstat -an' 2>&1
> 2010-04-26 10:44:51|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:51
> 2010-04-26 10:44:56|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:44:56
> 2010-04-26 10:45:01|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:45:01
> 2010-04-26 10:45:06|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:45:06
> 2010-04-26 10:45:08|19656|2126:2120|inuse|utils.pm:check_connection(1765)|checking
> for connection by ak565463 on vmguest-37, attempt 12
> 2010-04-26 10:45:08|19656|2126:2120|inuse|utils.pm:run_ssh_command(6180)|executing
> SSH command on vmguest-37:
> |19656|2126:2120|inuse| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
> vmguest-37 'netstat -an' 2>&1
> 2010-04-26 10:45:11|8190|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-04-26 10:45:11
> 
> 
> StateEst/Act
> TimeTotal
> Timeconfirming image exists(22)0:04/0:100:10starting load process(40)0:06/
> 0:020:12creating configuration file(28)0:02/0:000:12starting virtual
> machine(48)0:03/0:010:13running post configuration(9)19:31/0:340:47resource
> ready(43)0:00/0:221:09
> failed: process failed after trying to load or make available

-- 
Andy Kurth
Virtual Computing Lab
Office of Information Technology
North Carolina State University
andy_kurth@ncsu.edu
919.513.4090