[KVM-AUTOTEST PATCH v2 1/6] [RFC] Fix Unhandled* exceptions

[KVM-AUTOTEST PATCH v2 1/6] [RFC] Fix Unhandled* exceptions

[Michael Goldish]

In recent Python version, when exceptions are unpickled their __init__() method
is called again.  The parameters passed to __init__() upon unpickling are
*self.args.  Because the first execution of __init__() sets self.args to
something different from the parameters passed to __init__() (by passing
something to Exception.__init__()), upon unpickling __init__() is called with
unexpected parameters.

For example, if a NameError is raised in a test, UnhandledTestFail.__init__()
will call
Exception.__init__(self, "Unhandled NameError: ...").
Upon unpickling, UnhandledTestFail.__init__() will be called with "Unhandled
NameError: ..." which is a string.  It will then call
Exception.__init__(self, "Unhandled str: Unhandled NameError: ...")
because str is not an instance of TestFail.  The resulting exception's __str__()
method will return "Unhandled str: Unhandled NameError: ..." which isn't pretty.

To fix this, this patch makes the Unhandled* exceptions rely on __str__()
and attributes (self.unhandled_exception and self.traceback) instead of
__init__() and self.args.  An alternative solution could be to check whether
the parameter passed to __init__() is a string, and if so, pass it to the parent
exception's __init__() without modification.

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
---
 client/bin/job.py          |    6 ++--
 client/common_lib/error.py |   51 ++++++++++++++++++++++++++++---------------
 2 files changed, 36 insertions(+), 21 deletions(-)

diff --git a/client/bin/job.py b/client/bin/job.py
index 3d552ce..f4306fc 100644
--- a/client/bin/job.py
+++ b/client/bin/job.py
@@ -1182,13 +1182,13 @@ def runjob(control, drop_caches, options):
         sys.exit(1)
 
     except error.JobError, instance:
-        logging.error("JOB ERROR: " + instance.args[0])
+        logging.error("JOB ERROR: " + str(instance))
         if myjob:
             command = None
             if len(instance.args) > 1:
                 command = instance.args[1]
-                myjob.record('ABORT', None, command, instance.args[0])
-            myjob.record('END ABORT', None, None, instance.args[0])
+                myjob.record('ABORT', None, command, str(instance))
+            myjob.record('END ABORT', None, None, str(instance))
             assert myjob._record_indent == 0
             myjob.complete(1)
         else:
diff --git a/client/common_lib/error.py b/client/common_lib/error.py
index 42dfe2b..71ba4e5 100644
--- a/client/common_lib/error.py
+++ b/client/common_lib/error.py
@@ -44,14 +44,19 @@ class JobError(AutotestError):
 class UnhandledJobError(JobError):
     """Indicates an unhandled error in a job."""
     def __init__(self, unhandled_exception):
-        if isinstance(unhandled_exception, JobError):
-            JobError.__init__(self, *unhandled_exception.args)
+        JobError.__init__(self, unhandled_exception)
+        self.unhandled_exception = unhandled_exception
+        self.traceback = traceback.format_exc()
+
+    def __str__(self):
+        if isinstance(self.unhandled_exception, JobError):
+            return JobError.__str__(self.unhandled_exception)
         else:
             msg = "Unhandled %s: %s"
-            msg %= (unhandled_exception.__class__.__name__,
-                    unhandled_exception)
-            msg += "\n" + traceback.format_exc()
-            JobError.__init__(self, msg)
+            msg %= (self.unhandled_exception.__class__.__name__,
+                    self.unhandled_exception)
+            msg += "\n" + self.traceback
+            return msg
 
 
 class TestBaseException(AutotestError):
@@ -85,27 +90,37 @@ class TestWarn(TestBaseException):
 class UnhandledTestError(TestError):
     """Indicates an unhandled error in a test."""
     def __init__(self, unhandled_exception):
-        if isinstance(unhandled_exception, TestError):
-            TestError.__init__(self, *unhandled_exception.args)
+        TestError.__init__(self, unhandled_exception)
+        self.unhandled_exception = unhandled_exception
+        self.traceback = traceback.format_exc()
+
+    def __str__(self):
+        if isinstance(self.unhandled_exception, TestError):
+            return TestError.__str__(self.unhandled_exception)
         else:
             msg = "Unhandled %s: %s"
-            msg %= (unhandled_exception.__class__.__name__,
-                    unhandled_exception)
-            msg += "\n" + traceback.format_exc()
-            TestError.__init__(self, msg)
+            msg %= (self.unhandled_exception.__class__.__name__,
+                    self.unhandled_exception)
+            msg += "\n" + self.traceback
+            return msg
 
 
 class UnhandledTestFail(TestFail):
     """Indicates an unhandled fail in a test."""
     def __init__(self, unhandled_exception):
-        if isinstance(unhandled_exception, TestFail):
-            TestFail.__init__(self, *unhandled_exception.args)
+        TestFail.__init__(self, unhandled_exception)
+        self.unhandled_exception = unhandled_exception
+        self.traceback = traceback.format_exc()
+
+    def __str__(self):
+        if isinstance(self.unhandled_exception, TestFail):
+            return TestFail.__str__(self.unhandled_exception)
         else:
             msg = "Unhandled %s: %s"
-            msg %= (unhandled_exception.__class__.__name__,
-                    unhandled_exception)
-            msg += "\n" + traceback.format_exc()
-            TestFail.__init__(self, msg)
+            msg %= (self.unhandled_exception.__class__.__name__,
+                    self.unhandled_exception)
+            msg += "\n" + self.traceback
+            return msg
 
 
 class CmdError(TestError):
-- 
1.7.3.4

[KVM-AUTOTEST PATCH v2 2/6] [RFC] CmdError: remove extra blank line between methods

[Michael Goldish]

For consistency with other exception classes, keep just a single blank line
between __init__() and __str__().

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
---
 client/common_lib/error.py |    1 -
 1 files changed, 0 insertions(+), 1 deletions(-)

diff --git a/client/common_lib/error.py b/client/common_lib/error.py
index 71ba4e5..f1ddaea 100644
--- a/client/common_lib/error.py
+++ b/client/common_lib/error.py
@@ -133,7 +133,6 @@ class CmdError(TestError):
         self.result_obj = result_obj
         self.additional_text = additional_text
 
-
     def __str__(self):
         if self.result_obj.exit_status is None:
             msg = "Command <%s> failed and is not responding to signals"
-- 
1.7.3.4

[KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Michael Goldish]

In complex tests (KVM) an exception string is often not informative enough and
the traceback and source code have to be examined in order to figure out what
caused the exception.  Context strings are a way for tests to provide
information about what they're doing, so that when an exception is raised, this
information will be embedded in the exception string.  The result is a concise
yet highly informative exception string, which should make it very easy to
figure out where/when the exception was raised.

A typical example for a test where this may be useful is KVM's reboot test.
Some exceptions can be raised either before or after the VM is rebooted (e.g.
logging into the guest can fail) and whether they are raised before or after
is critical to the understanding of the failure.  Normally the traceback would
have to be examined, but the proposed method makes it easy to know where the
exception is raised without doing so.  To achieve this, the reboot test should
place calls to error.context() as follows:

error.context("before reboot")
<carry out pre-reboot actions>
error.context("sending reboot command")
<send the reboot command>
error.context("after reboot")
<carry out post-reboot actions>

If login fails in the pre-reboot section, the resulting exception string can
can have something like "context: before reboot" embedded in it.  (The actual
embedding is done in the next patch in the series.)

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
Signed-off-by: Eduardo Habkost <ehabkost@redhat.com>
---
 client/common_lib/error.py |   97 +++++++++++++++++++++++++++++++++++++++++++-
 1 files changed, 95 insertions(+), 2 deletions(-)

diff --git a/client/common_lib/error.py b/client/common_lib/error.py
index f1ddaea..952f977 100644
--- a/client/common_lib/error.py
+++ b/client/common_lib/error.py
@@ -2,13 +2,14 @@
 Internal global error types
 """
 
-import sys, traceback
+import sys, traceback, threading, logging
 from traceback import format_exception
 
 # Add names you want to be imported by 'from errors import *' to this list.
 # This must be list not a tuple as we modify it to include all of our
 # the Exception classes we define below at the end of this file.
-__all__ = ['format_error']
+__all__ = ['format_error', 'context_aware', 'context', 'get_context',
+           'context_for_exception']
 
 
 def format_error():
@@ -21,6 +22,98 @@ def format_error():
     return ''.join(trace)
 
 
+# Exception context information:
+# ------------------------------
+# Every function can have some context string associated with it.
+# The context string can be changed by calling context(str) and cleared by
+# calling context() with no parameters.
+# get_context() joins the current context strings of all functions in the
+# provided traceback.  The result is a brief description of what the test was
+# doing in the provided traceback (which should be the traceback of a caught
+# exception).
+#
+# For example: assume a() calls b() and b() calls c().
+#
+# def a():
+#     error.context("hello")
+#     b()
+#     error.context("world")
+#     get_context() ----> 'world'
+#
+# def b():
+#     error.context("foo")
+#     c()
+#
+# def c():
+#     error.context("bar")
+#     get_context() ----> 'hello --> foo --> bar'
+
+ctx = threading.local()
+
+
+def _new_context(s=""):
+    if not hasattr(ctx, "contexts"):
+        ctx.contexts = []
+    ctx.contexts.append(s)
+
+
+def _pop_context():
+    ctx.contexts.pop()
+
+
+def get_context():
+    """Return the current context (or None if none is defined)."""
+    if hasattr(ctx, "contexts"):
+        return " --> ".join([s for s in ctx.contexts if s])
+
+
+def context_for_exception(e):
+    """Return the context of a given exception (or None if none is defined)."""
+    if hasattr(e, "_context"):
+        return e._context
+
+
+def context(s="", log=None):
+    """
+    Set the context for the currently executing function and optionally log it.
+
+    @param s: A string.  If not provided, the context for the current function
+            will be cleared.
+    @param log: A logging function to pass the context message to.  If None, no
+            function will be called.
+    """
+    ctx.contexts[-1] = s
+    if s and log:
+        log("Context: %s" % get_context())
+
+
+def context_aware(fn):
+    """A decorator that must be applied to functions that call context()."""
+    def new_fn(*args, **kwargs):
+        _new_context("(%s)" % fn.__name__)
+        try:
+            try:
+                return fn(*args, **kwargs)
+            except Exception, e:
+                if not hasattr(e, "_context"):
+                    e._context = get_context()
+                raise
+        finally:
+            _pop_context()
+    new_fn.__name__ = fn.__name__
+    new_fn.__doc__ = fn.__doc__
+    new_fn.__dict__.update(fn.__dict__)
+    return new_fn
+
+
+def _context_message(e):
+    s = context_for_exception(e)
+    if s:
+        return "    [context: %s]" % s
+    else:
+        return ""
+
+
 class JobContinue(SystemExit):
     """Allow us to bail out requesting continuance."""
     pass
-- 
1.7.3.4

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Eduardo Habkost]

On Wed, Jan 05, 2011 at 05:45:26PM +0200, Michael Goldish wrote:
> In complex tests (KVM) an exception string is often not informative enough and
> the traceback and source code have to be examined in order to figure out what
> caused the exception.  Context strings are a way for tests to provide
> information about what they're doing, so that when an exception is raised, this
> information will be embedded in the exception string.  The result is a concise
> yet highly informative exception string, which should make it very easy to
> figure out where/when the exception was raised.
> 
> A typical example for a test where this may be useful is KVM's reboot test.
> Some exceptions can be raised either before or after the VM is rebooted (e.g.
> logging into the guest can fail) and whether they are raised before or after
> is critical to the understanding of the failure.  Normally the traceback would
> have to be examined, but the proposed method makes it easy to know where the
> exception is raised without doing so.  To achieve this, the reboot test should
> place calls to error.context() as follows:
> 
> error.context("before reboot")
> <carry out pre-reboot actions>
> error.context("sending reboot command")
> <send the reboot command>
> error.context("after reboot")
> <carry out post-reboot actions>
> 
> If login fails in the pre-reboot section, the resulting exception string can
> can have something like "context: before reboot" embedded in it.  (The actual
> embedding is done in the next patch in the series.)
> 
> Signed-off-by: Michael Goldish <mgoldish@redhat.com>
> Signed-off-by: Eduardo Habkost <ehabkost@redhat.com>
> ---
>  client/common_lib/error.py |   97 +++++++++++++++++++++++++++++++++++++++++++-
>  1 files changed, 95 insertions(+), 2 deletions(-)
> 

Where's the automated test code?  ;)


> +# def a():
> +#     error.context("hello")
> +#     b()
> +#     error.context("world")
> +#     get_context() ----> 'world'
> +#
> +# def b():
> +#     error.context("foo")
> +#     c()
> +#
> +# def c():
> +#     error.context("bar")
> +#     get_context() ----> 'hello --> foo --> bar'

The example above is outdated, isn't? It doesn't have the @context_aware
decorator.

-- 
Eduardo

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Avi Kivity]

On 01/05/2011 05:45 PM, Michael Goldish wrote:
> In complex tests (KVM) an exception string is often not informative enough and
> the traceback and source code have to be examined in order to figure out what
> caused the exception.  Context strings are a way for tests to provide
> information about what they're doing, so that when an exception is raised, this
> information will be embedded in the exception string.  The result is a concise
> yet highly informative exception string, which should make it very easy to
> figure out where/when the exception was raised.
>
> A typical example for a test where this may be useful is KVM's reboot test.
> Some exceptions can be raised either before or after the VM is rebooted (e.g.
> logging into the guest can fail) and whether they are raised before or after
> is critical to the understanding of the failure.  Normally the traceback would
> have to be examined, but the proposed method makes it easy to know where the
> exception is raised without doing so.  To achieve this, the reboot test should
> place calls to error.context() as follows:
>
> error.context("before reboot")
> <carry out pre-reboot actions>
> error.context("sending reboot command")
> <send the reboot command>
> error.context("after reboot")
> <carry out post-reboot actions>
>
> If login fails in the pre-reboot section, the resulting exception string can
> can have something like "context: before reboot" embedded in it.  (The actual
> embedding is done in the next patch in the series.)

It would be nice to make the error context a stack, and to use the with 
statement to manage the stack:


    with error.context("main test"):
        foo()
        with error.context("before reboot"):
            bar()

If foo() throws an exception, the context would be "main test", while if 
bar() throws an exception, the context would be "before reboot" in "main 
test".

-- 
error compiling committee.c: too many arguments to function

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Eduardo Habkost]

On Wed, Jan 05, 2011 at 06:12:05PM +0200, Avi Kivity wrote:
> It would be nice to make the error context a stack, and to use the
> with statement to manage the stack:
> 
> 
>    with error.context("main test"):
>        foo()
>        with error.context("before reboot"):
>            bar()
> 
> If foo() throws an exception, the context would be "main test",
> while if bar() throws an exception, the context would be "before
> reboot" in "main test".

Autotest targets Python 2.4, and Python 2.4 doesn't have the 'with'
statement.

The error context is already a stack, but without the 'with' statement
you would have to use try/finally explicitly:

  _new_context('foo')
  try:
    # [...]
  finally:
    _pop_context()

By the way, I think we could make _new_context() and _pop_context() part
of the public interface (i.e. remove the "_" from their names).  I see
@context_aware as just a helper for a stack interface that could be used
directly if needed.

-- 
Eduardo

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Avi Kivity]

On 01/05/2011 06:21 PM, Eduardo Habkost wrote:
> On Wed, Jan 05, 2011 at 06:12:05PM +0200, Avi Kivity wrote:
> >  It would be nice to make the error context a stack, and to use the
> >  with statement to manage the stack:
> >
> >
> >     with error.context("main test"):
> >         foo()
> >         with error.context("before reboot"):
> >             bar()
> >
> >  If foo() throws an exception, the context would be "main test",
> >  while if bar() throws an exception, the context would be "before
> >  reboot" in "main test".
>
> Autotest targets Python 2.4, and Python 2.4 doesn't have the 'with'
> statement.
>

Too bad :(

> The error context is already a stack, but without the 'with' statement
> you would have to use try/finally explicitly:
>
>    _new_context('foo')
>    try:
>      # [...]
>    finally:
>      _pop_context()
>
> By the way, I think we could make _new_context() and _pop_context() part
> of the public interface (i.e. remove the "_" from their names).  I see
> @context_aware as just a helper for a stack interface that could be used
> directly if needed.
>

Yeah.

-- 
error compiling committee.c: too many arguments to function

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Michael Goldish]

On 01/05/2011 06:21 PM, Eduardo Habkost wrote:
> On Wed, Jan 05, 2011 at 06:12:05PM +0200, Avi Kivity wrote:
>> It would be nice to make the error context a stack, and to use the
>> with statement to manage the stack:
>>
>>
>>    with error.context("main test"):
>>        foo()
>>        with error.context("before reboot"):
>>            bar()
>>
>> If foo() throws an exception, the context would be "main test",
>> while if bar() throws an exception, the context would be "before
>> reboot" in "main test".
> 
> Autotest targets Python 2.4, and Python 2.4 doesn't have the 'with'
> statement.
> 
> The error context is already a stack, but without the 'with' statement
> you would have to use try/finally explicitly:
> 
>   _new_context('foo')
>   try:
>     # [...]
>   finally:
>     _pop_context()
> 
> By the way, I think we could make _new_context() and _pop_context() part
> of the public interface (i.e. remove the "_" from their names).  I see
> @context_aware as just a helper for a stack interface that could be used
> directly if needed.

To actually use the context you also have to insert it into an
exception, i.e.

_new_context('foo')
try:
    try:
        ...
    except Exception, e:
        e._context = get_context()
finally:
    _pop_context()

and I thought it would be more comfortable to just define a
@context_aware function and call it.

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Eduardo Habkost]

On Wed, Jan 05, 2011 at 08:55:44PM +0200, Michael Goldish wrote:
> On 01/05/2011 06:21 PM, Eduardo Habkost wrote:
> > By the way, I think we could make _new_context() and _pop_context() part
> > of the public interface (i.e. remove the "_" from their names).  I see
> > @context_aware as just a helper for a stack interface that could be used
> > directly if needed.
> 
> To actually use the context you also have to insert it into an
> exception, i.e.
> 
> _new_context('foo')
> try:
>     try:
>         ...
>     except Exception, e:
>         e._context = get_context()
> finally:
>     _pop_context()

True. Just forget about my suggestion.  :)

-- 
Eduardo

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Avi Kivity]

On 01/05/2011 06:12 PM, Avi Kivity wrote:
> On 01/05/2011 05:45 PM, Michael Goldish wrote:
>> In complex tests (KVM) an exception string is often not informative 
>> enough and
>> the traceback and source code have to be examined in order to figure 
>> out what
>> caused the exception.  Context strings are a way for tests to provide
>> information about what they're doing, so that when an exception is 
>> raised, this
>> information will be embedded in the exception string.  The result is 
>> a concise
>> yet highly informative exception string, which should make it very 
>> easy to
>> figure out where/when the exception was raised.
>>
>> A typical example for a test where this may be useful is KVM's reboot 
>> test.
>> Some exceptions can be raised either before or after the VM is 
>> rebooted (e.g.
>> logging into the guest can fail) and whether they are raised before 
>> or after
>> is critical to the understanding of the failure.  Normally the 
>> traceback would
>> have to be examined, but the proposed method makes it easy to know 
>> where the
>> exception is raised without doing so.  To achieve this, the reboot 
>> test should
>> place calls to error.context() as follows:
>>
>> error.context("before reboot")
>> <carry out pre-reboot actions>
>> error.context("sending reboot command")
>> <send the reboot command>
>> error.context("after reboot")
>> <carry out post-reboot actions>
>>
>> If login fails in the pre-reboot section, the resulting exception 
>> string can
>> can have something like "context: before reboot" embedded in it.  
>> (The actual
>> embedding is done in the next patch in the series.)
>
> It would be nice to make the error context a stack, and to use the 
> with statement to manage the stack:
>
>
>    with error.context("main test"):
>        foo()
>        with error.context("before reboot"):
>            bar()
>
> If foo() throws an exception, the context would be "main test", while 
> if bar() throws an exception, the context would be "before reboot" in 
> "main test".
>

btw, you can have a decorator for enclosing an entire function in an 
error context:

    @function_error_context('migration test')
    def migration_test(...):
        ...

anything in migration_test() is enclosed in that context.  But we're 
just repeating the ordinary stack trace with something more readable.

-- 
error compiling committee.c: too many arguments to function

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Eduardo Habkost]

On Wed, Jan 05, 2011 at 06:21:35PM +0200, Avi Kivity wrote:
> btw, you can have a decorator for enclosing an entire function in an
> error context:
> 
>    @function_error_context('migration test')
>    def migration_test(...):
>        ...

@context_aware does that, but it doesn't let you set the context string
(it just initializes it to "(function_name)"). I think it is enough for
our purposes (and it keeps the API simple).

> 
> anything in migration_test() is enclosed in that context.  But we're
> just repeating the ordinary stack trace with something more
> readable.

The context information is more useful for cases we want to know where
exactly we were, inside a single function (e.g. "did we crash before or
after migration finished?"). So the API is optimized for the cases where
we actually want to change the context string inside the same function.

-- 
Eduardo

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Avi Kivity]

On 01/05/2011 06:36 PM, Eduardo Habkost wrote:
> On Wed, Jan 05, 2011 at 06:21:35PM +0200, Avi Kivity wrote:
> >  btw, you can have a decorator for enclosing an entire function in an
> >  error context:
> >
> >     @function_error_context('migration test')
> >     def migration_test(...):
> >         ...
>
> @context_aware does that, but it doesn't let you set the context string
> (it just initializes it to "(function_name)"). I think it is enough for
> our purposes (and it keeps the API simple).
>
> >
> >  anything in migration_test() is enclosed in that context.  But we're
> >  just repeating the ordinary stack trace with something more
> >  readable.
>
> The context information is more useful for cases we want to know where
> exactly we were, inside a single function (e.g. "did we crash before or
> after migration finished?"). So the API is optimized for the cases where
> we actually want to change the context string inside the same function.
>

Ok, makes sense.  'with' would have been nice, but I understand the need 
for compatibility.

-- 
error compiling committee.c: too many arguments to function

Re: [KVM-AUTOTEST PATCH v2 3/6] [RFC] Introduce exception context strings

[Michael Goldish]

On 01/05/2011 06:21 PM, Avi Kivity wrote:
> On 01/05/2011 06:12 PM, Avi Kivity wrote:
>> On 01/05/2011 05:45 PM, Michael Goldish wrote:
>>> In complex tests (KVM) an exception string is often not informative
>>> enough and
>>> the traceback and source code have to be examined in order to figure
>>> out what
>>> caused the exception.  Context strings are a way for tests to provide
>>> information about what they're doing, so that when an exception is
>>> raised, this
>>> information will be embedded in the exception string.  The result is
>>> a concise
>>> yet highly informative exception string, which should make it very
>>> easy to
>>> figure out where/when the exception was raised.
>>>
>>> A typical example for a test where this may be useful is KVM's reboot
>>> test.
>>> Some exceptions can be raised either before or after the VM is
>>> rebooted (e.g.
>>> logging into the guest can fail) and whether they are raised before
>>> or after
>>> is critical to the understanding of the failure.  Normally the
>>> traceback would
>>> have to be examined, but the proposed method makes it easy to know
>>> where the
>>> exception is raised without doing so.  To achieve this, the reboot
>>> test should
>>> place calls to error.context() as follows:
>>>
>>> error.context("before reboot")
>>> <carry out pre-reboot actions>
>>> error.context("sending reboot command")
>>> <send the reboot command>
>>> error.context("after reboot")
>>> <carry out post-reboot actions>
>>>
>>> If login fails in the pre-reboot section, the resulting exception
>>> string can
>>> can have something like "context: before reboot" embedded in it. 
>>> (The actual
>>> embedding is done in the next patch in the series.)
>>
>> It would be nice to make the error context a stack, and to use the
>> with statement to manage the stack:
>>
>>
>>    with error.context("main test"):
>>        foo()
>>        with error.context("before reboot"):
>>            bar()
>>
>> If foo() throws an exception, the context would be "main test", while
>> if bar() throws an exception, the context would be "before reboot" in
>> "main test".

This seems like the best solution and it's unfortunate that we can't use it.

> btw, you can have a decorator for enclosing an entire function in an
> error context:
> 
>    @function_error_context('migration test')
>    def migration_test(...):
>        ...
> 
> anything in migration_test() is enclosed in that context.  But we're
> just repeating the ordinary stack trace with something more readable.

The problem is that the string passed to function_error_context can't be
based on function parameters, so declaring a context like 'migrating
vm1' is impossible.

I do think we can benefit from 2 context levels per function though:

@context_aware
def migrate(...):
    base_context("migrating %s" % vm.name)
    context("collecting parameters")
    ...
    context("sending monitor command")
    ...
    context("cleanup")
    ...

base_context() and context() will just be joined together using ' --> '
like regular contexts.  base_context() can be useful for long utility
functions.  Does this sound like a reasonable solution, or do you think
it's cleaner to always define a new nested function for each context level?

[KVM-AUTOTEST PATCH v2 4/6] [RFC] Embed context information in exception strings

[Michael Goldish]

Exceptions look for a ._context attribute and embed it in the string returned
by __str__().  If the attribute isn't set (or if it's an empty string) nothing
is embedded.

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
---
 client/common_lib/error.py |   10 +++++++++-
 1 files changed, 9 insertions(+), 1 deletions(-)

diff --git a/client/common_lib/error.py b/client/common_lib/error.py
index 952f977..ff22d84 100644
--- a/client/common_lib/error.py
+++ b/client/common_lib/error.py
@@ -126,7 +126,8 @@ class JobComplete(SystemExit):
 
 class AutotestError(Exception):
     """The parent of all errors deliberatly thrown within the client code."""
-    pass
+    def __str__(self):
+        return Exception.__str__(self) + _context_message(self)
 
 
 class JobError(AutotestError):
@@ -148,6 +149,8 @@ class UnhandledJobError(JobError):
             msg = "Unhandled %s: %s"
             msg %= (self.unhandled_exception.__class__.__name__,
                     self.unhandled_exception)
+            if not isinstance(self.unhandled_exception, AutotestError):
+                msg += _context_message(self.unhandled_exception)
             msg += "\n" + self.traceback
             return msg
 
@@ -194,6 +197,8 @@ class UnhandledTestError(TestError):
             msg = "Unhandled %s: %s"
             msg %= (self.unhandled_exception.__class__.__name__,
                     self.unhandled_exception)
+            if not isinstance(self.unhandled_exception, AutotestError):
+                msg += _context_message(self.unhandled_exception)
             msg += "\n" + self.traceback
             return msg
 
@@ -212,6 +217,8 @@ class UnhandledTestFail(TestFail):
             msg = "Unhandled %s: %s"
             msg %= (self.unhandled_exception.__class__.__name__,
                     self.unhandled_exception)
+            if not isinstance(self.unhandled_exception, AutotestError):
+                msg += _context_message(self.unhandled_exception)
             msg += "\n" + self.traceback
             return msg
 
@@ -236,6 +243,7 @@ class CmdError(TestError):
 
         if self.additional_text:
             msg += ", " + self.additional_text
+        msg += _context_message(self)
         msg += '\n' + repr(self.result_obj)
         return msg
 
-- 
1.7.3.4

[KVM-AUTOTEST PATCH v2 5/6] [RFC] KVM test: use error.context() in migration_with_file_transfer

[Michael Goldish]

This is an example of a case where context information is useful.

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
---
 .../kvm/tests/migration_with_file_transfer.py      |   12 +++++++++---
 1 files changed, 9 insertions(+), 3 deletions(-)

diff --git a/client/tests/kvm/tests/migration_with_file_transfer.py b/client/tests/kvm/tests/migration_with_file_transfer.py
index 27c1fe1..8a2cc77 100644
--- a/client/tests/kvm/tests/migration_with_file_transfer.py
+++ b/client/tests/kvm/tests/migration_with_file_transfer.py
@@ -4,6 +4,7 @@ from autotest_lib.client.bin import utils as client_utils
 import kvm_subprocess, kvm_test_utils, kvm_utils
 
 
+@error.context_aware
 def run_migration_with_file_transfer(test, params, env):
     """
     KVM migration test:
@@ -47,24 +48,29 @@ def run_migration_with_file_transfer(test, params, env):
             finally:
                 bg.join()
 
-        logging.info("Transferring file from host to guest")
+        error.context("transferring file to guest while migrating",
+                      logging.info)
         bg = kvm_utils.Thread(vm.copy_files_to,
                               (host_path, guest_path, 0, transfer_timeout))
         run_and_migrate(bg)
 
-        logging.info("Transferring file back from guest to host")
+        error.context("transferring file back to host while migrating",
+                      logging.info)
         bg = kvm_utils.Thread(vm.copy_files_from,
                               (guest_path, host_path_returned, 0,
                                transfer_timeout))
         run_and_migrate(bg)
 
-        # Make sure the returned file is indentical to the original one
+        # Make sure the returned file is identical to the original one
+        error.context("comparing hashes", logging.info)
         orig_hash = client_utils.hash_file(host_path)
         returned_hash = client_utils.hash_file(host_path_returned)
         if orig_hash != returned_hash:
             raise error.TestFail("Returned file hash (%s) differs from "
                                  "original one (%s)" % (returned_hash,
                                                         orig_hash))
+        error.context()
+
     finally:
         session.close()
         if os.path.isfile(host_path):
-- 
1.7.3.4

[KVM-AUTOTEST PATCH v2 6/6] [RFC] KVM test: use error.context() in kvm_preprocessing.py

[Michael Goldish]

Signed-off-by: Michael Goldish <mgoldish@redhat.com>
---
 client/tests/kvm/kvm_preprocessing.py |   13 +++++++++++--
 1 files changed, 11 insertions(+), 2 deletions(-)

diff --git a/client/tests/kvm/kvm_preprocessing.py b/client/tests/kvm/kvm_preprocessing.py
index 5ce0a3b..e5b8906 100644
--- a/client/tests/kvm/kvm_preprocessing.py
+++ b/client/tests/kvm/kvm_preprocessing.py
@@ -39,6 +39,7 @@ def preprocess_image(test, params):
         raise error.TestError("Could not create image")
 
 
+@error.context_aware
 def preprocess_vm(test, params, env, name):
     """
     Preprocess a single VM object according to the instructions in params.
@@ -49,7 +50,8 @@ def preprocess_vm(test, params, env, name):
     @param env: The environment (a dict-like object).
     @param name: The name of the VM object.
     """
-    logging.debug("Preprocessing VM '%s'..." % name)
+    error.context("preprocessing '%s'" % name)
+
     vm = env.get_vm(name)
     if vm:
         logging.debug("VM object found in environment")
@@ -104,6 +106,7 @@ def postprocess_image(test, params):
         kvm_vm.remove_image(params, test.bindir)
 
 
+@error.context_aware
 def postprocess_vm(test, params, env, name):
     """
     Postprocess a single VM object according to the instructions in params.
@@ -114,7 +117,7 @@ def postprocess_vm(test, params, env, name):
     @param env: The environment (a dict-like object).
     @param name: The name of the VM object.
     """
-    logging.debug("Postprocessing VM '%s'..." % name)
+    error.context("postprocessing '%s'" % name)
     vm = env.get_vm(name)
     if vm:
         logging.debug("VM object found in environment")
@@ -187,6 +190,7 @@ def process(test, params, env, image_func, vm_func):
         vm_func(test, vm_params, env, vm_name)
 
 
+@error.context_aware
 def preprocess(test, params, env):
     """
     Preprocess all VMs and images according to the instructions in params.
@@ -196,6 +200,8 @@ def preprocess(test, params, env):
     @param params: A dict containing all VM and image parameters.
     @param env: The environment (a dict-like object).
     """
+    error.context("preprocessing")
+
     # Start tcpdump if it isn't already running
     if "address_cache" not in env:
         env["address_cache"] = {}
@@ -274,6 +280,7 @@ def preprocess(test, params, env):
         _screendump_thread.start()
 
 
+@error.context_aware
 def postprocess(test, params, env):
     """
     Postprocess all VMs and images according to the instructions in params.
@@ -282,6 +289,8 @@ def postprocess(test, params, env):
     @param params: Dict containing all VM and image parameters.
     @param env: The environment (a dict-like object).
     """
+    error.context("postprocessing")
+
     # Postprocess all VMs and images
     process(test, params, env, postprocess_image, postprocess_vm)
 
-- 
1.7.3.4