The snippets for before and after the reboot via console look the same so I pasted the 2nd set of message instead of the first. Sorry about that. I did discover that the /var/lib/dhclient/dhclient.leases existed but was empty. I've run across an issue with CentOS 7 where the lease file is missing so I wrote a "cloud-dhcp-check" service that makes sure it exists but now I need to validate its content. That being said, I have insured that the dhclient_leases was valid and replicated the problem.
The cloud-set-guest-xxxx scripts are from the master branch GitHub repository for apaches/cloudstack using the "https://github.com/apache/cloudstack/blob/master/setup/bindir/cloud-set-guest-password.in"; and the "https://github.com/apache/cloudstack/blob/master/setup/bindir/cloud-set-guest-sshkey.in"; links. I have attached the entire log from the VR but have some snippets below along with the VM client logs and the issue still occurs after fixing the dhcp lease file. I did not perform any password resets via the GUI during this process. == Logs from local link on the corresponding VR for April 5th only (time is UTC) == grep "CsHelper.*10\.1\.1\.39" /var/log/cloud.log 2016-04-05 18:32:41,103 CsHelper.py execute:160 Executing: curl --header "DomU_Request: save_password" "http://10.1.1.1:8080/"; -F "ip=10.1.1.39" -F "password=a8Q7Bs" -F "token=ae199529efcd26f7811f36ae7c0807b1" >/dev/null 2>/dev/null & 2016-04-05 18:32:44,806 CsHelper.py execute:160 Executing: curl --header "DomU_Request: save_password" "http://10.1.1.1:8080/"; -F "ip=10.1.1.39" -F "password=a8Q7Bs" -F "token=ae199529efcd26f7811f36ae7c0807b1" >/dev/null 2>/dev/null & 2016-04-05 18:38:21,043 CsHelper.py execute:160 Executing: curl --header "DomU_Request: save_password" "http://10.1.1.1:8080/"; -F "ip=10.1.1.39" -F "password=a8Q7Bs" -F "token=ae199529efcd26f7811f36ae7c0807b1" >/dev/null 2>/dev/null & 2016-04-05 18:38:24,454 CsHelper.py execute:160 Executing: curl --header "DomU_Request: save_password" "http://10.1.1.1:8080/"; -F "ip=10.1.1.39" -F "password=a8Q7Bs" -F "token=ae199529efcd26f7811f36ae7c0807b1" >/dev/null 2>/dev/null & == Logs from the VM client using "grep cloud /var/log/messages" (time is CDT) == -- Power off via GUI -- Apr 5 13:29:57 rsi-test-c7 systemd: Stopped Execute cloud user/final scripts. Apr 5 13:29:57 rsi-test-c7 systemd: Stopping Execute cloud user/final scripts... Apr 5 13:29:57 rsi-test-c7 systemd: Stopped Apply the settings specified in cloud-config. Apr 5 13:29:57 rsi-test-c7 systemd: Stopping Apply the settings specified in cloud-config... -- Powered on via GUI -- Apr 5 13:33:07 rsi-test-c7 systemd: Starting Initial cloud-init job (pre-networking)... Apr 5 13:33:09 rsi-test-c7 systemd: Started Initial cloud-init job (pre-networking). Apr 5 13:33:11 rsi-test-c7 NetworkManager[539]: <info> domain name 'cs2cloud.internal' Apr 5 13:33:17 rsi-test-c7 systemd: Starting LSB: cloud-dhcp-check... Apr 5 13:33:17 rsi-test-c7 cloud-dhcp-check: Checking for DHCP leas file... Apr 5 13:33:17 rsi-test-c7 cloud-dhcp-check: DHCP lease found: /var/lib/dhclient/dhclient.leases Apr 5 13:33:17 rsi-test-c7 systemd: Started LSB: cloud-dhcp-check. Apr 5 13:33:17 rsi-test-c7 systemd: Starting LSB: cloud-set-guest-password... Apr 5 13:33:17 rsi-test-c7 systemd: Starting LSB: cloud-set-guest-sshkey... Apr 5 13:33:17 rsi-test-c7 cloud: Found ssh key server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: Found password server IP 10.1.1.1 in /var/lib/dhclient/dhclient.leases Apr 5 13:33:17 rsi-test-c7 cloud: Sending request to password server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: Sending request to ssh key server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: Got response from server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: Did not receive any keys from any server Apr 5 13:33:17 rsi-test-c7 systemd: cloud-set-guest-sshkey.service: control process exited, code=exited status=1 Apr 5 13:33:17 rsi-test-c7 systemd: Failed to start LSB: cloud-set-guest-sshkey. Apr 5 13:33:17 rsi-test-c7 systemd: Unit cloud-set-guest-sshkey.service entered failed state. Apr 5 13:33:17 rsi-test-c7 systemd: cloud-set-guest-sshkey.service failed. Apr 5 13:33:17 rsi-test-c7 cloud: Got response from server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: VM got a valid password from server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 cloud: Changing password for user root Apr 5 13:33:17 rsi-test-c7 cloud: Sending acknowledgment to password server at 10.1.1.1 Apr 5 13:33:17 rsi-test-c7 systemd: Started LSB: cloud-set-guest-password. Apr 5 13:33:17 rsi-test-c7 cloud-set-guest-password: saved_password Apr 5 13:33:17 rsi-test-c7 systemd: Starting Initial cloud-init job (metadata service crawler)... Apr 5 13:33:18 rsi-test-c7 systemd: Started Initial cloud-init job (metadata service crawler). Apr 5 13:33:18 rsi-test-c7 systemd: Starting Apply the settings specified in cloud-config... Apr 5 13:33:19 rsi-test-c7 systemd: Started Apply the settings specified in cloud-config. Apr 5 13:33:19 rsi-test-c7 systemd: Starting Execute cloud user/final scripts... Apr 5 13:33:19 rsi-test-c7 systemd: Started Execute cloud user/final scripts. -- Changed root password via VM console then powered off via GUI -- Apr 5 13:37:10 rsi-test-c7 systemd: Stopped Execute cloud user/final scripts. Apr 5 13:37:10 rsi-test-c7 systemd: Stopping Execute cloud user/final scripts... Apr 5 13:37:10 rsi-test-c7 systemd: Stopped Apply the settings specified in cloud-config. Apr 5 13:37:10 rsi-test-c7 systemd: Stopping Apply the settings specified in cloud-config... -- Powered on via GUI -- Apr 5 13:38:47 rsi-test-c7 systemd: Starting Initial cloud-init job (pre-networking)... Apr 5 13:38:49 rsi-test-c7 systemd: Started Initial cloud-init job (pre-networking). Apr 5 13:38:51 rsi-test-c7 NetworkManager[535]: <info> domain name 'cs2cloud.internal' Apr 5 13:38:56 rsi-test-c7 systemd: Starting LSB: cloud-dhcp-check... Apr 5 13:38:56 rsi-test-c7 cloud-dhcp-check: Checking for DHCP leas file... Apr 5 13:38:57 rsi-test-c7 cloud-dhcp-check: DHCP lease found: /var/lib/dhclient/dhclient.leases Apr 5 13:38:57 rsi-test-c7 systemd: Started LSB: cloud-dhcp-check. Apr 5 13:38:57 rsi-test-c7 systemd: Starting LSB: cloud-set-guest-sshkey... Apr 5 13:38:57 rsi-test-c7 systemd: Starting LSB: cloud-set-guest-password... Apr 5 13:38:57 rsi-test-c7 cloud: Found ssh key server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: Found password server IP 10.1.1.1 in /var/lib/dhclient/dhclient.leases Apr 5 13:38:57 rsi-test-c7 cloud: Sending request to ssh key server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: Sending request to password server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: Got response from server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: Did not receive any keys from any server Apr 5 13:38:57 rsi-test-c7 systemd: cloud-set-guest-sshkey.service: control process exited, code=exited status=1 Apr 5 13:38:57 rsi-test-c7 systemd: Failed to start LSB: cloud-set-guest-sshkey. Apr 5 13:38:57 rsi-test-c7 systemd: Unit cloud-set-guest-sshkey.service entered failed state. Apr 5 13:38:57 rsi-test-c7 systemd: cloud-set-guest-sshkey.service failed. Apr 5 13:38:57 rsi-test-c7 cloud: Got response from server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: VM got a valid password from server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud: Changing password for user root Apr 5 13:38:57 rsi-test-c7 cloud: Sending acknowledgment to password server at 10.1.1.1 Apr 5 13:38:57 rsi-test-c7 cloud-set-guest-password: saved_password Apr 5 13:38:57 rsi-test-c7 systemd: Started LSB: cloud-set-guest-password. Apr 5 13:38:57 rsi-test-c7 systemd: Starting Initial cloud-init job (metadata service crawler)... Apr 5 13:38:58 rsi-test-c7 systemd: Started Initial cloud-init job (metadata service crawler). Apr 5 13:38:58 rsi-test-c7 systemd: Starting Apply the settings specified in cloud-config... Apr 5 13:38:58 rsi-test-c7 systemd: Started Apply the settings specified in cloud-config. Apr 5 13:38:58 rsi-test-c7 systemd: Starting Execute cloud user/final scripts... Apr 5 13:38:59 rsi-test-c7 systemd: Started Execute cloud user/final scripts. Let me know if I've missed something or you need further info. Richard Klein <rkl...@rsitex.com> RSI 5426 Guadalupe, Suite 100 Austin TX 78751 > -----Original Message----- > From: Erik Weber [mailto:terbol...@gmail.com] > Sent: Tuesday, April 05, 2016 12:30 AM > To: users@cloudstack.apache.org > Subject: Re: Cloudstack 4.7 password reset issue. > > On Mon, Apr 4, 2016 at 9:17 PM, Richard Klein (RSI) <rkl...@rsitex.com> > wrote: > > > Thanks for the reply and sorry for the delay. You know how it is on > > Monday's. > > > > I checked the VR password file as suggested after the password reset > > via the GUI but before powering on the VM. I did see the password > > reset there as expected. I powered on the VM and the password was reset as > expected. > > The test VM is built from a CentOS7 template with password enabled. I > > checked the /var/log/messages and you can see from the client > > perspective the change went as expected. Below is "snippet1" from the > > message log on the VM (there are no SSH key so it fails as expected): > > > > > This is your first VM snippet: > > > > Apr 4 13:45:35 rsi-test-c7 systemd: Starting LSB: > > cloud-set-guest-sshkey... > > Apr 4 13:45:35 rsi-test-c7 systemd: Starting LSB: > > cloud-set-guest-password... > > Apr 4 13:45:35 rsi-test-c7 cloud: Unable to determine the password > > server, falling back to data-server Apr 4 13:45:35 rsi-test-c7 cloud: > > Could not find ssh key server IP in /var/lib/dhclient/dhclient.leases > > Apr 4 13:45:36 rsi-test-c7 cloud: Unable to determine the password > > server, falling back to data-server Apr 4 13:45:36 rsi-test-c7 cloud: > > Sending request to password server at data-server Apr 4 13:45:36 > > rsi-test-c7 cloud: Sending request to ssh key server at data-server > > Apr 4 13:45:36 rsi-test-c7 cloud: Got response from server at > > data-server Apr 4 13:45:36 rsi-test-c7 cloud: Did not receive any > > keys from any server Apr 4 13:45:36 rsi-test-c7 systemd: cloud-set-guest- > sshkey.service: > > control process exited, code=exited status=1 Apr 4 13:45:36 > > rsi-test-c7 systemd: Failed to start LSB: > > cloud-set-guest-sshkey. > > Apr 4 13:45:36 rsi-test-c7 systemd: Unit > > cloud-set-guest-sshkey.service entered failed state. > > Apr 4 13:45:36 rsi-test-c7 systemd: cloud-set-guest-sshkey.service failed. > > Apr 4 13:45:36 rsi-test-c7 cloud: Got response from server at > > data-server Apr 4 13:45:36 rsi-test-c7 cloud: VM got a valid password > > from server at data-server Apr 4 13:45:36 rsi-test-c7 cloud: Changing > > password for user root Apr 4 13:45:36 rsi-test-c7 cloud: Sending > > acknowledgment to password server at data-server Apr 4 13:45:36 > > rsi-test-c7 cloud-set-guest-password: saved_password Apr 4 13:45:36 > > rsi-test-c7 systemd: Started LSB: cloud-set-guest-password. > > Apr 4 13:45:36 rsi-test-c7 systemd: Starting Initial cloud-init job > > (metadata service crawler)... > > Apr 4 13:45:37 rsi-test-c7 systemd: Started Initial cloud-init job > > (metadata service crawler). > > Apr 4 13:45:37 rsi-test-c7 systemd: Starting Apply the settings > > specified in cloud-config... > > Apr 4 13:45:37 rsi-test-c7 systemd: Started Apply the settings > > specified in cloud-config. > > Apr 4 13:45:37 rsi-test-c7 systemd: Starting Execute cloud user/final > > scripts... > > Apr 4 13:45:37 rsi-test-c7 systemd: Started Execute cloud user/final > > scripts. > > > > I checked the password file on the VR and it was empty now. I then > > manually reset the password on the VM console only (not CS GUI) and > > performed an OS reboot from the console. I could log in with the > > password I change with the console. Below is the system messages > "snippet2": > > > > > This is your second VM snippet, happening before snippet1 > > > > Apr 4 13:36:27 rsi-test-c7 systemd: Starting LSB: > > cloud-set-guest-sshkey... > > Apr 4 13:36:27 rsi-test-c7 systemd: Starting LSB: > > cloud-set-guest-password... > > Apr 4 13:36:27 rsi-test-c7 cloud: Could not find ssh key server IP in > > /var/lib/dhclient/dhclient.leases > > > > Do you have such file, or is there a configuration error in the > cloud-set-guest- > password? > You seem to be running centos7, and that wasn't around when these scripts > where made and thus might have to be modified for them to work. > > > > Apr 4 13:36:27 rsi-test-c7 cloud: Unable to determine the password > > server, falling back to data-server Apr 4 13:36:27 rsi-test-c7 cloud: > > Unable to determine the password server, falling back to data-server > > Apr 4 13:36:27 rsi-test-c7 cloud: Sending request to password server > > at data-server Apr 4 13:36:27 rsi-test-c7 cloud: Sending request to > > ssh key server at data-server Apr 4 13:36:27 rsi-test-c7 cloud: Got > > response from server at data-server Apr 4 13:36:27 rsi-test-c7 cloud: > > Did not receive any keys from any server Apr 4 13:36:27 rsi-test-c7 > > systemd: cloud-set-guest-sshkey.service: > > control process exited, code=exited status=1 Apr 4 13:36:27 > > rsi-test-c7 systemd: Failed to start LSB: > > cloud-set-guest-sshkey. > > Apr 4 13:36:27 rsi-test-c7 systemd: Unit > > cloud-set-guest-sshkey.service entered failed state. > > Apr 4 13:36:27 rsi-test-c7 systemd: cloud-set-guest-sshkey.service failed. > > Apr 4 13:36:27 rsi-test-c7 cloud: Got response from server at > > data-server Apr 4 13:36:27 rsi-test-c7 cloud: VM has already saved a > > password from the password server at data-server Apr 4 13:36:27 > > rsi-test-c7 cloud: Did not need to change password. > > Apr 4 13:36:27 rsi-test-c7 systemd: Started LSB: cloud-set-guest-password. > > > > I then powered off the VM and powered it back on without changing any > > passwords. The password was set to the last change password via the GUI. > > The logs behave as if the password reset was performed from the GUI > > again (snippet1). I checked the password file on the VR and it was > > empty. I also monitored the VR /var/log/cloud.log messages and > > discovered something interesting. As expected there was a flurry of > > activity but the following > > 2 messages stood out to me: > > > > > This is your VR snippet. > > > > 2016-04-04 18:45:06,937 merge.py save:72 {u'id': u'dhcpentry', > > u'10.1.1.39': {u'default_gateway': u'10.1.1.1', u'ipv6_duid': u'00:03:00:01: > > 02:00:26:c0:00:07', u'default_entry': True, u'ipv4_adress': > > u'10.1.1.39', > > u'host_name': u'rsi-test-c7', u'mac_address': u'02:00:26:c0:00:07' > > , u'type': u'dhcpentry', u'dns_adresses': u'10.1.1.1'}} > > > > 2016-04-04 18:45:07,006 CsHelper.py execute:160 Executing: curl > > --header > > "DomU_Request: save_password" "http://10.1.1.1:8080/"; -F "ip=10.1.1.39" > > -F "password=a8Q7Bs" -F "token=ae199529efcd26f7811f36ae7c0807b1" > > >/dev/null > > 2>/dev/null & > > > > > I am assuming you have a timezone difference between the VR and your VMs, > but could you confirm that the VR time of 18:45 is 13:45 your time? > > But if so, the VR snippet you pasted is happening BEFORE the first VM snippet > and looks correct. > > It would be helpful if you also could attach the logs for the duration of the > first > VM snippet. > Also, could you point us to the source of the cloud-set-guest-* scripts you > used, > preferably with any modifications? > > > -- > Erik
