From 330d1fb7bb26a5b00d17b9dd19b86adeea0a2947 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Ionu=C8=9B=20Ar=C8=9B=C4=83ri=C8=99i?= <iartarisi@suse.cz>
Date: Thu, 10 Jul 2014 12:25:42 +0200
Subject: [PATCH] show stdout/err from failed command execution

When executing a command the mysql service status command it is useful
to see the actual output of the failing command in debug mode, not just
the exit status.

Add a log_output_on_error parameter to execute_with_timeout() so this
can be reused.

Change-Id: Iff931d0489754303e099e8567bca3237fd476f8f
Closes-Bug: #1340124
---
 trove/common/utils.py                       | 11 +++++
 trove/guestagent/datastore/mysql/service.py |  3 +-
 trove/tests/unittests/common/test_utils.py  | 54 +++++++++++++++++++++
 3 files changed, 67 insertions(+), 1 deletion(-)
 create mode 100644 trove/tests/unittests/common/test_utils.py

diff --git a/trove/common/utils.py b/trove/common/utils.py
index d10241a988..a27cd8d87c 100644
--- a/trove/common/utils.py
+++ b/trove/common/utils.py
@@ -272,10 +272,21 @@ def get_id_from_href(href):
 
 def execute_with_timeout(*args, **kwargs):
     time = kwargs.pop('timeout', 30)
+    log_output_on_error = kwargs.pop('log_output_on_error', False)
 
     timeout = Timeout(time)
     try:
         return execute(*args, **kwargs)
+    except exception.ProcessExecutionError as e:
+        if log_output_on_error:
+            LOG.error(
+                _("Command '%(cmd)s' failed. %(description)s "
+                  "Exit code: %(exit_code)s\nstderr: %(stderr)s\n"
+                  "stdout: %(stdout)s") %
+                {'cmd': e.cmd, 'description': e.description or '',
+                 'exit_code': e.exit_code, 'stderr': e.stderr,
+                 'stdout': e.stdout})
+        raise
     except Timeout as t:
         if t is not timeout:
             LOG.error(_("Got a timeout but not the one expected."))
diff --git a/trove/guestagent/datastore/mysql/service.py b/trove/guestagent/datastore/mysql/service.py
index ea32616259..18e62c23b5 100644
--- a/trove/guestagent/datastore/mysql/service.py
+++ b/trove/guestagent/datastore/mysql/service.py
@@ -158,7 +158,8 @@ class MySqlAppStatus(service.BaseDbStatus):
         try:
             out, err = utils.execute_with_timeout(
                 "/usr/bin/mysqladmin",
-                "ping", run_as_root=True, root_helper="sudo")
+                "ping", run_as_root=True, root_helper="sudo",
+                log_output_on_error=True)
             LOG.info(_("MySQL Service Status is RUNNING."))
             return rd_instance.ServiceStatuses.RUNNING
         except exception.ProcessExecutionError:
diff --git a/trove/tests/unittests/common/test_utils.py b/trove/tests/unittests/common/test_utils.py
new file mode 100644
index 0000000000..d186444222
--- /dev/null
+++ b/trove/tests/unittests/common/test_utils.py
@@ -0,0 +1,54 @@
+# Copyright 2014 SUSE Linux GmbH.
+# All Rights Reserved.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+#
+
+from trove.common import exception
+import trove.common.utils as utils
+
+from mock import Mock
+import testtools
+from testtools import ExpectedException
+
+
+class TestTroveExecuteWithTimeout(testtools.TestCase):
+    def test_throws_process_execution_error(self):
+        utils.execute = Mock(
+            side_effect=exception.ProcessExecutionError(
+                description='test-desc', exit_code=42, stderr='err',
+                stdout='out', cmd='test'))
+
+        with ExpectedException(
+                exception.ProcessExecutionError,
+                "test-desc\nCommand: test\nExit code: 42\n"
+                "Stdout: 'out'\nStderr: 'err'"):
+            utils.execute_with_timeout('/usr/bin/foo')
+
+    def test_log_error_when_log_output_on_error_is_true(self):
+        utils.execute = Mock(
+            side_effect=exception.ProcessExecutionError(
+                description='test-desc', exit_code=42, stderr='err',
+                stdout='out', cmd='test'))
+        utils.LOG.error = Mock()
+
+        with ExpectedException(
+                exception.ProcessExecutionError,
+                "test-desc\nCommand: test\nExit code: 42\n"
+                "Stdout: 'out'\nStderr: 'err'"):
+            utils.execute_with_timeout(
+                '/usr/bin/foo', log_output_on_error=True)
+
+        utils.LOG.error.assert_called_with(
+            u"Command 'test' failed. test-desc Exit code: 42\n"
+            "stderr: err\nstdout: out")