Not enough debug info for "execute"

[Cédric Jeanneret deactivated]

Dear Stackers,

We're hitting a nasty issue while trying to resize nova instance on Pike, and are currently unable to catch the root cause.

If you have a look at the log snippet at the end of this report, you'll see we can't know why the command fails - only the error code, but nothing more. A command output would be really useful, especially since we can't reproduce the exact command env by hand (nova user has a /sbin/nologin shell, so we must use "su -s /bin/sh" and other tricks that might temper the test).

It would be good to extend the following log entry in order to get the command output, especially in case of failure:
https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/processutils.py#L403-L404

Thank you in advance.

Cheers,

C.

Log in the current situation:

2017-11-09 09:06:00.411 26966 DEBUG nova.virt.libvirt.volume.remotefs [req-5e33aaa5-af39-47d6-b321-fa69258f157a 8c7e625be680b79dc2528d87f967965b11d2a0157aa582c083ab1113aa7b6dec 981c7dd9aeec4c71a0afa3f1efc2e2b3 - 7f117f751d7244a3a640019424
1bb825 7f117f751d7244a3a6400194241bb825] Creating file /var/lib/nova/instances/23ee6632-f3d7-48be-a6cb-e5e539f31eff/6246fd63ad664d67b951f96922d5b8f3.tmp on remote host 10.27.101.6 create_file /usr/lib/python2.7/site-packages/nova/virt/lib
virt/volume/remotefs.py:87
2017-11-09 09:06:00.411 26966 DEBUG oslo_concurrency.processutils [req-5e33aaa5-af39-47d6-b321-fa69258f157a 8c7e625be680b79dc2528d87f967965b11d2a0157aa582c083ab1113aa7b6dec 981c7dd9aeec4c71a0afa3f1efc2e2b3 - 7f117f751d7244a3a6400194241bb8
25 7f117f751d7244a3a6400194241bb825] Running cmd (subprocess): ssh -o BatchMode=yes 10.27.101.6 touch /var/lib/nova/instances/23ee6632-f3d7-48be-a6cb-e5e539f31eff/6246fd63ad664d67b951f96922d5b8f3.tmp execute /usr/lib/python2.7/site-packag
es/oslo_concurrency/processutils.py:367
2017-11-09 09:06:00.439 26966 DEBUG oslo_concurrency.processutils [req-5e33aaa5-af39-47d6-b321-fa69258f157a 8c7e625be680b79dc2528d87f967965b11d2a0157aa582c083ab1113aa7b6dec 981c7dd9aeec4c71a0afa3f1efc2e2b3 - 7f117f751d7244a3a6400194241bb8
25 7f117f751d7244a3a6400194241bb825] CMD "ssh -o BatchMode=yes 10.27.101.6 touch /var/lib/nova/instances/23ee6632-f3d7-48be-a6cb-e5e539f31eff/6246fd63ad664d67b951f96922d5b8f3.tmp" returned: 255 in 0.028s execute /usr/lib/python2.7/site-pa
ckages/oslo_concurrency/processutils.py:404
2017-11-09 09:06:00.440 26966 DEBUG oslo_concurrency.processutils [req-5e33aaa5-af39-47d6-b321-fa69258f157a 8c7e625be680b79dc2528d87f967965b11d2a0157aa582c083ab1113aa7b6dec 981c7dd9aeec4c71a0afa3f1efc2e2b3 - 7f117f751d7244a3a6400194241bb8
25 7f117f751d7244a3a6400194241bb825] u'ssh -o BatchMode=yes 10.27.101.6 touch /var/lib/nova/instances/23ee6632-f3d7-48be-a6cb-e5e539f31eff/6246fd63ad664d67b951f96922d5b8f3.tmp' failed. Not Retrying. execute /usr/lib/python2.7/site-package
s/oslo_concurrency/processutils.py:452

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/518695

[OpenStack Infra (hudson-openstack)]

Change abandoned by Yuriy Taraday (<email address hidden>) on branch: master
Review: https://review.opendev.org/518695
Reason: As I understand, consensus is that this should not be done in library, and author's account has bee deactivated since posting this change.