pyblish silent fail confusing

[hannesdelbeke]

when a plugin module fails criteria during the discovery phase, it fails silently resulting in confusing the developer.
is this the best way to handle this, or can we add a log error to the log.

[hannesdelbeke]

more indepth example:

for plugins, any importing is usually done inside the process method for dcc specific code, so QML can access the plugins outside the dcc and wont crash when pymel is not found
example:
import pymel.core as pm

but if you want to import an action in a plugin, instead of hardcoding the action in your plugin module.
then we have to import at the top of the file.
If this import fails, the plugin discovery will fail silently and the plugin wont show. leaving the user guessing what happened.

example
PATH = C:\my_folder\

plugins live in
C:\my_folder\pyblish_plugins

let's say we have the files (+ any init needed)
C:\my_folder\pyblish_plugins\plugin.py
C:\my_folder\pyblish_plugins\action.py

when we import the action in the plugin
import action will fail
but import pyblish_plugins.action will succeed
this makes sense since pyblish is not an environment manager, and we never added the pyblish_plugins folder to the path.
however pyblish is able to import the plugin, which is in the same folder, because we registered the folder
pyblish.api.register_plugin_path(r"C:\my_folder\pyblish_plugins")

this results in a quite confusing case where pyblish silently fails, and it is quite tricky to debug why it fails.
when enabling DEBUG log pyblish logs "module action not found"
but action is in the same folder as plugin, which is found.
only after thoroughly investigating how it all hooks up can you find out why this happens.

i'm not sure if there is a good solution for this.
i can get around it and change the import in the plugin.
but any issues with a broken module for any other reasons wont be feedbacked to the user

[mottosso]

Agreed, this has been a problem since day one. The problem has been where to make the error visible, as it isn't something the end-user can do anything with. So it's a developer-only error, which means we shouldn't display it in any GUI but could display in a terminal or e.g. Maya's Output Window. That said, having it more visible - even to users - wouldn't be the end of the world either.

If you have any ideas, I'd be happy to consider them.

[hannesdelbeke]

when any tool or script in maya crashes it just errors out in the console (script editor, not output window)
i know it's a dev thing, but ideally you don't release broken code.
and hiding the plugin makes it more likely you'll release broken code

ex.
enduser doesnt care if a plugin load was skipped because it's a private one started with _
so we shouldn't tell them about that. this is just DEBUG log info.
but if a plugin fails to load because the code is broken, an error should be displayed IMO

[mottosso]

Your intuition aligns with mine, would be happy to consider changing this aspect of error reporting. For a start, if you are able to make it easy for me to digest and understand the changes (my time is very limited at this very moment due to Ragdoll) then if all goes well I'd also be happy to consider giving you the "keys to the castle" as it were, such that you can make changes more rapidly without me picking on each new line.

[hannesdelbeke]

It be great to get your feedback on the following.
Tested this setup for a while, and it helps a lot with "why is my plugin not showing" / silent fail.

log.debug

Most cases of silent plugin fail happen during discover.
It can be unclear what is happening, and why a plugin doesn't load.

Currently some steps aren't logged, resulting in silently skipping a plugin.
with the proposed PR, it's clear why the plugin doesn't load.

example:
A plugin does not load due to no compatible host.
This confuses the user, who wonders why their perfectly fine plugin doesn't load.

the user enables debug log in the console with

import logging
logging.getLogger("pyblish").setLevel(logging.DEBUG)

Before nothing informative would show, now we see plugin load is skipped due to no compatible host

// pyblish.plugin : missing hosts: ['maya'] // 
// pyblish.plugin : No supported host found for plugin:<class 'pyblish_wrapper.validate_main_function'> // 

log.debug handles expected behaviour. plugin is not loaded due to no compatible host. pyblish works as intended.
TODO:

• merge in suggested PR
• Make developer more aware of the debug log levels in pyblish docs. atm it's a bit hidden in the docs: logging

Exception

Currently, when a plugin doesn't load due to ex. a compile error, it logs as debug.
When a user is not aware of the debug log, it appears pyblish does not load the plugin despite no compile errors in the console.
To make it more intuitive, compile errors can be logged as an error.
Instead of a silent fail. it now displays in the console, even when not in debug mode.

TODO:

• merge in suggested PR

example:

// Error: pyblish.plugin : Skipped: "pyblish_wrapper" (No module named check_core.check_functions) // 

other

there are still rare cases of silent fails, I've noticed that putting reload in your module can trigger a silent fail with no exceptions.
This is likely not just a UX issue but related to how pyblish handles plugin loading / env variables. moving this to a sep thread

[hannesdelbeke]

closing this since PR went in :)

[hannesdelbeke]

actually reopening this since we need to write documentation regarding the debug logging.
Errors in plugins are now easy to see on sight, which solves most of this.
But silent non loading occasions due to a poor config. mispelled path etc are still possible