Traceback available in error results

[PaulSchweizer]

Based on this PR/discussion: #347 (comment)

I also added logging of the error, useful for situations where there is no UI and/or something unexpected occurs but I'm not sure if there are arguments against this?

As for the unittest, I am not sure if this is the correct location, please let me know where the test should go.

[mottosso]

Ok, I've had a look at this and unfortunately it reproduces the problem with #347, in that we now have duplicate data.

Here's the data present in the context.data["results"][-1]["error"] member.

test.py

from pyblish import api, util

class Plugin(api.ContextPlugin):
   def process(self, context):
     assert False, "This was a problem"

api.register_plugin(Plugin)
ctx = util.publish()
error = ctx.data["results"][-1]["error"]

fname, lineno, func, msg = error.traceback
print(fname, lineno, func, msg)

Python 2

> $ python .\test.py
This was a problem
('.\\test.py', 5, 'process', 'assert False, "This was a problem"')

Python 3

> $ python .\test.py
This was a problem
.\test.py 5 process assert False, "This was a problem"

Notice how all information in the new error_info is all here, unless I'm missing something?

In addition, this PR includes support for a <string> filename, which can (only?) happen when registering a plug-in in an interactive Python session. And outside of experimentation and testing, is that something people do? For example, writing in the Maya Script Editor and using that in their production publishes, or somehow reading the raw test from a Python module of Pyblish plug-ins, and exec()-ing those.

We could support that, like you have here, but we would need a usecase for it. A reason.

Other than supporting <string>, does this PR add anything new? Could it be the case that "error" was misunderstood, or not visible enough? Granted, it isn't obvious that the members contained in that tuple are in that order, but that's what Python's traceback object looks like.

[PaulSchweizer]

Duplicated data
Yes kind of. I added the error_info dict from that PR because I was under the false impression that that was what was agreed upon, I do not need it.
The only thing we do not yet have (and I would want) is the formated traceback message which I can not reproduce from fname, lineno, func, msg = error.traceback after the fact since the sys.exc_info() is gone by that time. If there is a way to achieve that though, please let me know.

Basically this is the only thing we'd need:

test.py

from pyblish import api, util

class Plugin(api.ContextPlugin):
   def process(self, context):
     assert False, "This was a problem"

api.register_plugin(Plugin)
ctx = util.publish()
error = ctx.data["results"][-1]["error"]

fname, lineno, func, msg = error.traceback
formatted_traceback = error.formatted_traceback  # This would be new
print(fname, lineno, func, msg)
print(formatted_traceback)

Result:

> $ python .\test.py
This was a problem
('.\\test.py', 5, 'process', 'assert False, "This was a problem"')

Traceback (most recent call last):
  File "/pyblish/plugin.py", line 518, in __explicit_process
    runner(*args)
  File "/test.py", line 5, in process
AssertionError: This was a problem 

String paths
We are registering pyblish plugins like this everywhere:

from pyblish import api 

api.register_plugin_path("my/plugin/path")
api.discover()

Which leads to the <string> issue as reproduced in the tests but please let me know if this does not happen for you?
Also, let me know if we should refrain from doing it this way? It's just helpful in situations where we have plugins in context specific places, but that can be solved differently as well of course.

[BigRoy]

👍 To add a little note from my end.

Exactly this is what I'd like to see too:

Traceback (most recent call last):
  File "/pyblish/plugin.py", line 518, in __explicit_process
    runner(*args)
  File "/test.py", line 5, in process
AssertionError: This was a problem 

Especially the full traceback that also includes this information: File "/pyblish/plugin.py", line 518, in __explicit_process. Note how that information is not in the other data. This would allow to have a full traceback depth as opposed to only the last call. If I recall correctly that's exactly the issue I was having with displayed errors in Pyblish QML, that they were incapable of displaying the full traceback. But I'd have to test whether that's actually (still) the case.

[mottosso]

Basically this is the only thing we'd need:

Yes, that looks good to me.

Also, let me know if we should refrain from doing it this way?

No that's the right way, and I see the problem now. This is a bug. Plug-ins coming from register_plugin_path does have a path. But it looks like that path is thrown away by discover() (to facilitate the auto-reload functionality).

I had a look to see whether there was an easy fix here, but came up short. The problem is how extract_traceback finds that path to begin with. The discover function does make a record of what the path is, but it doesn't seem to be looking there.

So in addition to your fix for converting <string> to a full path, could you also add this?

        lib.extract_traceback(error)
        if error.traceback[0] == "<string>":
           error.traceback = (os.path.abspath(plugin.__module__),) + error.traceback[1:]
        result["error"] = error

Idealy, the formatting would then be able to use this path, so we wouldn't have to check for <string> twice, but if not then that's fine.

With this, we should have a fully correct error.

[PaulSchweizer]

So in addition to your fix for converting to a full path, could you also add this?

Done

Idealy, the formatting would then be able to use this path, so we wouldn't have to check for twice, but if not then that's fine.

The formatting of the exception message is an internal process of the traceback module and it relies on sys.exc_info and not the extracted data so I don't see a way to inject the correct file path in there.
Good news though is that we only need to check for once anyways.

[mottosso]

Sorry to keep picking on this, but something only become apparent when you're just about to merge. xD

Could we make this function take a fname=None argument instead? Having it take plugin implies some dependency on Pyblish's Plugin class, and it's actually quite general and has to do with overriding the fname found in the exception argument. That would make it squeaky clean.

If you're done with this, I understand and could take a look at it myself in the coming days.

[PaulSchweizer]

No worries, I'll add that later today

[PaulSchweizer]

It's changed

[mottosso]

Thanks, great work!

[tokejepsen]

Awesome stuff @PaulSchweizer !

[mkolar]

I completely missed this happening.

Yeah, this will work for us as well in our pyblish lite. The result should be exactly what we were after in #347.

Nice job.