You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@aurora.apache.org by mc...@apache.org on 2014/10/08 16:46:19 UTC

git commit: Improve handling of unknown errors in the aurora client.

Repository: incubator-aurora
Updated Branches:
  refs/heads/master badd5e146 -> 74ee724c6


Improve handling of unknown errors in the aurora client.

Instead of dumping the stack on the user's terminal, or
absorbing the error and generating a brief error
message, the client now writes detailed information about
the error is written into an error log file, and the
user is given a clean error message referring them to that
file for details.

Bugs closed: aurora-779

Reviewed at https://reviews.apache.org/r/26328/


Project: http://git-wip-us.apache.org/repos/asf/incubator-aurora/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-aurora/commit/74ee724c
Tree: http://git-wip-us.apache.org/repos/asf/incubator-aurora/tree/74ee724c
Diff: http://git-wip-us.apache.org/repos/asf/incubator-aurora/diff/74ee724c

Branch: refs/heads/master
Commit: 74ee724c6c8e2b7b59b8f84e3089f4d8fb47094b
Parents: badd5e1
Author: Mark Chu-Carroll <mc...@twopensource.com>
Authored: Wed Oct 8 10:42:42 2014 -0400
Committer: Mark Chu-Carroll <mc...@twitter.com>
Committed: Wed Oct 8 10:42:42 2014 -0400

----------------------------------------------------------------------
 .../python/apache/aurora/client/cli/__init__.py | 29 ++++++++++++---
 .../aurora/client/cli/standalone_client.py      |  4 +++
 .../aurora/client/cli/test_api_from_cli.py      |  4 +--
 .../apache/aurora/client/cli/test_create.py     | 37 +++++++++++++++++++-
 4 files changed, 66 insertions(+), 8 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/incubator-aurora/blob/74ee724c/src/main/python/apache/aurora/client/cli/__init__.py
----------------------------------------------------------------------
diff --git a/src/main/python/apache/aurora/client/cli/__init__.py b/src/main/python/apache/aurora/client/cli/__init__.py
index e0c3050..5c0688f 100644
--- a/src/main/python/apache/aurora/client/cli/__init__.py
+++ b/src/main/python/apache/aurora/client/cli/__init__.py
@@ -34,6 +34,8 @@ import argparse
 import getpass
 import logging
 import sys
+import time
+import traceback
 from abc import abstractmethod
 from uuid import uuid1
 
@@ -416,9 +418,26 @@ class CommandLine(object):
       print_aurora_log(logging.INFO, "Error executing command: %s", c.msg)
       self.print_err("Error executing command: %s" % c.msg)
       return c.code
-    except Exception as e:
-      print_aurora_log(logging.ERROR, "Internal error executing command: %s", e)
-      return EXIT_API_ERROR
+    except Exception:
+      exc_type, exc_value, exc_traceback = sys.exc_info()
+      self.dump_error_log(args, exc_type, exc_value, exc_traceback)
+      return EXIT_UNKNOWN_ERROR
+
+  def dump_error_log(self, cmd_args, exc_type, exc_value, exc_traceback):
+    """Create an error log file in the directly where a command was executed,
+    and print detailed information about the error into the file.
+    :param cmd_args: the command-line arguments passed to the command that resulted in an error.
+    :param exc_type: the exc_type value for the error returnen by sys.exc_info()
+    :param exc_value: the exc_value value for the error returnen by sys.exc_info()
+    :param exc_traceback: the exc_traceback value for the error returnen by sys.exc_info()
+    """
+    now = str(int(time.time()))
+    path = "%s-%s.error-log" % (self.name, now)
+    print("Fatal error running command; traceback can be found in %s" % path,
+        file=sys.stderr)
+    with open(path, "w") as out:
+      print("ERROR LOG: command arguments = %s" % cmd_args, file=out)
+      traceback.print_exception(exc_type, exc_value, exc_traceback, file=out)
 
   def execute(self, args):
     try:
@@ -428,8 +447,8 @@ class CommandLine(object):
       return EXIT_INTERRUPTED
     except Exception as e:
       print_aurora_log(logging.ERROR, "Unknown error: %s" % e)
-      if Context.reveal_errors():
-        raise
+      exc_type, exc_value, exc_traceback = sys.exc_info()
+      self.dump_error_log(args, exc_type, exc_value, exc_traceback)
       return EXIT_UNKNOWN_ERROR
 
 

http://git-wip-us.apache.org/repos/asf/incubator-aurora/blob/74ee724c/src/main/python/apache/aurora/client/cli/standalone_client.py
----------------------------------------------------------------------
diff --git a/src/main/python/apache/aurora/client/cli/standalone_client.py b/src/main/python/apache/aurora/client/cli/standalone_client.py
index 7c0975c..4fdcf6d 100644
--- a/src/main/python/apache/aurora/client/cli/standalone_client.py
+++ b/src/main/python/apache/aurora/client/cli/standalone_client.py
@@ -98,6 +98,10 @@ class AuroraCommandLine(CommandLine):
     self.register_plugin(AuroraLogConfigurationPlugin())
     self.register_plugin(AuroraErrorHandlingPlugin())
 
+  @property
+  def name(self):
+    return 'aurora'
+
   @classmethod
   def get_description(cls):
     return 'Aurora client command line'

http://git-wip-us.apache.org/repos/asf/incubator-aurora/blob/74ee724c/src/test/python/apache/aurora/client/cli/test_api_from_cli.py
----------------------------------------------------------------------
diff --git a/src/test/python/apache/aurora/client/cli/test_api_from_cli.py b/src/test/python/apache/aurora/client/cli/test_api_from_cli.py
index 78f21d2..733327b 100644
--- a/src/test/python/apache/aurora/client/cli/test_api_from_cli.py
+++ b/src/test/python/apache/aurora/client/cli/test_api_from_cli.py
@@ -16,7 +16,7 @@ import contextlib
 
 from mock import Mock, patch
 
-from apache.aurora.client.cli import EXIT_API_ERROR
+from apache.aurora.client.cli import EXIT_UNKNOWN_ERROR
 from apache.aurora.client.cli.client import AuroraCommandLine
 from apache.aurora.client.cli.util import AuroraClientCommandTest
 
@@ -139,5 +139,5 @@ class TestApiFromCLI(AuroraClientCommandTest):
       # getTasksWithoutConfigs call against the mock_scheduler_client. That should raise an
       # exception, which results in the command failing with an error code.
       result = cmd.execute(['job', 'status', 'west/bozo/test/hello'])
-      assert result == EXIT_API_ERROR
+      assert result == EXIT_UNKNOWN_ERROR
       mock_scheduler_client.getTasksWithoutConfigs.assert_call_count == 1

http://git-wip-us.apache.org/repos/asf/incubator-aurora/blob/74ee724c/src/test/python/apache/aurora/client/cli/test_create.py
----------------------------------------------------------------------
diff --git a/src/test/python/apache/aurora/client/cli/test_create.py b/src/test/python/apache/aurora/client/cli/test_create.py
index 6e55188..8dc0ccb 100644
--- a/src/test/python/apache/aurora/client/cli/test_create.py
+++ b/src/test/python/apache/aurora/client/cli/test_create.py
@@ -13,6 +13,7 @@
 #
 
 import contextlib
+import os
 
 from mock import Mock, patch
 from twitter.common.contextutil import temporary_file
@@ -21,6 +22,7 @@ from apache.aurora.client.cli import (
     EXIT_COMMAND_FAILURE,
     EXIT_INTERRUPTED,
     EXIT_INVALID_CONFIGURATION,
+    EXIT_OK,
     EXIT_UNKNOWN_ERROR
 )
 from apache.aurora.client.cli.client import AuroraCommandLine
@@ -38,6 +40,9 @@ from gen.apache.aurora.api.ttypes import (
 )
 
 
+class UnknownException(Exception):
+  pass
+
 class TestClientCreateCommand(AuroraClientCommandTest):
 
   @classmethod
@@ -123,6 +128,34 @@ class TestClientCreateCommand(AuroraClientCommandTest):
       self.assert_create_job_called(api)
       self.assert_scheduler_called(api, mock_query, 2)
 
+  def test_create_job_fail_and_write_log(self):
+    """Check that when an unknown error occurs during command execution,
+    the command-line framework catches it, and writes out an error log file
+    containing the details of the error, including the command-line arguments
+    passed to aurora to execute the command, and the stack trace of the error.
+    """
+    mock_context = FakeAuroraCommandContext()
+    with contextlib.nested(
+        patch('time.time', return_value=23),
+        patch('apache.aurora.client.cli.jobs.Job.create_context', return_value=mock_context)):
+      api = mock_context.get_api('west')
+      api.create_job.side_effect = UnknownException()
+
+      with temporary_file() as fp:
+        fp.write(self.get_valid_config())
+        fp.flush()
+        cmd = AuroraCommandLine()
+        result = cmd.execute(['job', 'create', '--wait-until=RUNNING', 'west/bozo/test/hello',
+            fp.name])
+        assert result == EXIT_UNKNOWN_ERROR
+        with open("aurora-23.error-log", "r") as logfile:
+          error_log = logfile.read()
+          assert error_log.startswith("ERROR LOG: command arguments = %s" %
+              ['job', 'create', '--wait-until=RUNNING', 'west/bozo/test/hello',
+              fp.name])
+          assert "Traceback" in error_log
+        os.remove('aurora-23.error-log')
+
   def test_create_job_delayed(self):
     """Run a test of the "create" command against a mocked-out API:
     this time, make the monitor check status several times before successful completion.
@@ -203,10 +236,11 @@ class TestClientCreateCommand(AuroraClientCommandTest):
         assert result == EXIT_INTERRUPTED
         assert api.create_job.call_count == 0
 
-  def test_unknown_error(self):
+  def test_interrupt_error(self):
     mock_context = FakeAuroraCommandContext(reveal=False)
     with contextlib.nested(
         patch('time.sleep'),
+        patch('time.time', return_value=23),
         patch('apache.aurora.client.cli.jobs.Job.create_context',
             side_effect=Exception("Argh"))):
       api = mock_context.get_api('west')
@@ -219,6 +253,7 @@ class TestClientCreateCommand(AuroraClientCommandTest):
             fp.name])
         assert result == EXIT_UNKNOWN_ERROR
         assert api.create_job.call_count == 0
+        os.remove('aurora-23.error-log')
 
   def test_simple_successful_create_job_output(self):
     """Run a test of the "create" command against a mocked-out API: