[ovirt-users] java.io.IOException: Command returned failure code 1 during SSH session

Mon Jun 13 14:59:48 UTC 2016

Please share the whole installation log , this vdsDeploy part is new and I
want to get more details on why the connection says it terminated suddenly

The log path is visible in an 'Event' raised in the webadmin after the
installation fails

On Mon, Jun 13, 2016 at 2:59 PM, Phillip Bailey <phbailey at redhat.com> wrote:

> On Mon, Jun 13, 2016 at 4:34 AM, Yedidyah Bar David <didi at redhat.com>
> wrote:
>
>> On Sat, Jun 11, 2016 at 5:56 PM, Gregor Binder <gregor.binder at wefixit.at>
>> wrote:
>> > -----BEGIN PGP SIGNED MESSAGE-----
>> > Hash: SHA256
>> >
>> > Hi,
>> >
>> > during inspecting the engine.log I found this entry:
>> >
>> > - ------------
>> > [org.ovirt.engine.core.uutils.ssh.SSHDialog]
>> > (DefaultQuartzScheduler_Worker-81) [] Exception: java.io.IOException:
>> > Command returned failure code 1 during SSH session 'root@<hostmachine
>> > name remove>'
>> > - ------------
>> > Message: Failed to check for available updates on host host01 with
>> > message 'Command returned failure code 1 during SSH session
>> > 'root@<hostmachine name remove>'
>> > - ------------
>> >
>> > Looks like a serious problem because the engine can't check for updates.
>>
>> You should have some more information in the log. Please check around this
>> line and/or post full log. Thanks.
>>
>> >
>> > cheers
>> > gregor
>> > - --
>> > GPG-Key: 67F1534F
>> > URL:
>> http://pgp.mit.edu:11371/pks/lookup?op=get&search=0x137FB29D67F1534
>> > F
>> > -----BEGIN PGP SIGNATURE-----
>> > Version: GnuPG v2
>> >
>> > iQIcBAEBCAAGBQJXXCaMAAoJEBN/sp1n8VNP1B4QAL1EZRBMe+TFYENj2WH0saTm
>> > GBOZxKljwkno0xdGpql64ZsmPogQ9Ybtus6eEWBuzGScc0uHvsbzVKWrVNf2afAP
>> > XbvWYvdTWECfhSTbQQ0MS/itwkuOfeEONywdo9jcCv+261oEJwQyltjDKK6NDgYl
>> > K4L5Qyvhac0EZsjRpDtKDyHj+QT321hLI5gRps/eMPIAHWl8zaq+LJVFDI4EV3gE
>> > 9Ndcljyxjd6IyqIG4LzQobNowA8Jp+QAIrA316ekkb9BLF7o/W9VaITmS+5xS5Dl
>> > y2lL7Ga/LYdpEkMh8ZQmLwjoTWZvKoL08xFQgnUQ4Ry/UI8ENukmIXecuQebhEHH
>> > Bs4WnaZCDxditHymI809lwf2jpeGVjLkOPuLfev38AIfKS00acm0Yb3TIWNbzs6F
>> > ZJ+rz9X6gtPBET2XOSDPWa/JsCcIbg/XjqEM4qzOANmKzWA4mJpVh7uM6M8mgFd+
>> > 4kZA8hVz4sckat1jbXFXgIJuMvNDwjgKUsDVBoZ1wKJvfj/btfgFaVI/osDnNQ8l
>> > rtnuGCDNhZvJCctxIbLOpC7+raImWLOy89Od1W3KMYg6ECgAM7t5A7VRtTdzSqyt
>> > pji7NaXsZxNqCh2QCXa8srjUQgWttpkRsH/iR3xq/s7QdS+Moail5AoF8XeCzFvB
>> > GX+DLN8RPMcIilUXuaUs
>> > =OnF7
>> > -----END PGP SIGNATURE-----
>> > _______________________________________________
>> > Users mailing list
>> > Users at ovirt.org
>> > http://lists.ovirt.org/mailman/listinfo/users
>>
>> Didi,
>
> I've been having the same problem since the end of last week. I get the
> error whenever I try to add a new host or run reinstall on one that failed
> to install correctly. The relevant part of my log file is below. It covers
> everything from the point that I start the action that causes the error to
> the end of the log file. Also, I have SSH'd to the host to make sure that
> there's nothing wrong with the connectivity and everything there works as
> expected. Any help you can provide would be greatly appreciated.
>
> 2016-06-13 07:52:56,816 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.InstallVdsCommand] (default task-81)
> [1a1eab5e] Running command: InstallVdsCommand internal: false. Entities
> affected :  ID: 244264be-4156-45a1-aed5-d05681303c07 Type: VDSAction group
> EDIT_HOST_CONFIGURATION with role type ADMIN
> 2016-06-13 07:52:56,862 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand] (default
> task-81) [1a1eab5e] Lock Acquired to object
> 'EngineLock:{exclusiveLocks='[244264be-4156-45a1-aed5-d05681303c07=<VDS,
> ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
> 2016-06-13 07:52:56,868 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Running command:
> InstallVdsInternalCommand internal: true. Entities affected :  ID:
> 244264be-4156-45a1-aed5-d05681303c07 Type: VDS
> 2016-06-13 07:52:56,887 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Before Installation host
> 244264be-4156-45a1-aed5-d05681303c07, m2-h1
> 2016-06-13 07:52:56,889 WARN
>  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (default task-81) [1a1eab5e] Correlation ID: null, Call Stack: null, Custom
> Event ID: -1, Message: Failed to verify Power Management configuration for
> Host m2-h1.
> 2016-06-13 07:52:56,918 INFO
>  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] START,
> SetVdsStatusVDSCommand(HostName = m2-h1,
> SetVdsStatusVDSCommandParameters:{runAsync='true',
> hostId='244264be-4156-45a1-aed5-d05681303c07', status='Installing',
> nonOperationalReason='NONE', stopSpmFailureLogged='false',
> maintenanceReason='null'}), log id: 7656e770
> 2016-06-13 07:52:56,921 INFO
>  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (default task-81) [1a1eab5e] Correlation ID: 1a1eab5e, Call Stack: null,
> Custom Event ID: -1, Message: Host m2-h1 configuration was updated by
> admin at internal.
> 2016-06-13 07:52:56,933 INFO
>  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] FINISH,
> SetVdsStatusVDSCommand, log id: 7656e770
> 2016-06-13 07:52:57,140 INFO
>  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Correlation ID: 1a1eab5e,
> Call Stack: null, Custom Event ID: -1, Message: Installing Host m2-h1.
> Connected to host 192.168.1.12 with SSH key fingerprint:
> SHA256:oxhsFheDmU6jM0VVPhYXKsckaHLVL8z/fDV3HiLa/Uk.
> 2016-06-13 07:52:57,206 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Installation of 192.168.1.12.
> Executing command via SSH umask 0077; MYTMP="$(TMPDIR="${OVIRT_TMPDIR}"
> mktemp -d -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" >
> /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; tar
> --warning=no-timestamp -C "${MYTMP}" -x &&  "${MYTMP}"/ovirt-host-deploy
> DIALOG/dialect=str:machine DIALOG/customization=bool:True <
> /home/phillip/ovirt-engine/var/cache/ovirt-engine/ovirt-host-deploy.tar
> 2016-06-13 07:52:57,206 INFO
>  [org.ovirt.engine.core.utils.archivers.tar.CachedTar]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Tarball
> '/home/phillip/ovirt-engine/var/cache/ovirt-engine/ovirt-host-deploy.tar'
> refresh
> 2016-06-13 07:52:57,269 INFO  [org.ovirt.engine.core.uutils.ssh.SSHDialog]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] SSH execute '
> root at 192.168.1.12' 'umask 0077; MYTMP="$(TMPDIR="${OVIRT_TMPDIR}" mktemp
> -d -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null
> 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; tar --warning=no-timestamp
> -C "${MYTMP}" -x &&  "${MYTMP}"/ovirt-host-deploy
> DIALOG/dialect=str:machine DIALOG/customization=bool:True'
> 2016-06-13 07:52:57,415 ERROR
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1a1eab5e]
> Error during deploy dialog: java.io.IOException: Unexpected connection
> termination
> at
> org.ovirt.otopi.dialog.MachineDialogParser.nextEvent(MachineDialogParser.java:376)
> [otopi.jar:]
> at
> org.ovirt.otopi.dialog.MachineDialogParser.nextEvent(MachineDialogParser.java:393)
> [otopi.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase.threadMain(VdsDeployBase.java:304)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase.lambda$new$148(VdsDeployBase.java:383)
> [bll.jar:]
> at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_71]
>
> 2016-06-13 07:52:57,416 ERROR [org.ovirt.engine.core.uutils.ssh.SSHDialog]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] SSH error running command
> root at 192.168.1.12:'umask 0077; MYTMP="$(TMPDIR="${OVIRT_TMPDIR}" mktemp
> -d -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null
> 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; tar --warning=no-timestamp
> -C "${MYTMP}" -x &&  "${MYTMP}"/ovirt-host-deploy
> DIALOG/dialect=str:machine DIALOG/customization=bool:True': Command
> returned failure code 1 during SSH session 'root at 192.168.1.12'
> 2016-06-13 07:52:57,416 ERROR [org.ovirt.engine.core.uutils.ssh.SSHDialog]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Exception:
> java.io.IOException: Command returned failure code 1 during SSH session '
> root at 192.168.1.12'
> at
> org.ovirt.engine.core.uutils.ssh.SSHClient.executeCommand(SSHClient.java:526)
> [uutils.jar:]
> at
> org.ovirt.engine.core.uutils.ssh.SSHDialog.executeCommand(SSHDialog.java:317)
> [uutils.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase.execute(VdsDeployBase.java:563)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.installHost(InstallVdsInternalCommand.java:169)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.executeCommand(InstallVdsInternalCommand.java:90)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1304)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1446)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2066)
> [bll.jar:]
> at
> org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:166)
> [utils.jar:]
> at
> org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105)
> [utils.jar:]
> at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1485)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:401)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.executeValidatedCommand(PrevalidatingMultipleActionsRunner.java:198)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.runCommands(PrevalidatingMultipleActionsRunner.java:170)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.lambda$invokeCommands$49(PrevalidatingMultipleActionsRunner.java:176)
> [bll.jar:]
> at
> org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:92)
> [utils.jar:]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [rt.jar:1.8.0_71]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [rt.jar:1.8.0_71]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [rt.jar:1.8.0_71]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [rt.jar:1.8.0_71]
> at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_71]
>
> 2016-06-13 07:52:57,425 ERROR
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Error during host
> 192.168.1.12 install: java.io.IOException: Command returned failure code 1
> during SSH session 'root at 192.168.1.12'
> at
> org.ovirt.engine.core.uutils.ssh.SSHClient.executeCommand(SSHClient.java:526)
> [uutils.jar:]
> at
> org.ovirt.engine.core.uutils.ssh.SSHDialog.executeCommand(SSHDialog.java:317)
> [uutils.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase.execute(VdsDeployBase.java:563)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.installHost(InstallVdsInternalCommand.java:169)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.executeCommand(InstallVdsInternalCommand.java:90)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1304)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1446)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2066)
> [bll.jar:]
> at
> org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:166)
> [utils.jar:]
> at
> org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105)
> [utils.jar:]
> at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1485)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:401)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.executeValidatedCommand(PrevalidatingMultipleActionsRunner.java:198)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.runCommands(PrevalidatingMultipleActionsRunner.java:170)
> [bll.jar:]
> at
> org.ovirt.engine.core.bll.PrevalidatingMultipleActionsRunner.lambda$invokeCommands$49(PrevalidatingMultipleActionsRunner.java:176)
> [bll.jar:]
> at
> org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:92)
> [utils.jar:]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [rt.jar:1.8.0_71]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [rt.jar:1.8.0_71]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [rt.jar:1.8.0_71]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [rt.jar:1.8.0_71]
> at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_71]
>
> 2016-06-13 07:52:57,437 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Correlation ID: 1a1eab5e,
> Call Stack: null, Custom Event ID: -1, Message: Failed to install Host
> m2-h1. Command returned failure code 1 during SSH session '
> root at 192.168.1.12'.
> 2016-06-13 07:52:57,437 ERROR
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Error during host
> 192.168.1.12 install, prefering first exception: Unexpected connection
> termination
> 2016-06-13 07:52:57,437 ERROR
> [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Host installation failed for
> host '244264be-4156-45a1-aed5-d05681303c07', 'm2-h1': Unexpected connection
> termination
> 2016-06-13 07:52:57,440 INFO
>  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] START,
> SetVdsStatusVDSCommand(HostName = m2-h1,
> SetVdsStatusVDSCommandParameters:{runAsync='true',
> hostId='244264be-4156-45a1-aed5-d05681303c07', status='InstallFailed',
> nonOperationalReason='NONE', stopSpmFailureLogged='false',
> maintenanceReason='null'}), log id: 706571c5
> 2016-06-13 07:52:57,445 INFO
>  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] FINISH,
> SetVdsStatusVDSCommand, log id: 706571c5
> 2016-06-13 07:52:57,462 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Correlation ID: 1a1eab5e,
> Call Stack: null, Custom Event ID: -1, Message: Host m2-h1 installation
> failed. Unexpected connection termination.
> 2016-06-13 07:52:57,462 INFO
>  [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand]
> (org.ovirt.thread.pool-8-thread-1) [1a1eab5e] Lock freed to object
> 'EngineLock:{exclusiveLocks='[244264be-4156-45a1-aed5-d05681303c07=<VDS,
> ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20160613/9f8e6653/attachment-0001.html>