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:\...@{$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_ku...@ncsu.edu
919.513.4090
