[Engine-devel] Add Host(Bootstrap) fails with tar:timestamp in future error

Hi All, I am facing the following issue when adding a f18 node to 3.3-master engine(nightly). I have an engine with proper time set, but my f18 node has an old time(01-01-2013) set. Then i tried adding the node to engine, but it failed with following error in the engine.log. But no error is seen in host-deploy log file. 2013-07-11 12:31:28,193 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Pre-termination. 2013-07-11 12:31:28,229 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log' 2013-07-11 12:31:28,237 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log'. 2013-07-11 12:31:28,553 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Stage: Termination 2013-07-11 12:31:28,562 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Termination. 2013-07-11 12:31:28,634 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH stderr during command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': stderr: tar: ./otopi: time stamp 2013-07-04 14:21:43 is 15945691.410852852 s in the future tar: ./ovirt-host-deploy: time stamp 2013-07-10 04:55:38 is 16430126.410376831 s in the future tar: ./pythonlib/otopi/miniyum.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410119301 s in the future tar: ./pythonlib/otopi/__main__.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410010001 s in the future tar: ./pythonlib/otopi/dialog.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409909584 s in the future tar: ./pythonlib/otopi/packager.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409809844 s in the future tar: ./pythonlib/otopi/packager.py: time stamp 2013-07-04 14:21:44 is 15945692.409518324 s in the future tar: ./pythonlib/otopi/common.pyo: time stamp 2013-07-04 14:21:45 is 15945693.40935584 s in the future tar: ./pythonlib/otopi/transaction.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409253666 s in the future tar: ./pythonlib/otopi/miniyum.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409127283 s in the future tar: ./pythonlib/otopi/plugin.py: time stamp 2013-07-04 14:21:44 is 15945692.409022969 s in the future 2013-07-11 12:31:28,641 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH error running command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': java.io.IOException: Error messages during execution at org.ovirt.engine.core.utils.ssh.SSHDialog.executeCommand(SSHDialog.java:318) [utils.jar:] After the failure, i tried doing a re-install, that went through fine without any issue and the host came up after the installation. Looks like the first time bootstrapping reset the time. Also i can see the node's time is changed to current time. Thanks, Kanagaraj

On 07/12/2013 05:07 PM, Kanagaraj wrote:
Hi All,
I am facing the following issue when adding a f18 node to 3.3-master engine(nightly).
Also the node have recent vdsm built from master branch. Can someone please help in this regard?
I have an engine with proper time set, but my f18 node has an old time(01-01-2013) set. Then i tried adding the node to engine, but it failed with following error in the engine.log. But no error is seen in host-deploy log file.
2013-07-11 12:31:28,193 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Pre-termination. 2013-07-11 12:31:28,229 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log' 2013-07-11 12:31:28,237 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log'. 2013-07-11 12:31:28,553 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Stage: Termination 2013-07-11 12:31:28,562 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Termination. 2013-07-11 12:31:28,634 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH stderr during command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': stderr: tar: ./otopi: time stamp 2013-07-04 14:21:43 is 15945691.410852852 s in the future tar: ./ovirt-host-deploy: time stamp 2013-07-10 04:55:38 is 16430126.410376831 s in the future tar: ./pythonlib/otopi/miniyum.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410119301 s in the future tar: ./pythonlib/otopi/__main__.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410010001 s in the future tar: ./pythonlib/otopi/dialog.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409909584 s in the future tar: ./pythonlib/otopi/packager.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409809844 s in the future tar: ./pythonlib/otopi/packager.py: time stamp 2013-07-04 14:21:44 is 15945692.409518324 s in the future tar: ./pythonlib/otopi/common.pyo: time stamp 2013-07-04 14:21:45 is 15945693.40935584 s in the future tar: ./pythonlib/otopi/transaction.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409253666 s in the future tar: ./pythonlib/otopi/miniyum.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409127283 s in the future tar: ./pythonlib/otopi/plugin.py: time stamp 2013-07-04 14:21:44 is 15945692.409022969 s in the future
2013-07-11 12:31:28,641 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH error running command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': java.io.IOException: Error messages during execution at org.ovirt.engine.core.utils.ssh.SSHDialog.executeCommand(SSHDialog.java:318) [utils.jar:]
After the failure, i tried doing a re-install, that went through fine without any issue and the host came up after the installation. Looks like the first time bootstrapping reset the time. Also i can see the node's time is changed to current time.
Thanks, Kanagaraj _______________________________________________ Engine-devel mailing list Engine-devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/engine-devel

the errors from the tar produce this. after 1st bootstrap the clock is sync, so the next one is ok. the following[1] fixes that. [1] http://gerrit.ovirt.org/#/c/16640/ ----- Original Message -----
From: "Kanagaraj" <kmayilsa@redhat.com> To: "engine-devel" <engine-devel@ovirt.org> Sent: Friday, July 12, 2013 2:37:25 PM Subject: [Engine-devel] Add Host(Bootstrap) fails with tar:timestamp in future error
Hi All,
I am facing the following issue when adding a f18 node to 3.3-master engine(nightly).
I have an engine with proper time set, but my f18 node has an old time(01-01-2013) set. Then i tried adding the node to engine, but it failed with following error in the engine.log. But no error is seen in host-deploy log file.
2013-07-11 12:31:28,193 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Pre-termination. 2013-07-11 12:31:28,229 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log' 2013-07-11 12:31:28,237 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log'. 2013-07-11 12:31:28,553 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Stage: Termination 2013-07-11 12:31:28,562 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Termination. 2013-07-11 12:31:28,634 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH stderr during command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': stderr: tar: ./otopi: time stamp 2013-07-04 14:21:43 is 15945691.410852852 s in the future tar: ./ovirt-host-deploy: time stamp 2013-07-10 04:55:38 is 16430126.410376831 s in the future tar: ./pythonlib/otopi/miniyum.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410119301 s in the future tar: ./pythonlib/otopi/__main__.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410010001 s in the future tar: ./pythonlib/otopi/dialog.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409909584 s in the future tar: ./pythonlib/otopi/packager.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409809844 s in the future tar: ./pythonlib/otopi/packager.py: time stamp 2013-07-04 14:21:44 is 15945692.409518324 s in the future tar: ./pythonlib/otopi/common.pyo: time stamp 2013-07-04 14:21:45 is 15945693.40935584 s in the future tar: ./pythonlib/otopi/transaction.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409253666 s in the future tar: ./pythonlib/otopi/miniyum.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409127283 s in the future tar: ./pythonlib/otopi/plugin.py: time stamp 2013-07-04 14:21:44 is 15945692.409022969 s in the future
2013-07-11 12:31:28,641 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH error running command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': java.io.IOException: Error messages during execution at org.ovirt.engine.core.utils.ssh.SSHDialog.executeCommand(SSHDialog.java:318) [utils.jar:]
After the failure, i tried doing a re-install, that went through fine without any issue and the host came up after the installation. Looks like the first time bootstrapping reset the time. Also i can see the node's time is changed to current time.
Thanks, Kanagaraj _______________________________________________ Engine-devel mailing list Engine-devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/engine-devel

Thanks Alon, it fixes the issue. On 07/12/2013 05:12 PM, Alon Bar-Lev wrote:
the errors from the tar produce this. after 1st bootstrap the clock is sync, so the next one is ok. the following[1] fixes that.
[1] http://gerrit.ovirt.org/#/c/16640/
----- Original Message -----
From: "Kanagaraj" <kmayilsa@redhat.com> To: "engine-devel" <engine-devel@ovirt.org> Sent: Friday, July 12, 2013 2:37:25 PM Subject: [Engine-devel] Add Host(Bootstrap) fails with tar:timestamp in future error
Hi All,
I am facing the following issue when adding a f18 node to 3.3-master engine(nightly).
I have an engine with proper time set, but my f18 node has an old time(01-01-2013) set. Then i tried adding the node to engine, but it failed with following error in the engine.log. But no error is seen in host-deploy log file.
2013-07-11 12:31:28,193 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Pre-termination. 2013-07-11 12:31:28,229 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log' 2013-07-11 12:31:28,237 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-20130711123128-10.70.43.127-62f72352.log'. 2013-07-11 12:31:28,553 INFO [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation 10.70.43.127: Stage: Termination 2013-07-11 12:31:28,562 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) Correlation ID: 62f72352, Call Stack: null, Custom Event ID: -1, Message: Installing Host server1. Stage: Termination. 2013-07-11 12:31:28,634 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH stderr during command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': stderr: tar: ./otopi: time stamp 2013-07-04 14:21:43 is 15945691.410852852 s in the future tar: ./ovirt-host-deploy: time stamp 2013-07-10 04:55:38 is 16430126.410376831 s in the future tar: ./pythonlib/otopi/miniyum.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410119301 s in the future tar: ./pythonlib/otopi/__main__.pyc: time stamp 2013-07-04 14:21:45 is 15945693.410010001 s in the future tar: ./pythonlib/otopi/dialog.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409909584 s in the future tar: ./pythonlib/otopi/packager.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409809844 s in the future tar: ./pythonlib/otopi/packager.py: time stamp 2013-07-04 14:21:44 is 15945692.409518324 s in the future tar: ./pythonlib/otopi/common.pyo: time stamp 2013-07-04 14:21:45 is 15945693.40935584 s in the future tar: ./pythonlib/otopi/transaction.pyc: time stamp 2013-07-04 14:21:45 is 15945693.409253666 s in the future tar: ./pythonlib/otopi/miniyum.pyo: time stamp 2013-07-04 14:21:45 is 15945693.409127283 s in the future tar: ./pythonlib/otopi/plugin.py: time stamp 2013-07-04 14:21:44 is 15945692.409022969 s in the future
2013-07-11 12:31:28,641 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-6-thread-42) SSH error running command root@10.70.43.127:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && tar -C "${MYTMP}" -x && "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': java.io.IOException: Error messages during execution at org.ovirt.engine.core.utils.ssh.SSHDialog.executeCommand(SSHDialog.java:318) [utils.jar:]
After the failure, i tried doing a re-install, that went through fine without any issue and the host came up after the installation. Looks like the first time bootstrapping reset the time. Also i can see the node's time is changed to current time.
Thanks, Kanagaraj _______________________________________________ Engine-devel mailing list Engine-devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/engine-devel
participants (2)
-
Alon Bar-Lev
-
Kanagaraj