Publisher: Do not log to console #877

iLLiCiTiT · 2024-09-10T08:50:08Z

Changelog Description

Preflight PR to disable logging to console in Publish UI.

Additional info

Disable propagation of pyblish plugin logs to root logger handlers. Add custom logging handler that is added to plugin logger and to root logger for process time, which is remove afterwards.

With current modifications it also captures all logs in root logger, not sure if that happened before too, but I like it.

Question

How to give option to change the behavior now? Some settings checkbox?

Testing notes:

Publishing in Publisher does not log plugin logs to console.
Logs are visible in report viewer.

Resolves #740

client/ayon_core/tools/publisher/models/publish.py

BigRoy · 2024-09-10T09:12:39Z

With current modifications it also captures all logs in root logger, not sure if that happened before too, but I like it.

It did actually, it captured all output. I think it was just getting everything from the root logger.

Is there any way we can set the logger just on start and end of the publish iterator instead of per plug-in?

We could have a constant on the UI controller like:

control_loggers = {"pyblish"}

So that we can just do on publisher UI start:

for name in control_loggers:
    logger = logging.getLogger(name)
    logger.propagate = False
    logger.addHandler(ui_handler)
# Add root handler
logging.getLogger().addHandler(ui_handler)

And then when the publishing UI stops we do:

for name in control_loggers:
    logger = logging.getLogger(name)
    logger.propagate = True
    logger.removeHandler(ui_handler)
# Remove root handler
logging.getLogger().removeHandler(ui_handler)

That would also make it much easier to expand it to capturing more logs explicitly, like ayon logs, etc.

It would be extra awesome if somehow we could ALSO capture the output of "resetting" the publisher so that e.g. this:

DEBUG:pyblish.CollectLocalRenderInstances:Plugin CollectLocalRenderInstances - Attr: use_deadline_aov_filter -> False
DEBUG:pyblish.CollectLocalRenderInstances:Plugin CollectLocalRenderInstances - Attr: aov_filter -> {'host_name': 'houdini', 'value': ['.*([Bb]eauty).*']}
DEBUG:pyblish.ValidateReviewColorspace:Plugin ValidateReviewColorspace - Attr: enabled -> True
DEBUG:pyblish.ValidateReviewColorspace:Plugin ValidateReviewColorspace - Attr: optional -> True
DEBUG:pyblish.ValidateReviewColorspace:Plugin ValidateReviewColorspace - Attr: active -> True
>>> [ *** Discovered 1 abstract plugins
- AutoCreator ]

Would become part of the UI logs as well.

iLLiCiTiT · 2024-09-10T09:18:35Z

It did actually, it captured all output. I think it was just getting everything from the root logger.

Yep, isn't that better? 🙂

Is there any way we can set the logger just on start and end of the publish iterator instead of per plug-in?

Technically yes, but it would be much harder to maintain it. It could start capture logs out of publishing logic unrelated to publish plugins.

It would be extra awesome if somehow we could ALSO capture the output of "resetting" the publisher so that e.g. this:

That happens out of publish plugins. In other words, outof scope of this PR as that is feature request.

…console

kalisp · 2024-09-12T15:16:59Z

I think this breaks publishing in Maya:

DEBUG: *** AYON addons initialization.
DEBUG: Executing [GET] settings?variant=test_dependency_bundle-deadline-06&bundle_name=test_dependency_bundle-deadline-06&site_id=greedy-earwig-of-perception
DEBUG: http://localhost:5000 "GET /api/settings?variant=test_dependency_bundle-deadline-06&bundle_name=test_dependency_bundle-deadline-06&site_id=greedy-earwig-of-perception HTTP/1.1" 200 123614
ERROR: Traceback (most recent call last):
  File "C:\Users\petrk\AppData\Local\Ynput\AYON\dependency_packages\ayon_2409121639_windows.zip\dependencies\pyblish\plugin.py", line 528, in __explicit_process
    runner(*args)
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\plugins\publish\collect_addons.py", line 15, in process
    manager = AddonsManager()
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\addon\base.py", line 809, in __init__
    self.initialize_addons()
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\addon\base.py", line 890, in initialize_addons
    settings = get_studio_settings()
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\settings\lib.py", line 142, in get_studio_settings
    return _AyonSettingsCache.get_value_by_project(None)
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\settings\lib.py", line 83, in get_value_by_project
    value = ayon_api.get_addons_settings(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\_api.py", line 1999, in get_addons_settings
    return con.get_addons_settings(*args, **kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 3577, in get_addons_settings
    return self.get_addons_studio_settings(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 3461, in get_addons_studio_settings
    output = self.get_bundle_settings(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 3425, in get_bundle_settings
    response = self.get("settings{}".format(query))
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 1361, in get
    return self.raw_get(entrypoint, params=kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 1335, in raw_get
    return self._do_rest_request(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\ayon_api\server_api.py", line 1243, in _do_rest_request
    response = function(url, **kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\requests\sessions.py", line 602, in get
    return self.request("GET", url, **kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\requests\sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\requests\sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\requests\adapters.py", line 486, in send
    resp = conn.urlopen(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\urllib3\connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
  File "C:\Users\petrk\Documents\ayon\ayon-launcher\.venv\lib\site-packages\urllib3\connectionpool.py", line 473, in _make_request
    log.debug(
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 1465, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 1624, in _log
    self.handle(record)
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 1634, in handle
    self.callHandlers(record)
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 1696, in callHandlers
    hdlr.handle(record)
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 968, in handle
    self.emit(record)
  File "C:\Users\petrk\Documents\ayon\ayon-core\client\ayon_core\pipeline\context_tools.py", line 135, in modified_emit
    record.msg = record.getMessage()
  File "C:\Program Files\Autodesk\Maya2024\Python\lib\logging\__init__.py", line 368, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting

iLLiCiTiT · 2024-09-16T17:06:03Z

I think this breaks publishing in Maya:

Should be fixed.

…console

client/ayon_core/tools/publisher/models/publish.py

iLLiCiTiT · 2024-09-30T14:58:31Z

Now the question is how to allow to enable/disable logging to console.

From my point of view logging from plugins to console should be disabled by default in publisher UI, but for development it might be helpful to have it enabled.

Suggestion: Add settings button to top right of publisher window with menu and actions? That could be also place for debuger tool. With that it is kinda hidden from artists and does not require restart of DCC to change behavior.

MustafaJafar

This works on my side. publishing is much faster now.

Now the question is how to allow to enable/disable logging to console.

IMO, we can jsut depend on an environment variable that users/developers can set in their session.

BigRoy · 2024-10-03T12:35:39Z

IMO, we can jsut depend on an environment variable that users/developers can set in their session.

I agree, a documented environment variable should suffice for now. AYON_PUBLISHER_PRINT_LOGS or whatever.

…console # Conflicts: # client/ayon_core/tools/publisher/models/publish.py

iLLiCiTiT · 2024-10-03T13:53:06Z

Crap, I've merged it... AYON_PUBLISHER_PRINT_LOGS is used, but not documented.

NOTE:
Where it should be documented?

BigRoy · 2024-10-03T14:14:15Z

I'd say somewhere in ayon-documentation. So merged is fine - up in @MustafaJafar 's hands now for documenting? :)

AYON_PUBLISHER_PRINT_LOGS can be 1 or 0 - and defaults to off when not set. See here.

MustafaJafar · 2024-10-03T14:46:40Z

I'd say somewhere in ayon-documentation. So merged is fine - up in @MustafaJafar 's hands now for documenting? :)

This is awesome. Let's create a GH issue for it so that we don't forget about it, and I'm going to pick it up as as I get my hands free.

do not log into console during publishing

2a2b956

ynbot added type: enhancement Improvement of existing functionality or minor addition size/XS labels Sep 10, 2024

BigRoy reviewed Sep 10, 2024

View reviewed changes

client/ayon_core/tools/publisher/models/publish.py Outdated Show resolved Hide resolved

iLLiCiTiT added 2 commits September 10, 2024 11:03

move propagate to publish iterator

6099d4a

calculate message at the time of emit

4c809f9

Merge branch 'develop' into enhancement/publisher-ui-does-not-log-to-…

84b513f

…console

call getMessage in try block

f5c26e3

Merge branch 'develop' into enhancement/publisher-ui-does-not-log-to-…

717e370

…console

BigRoy reviewed Sep 16, 2024

View reviewed changes

client/ayon_core/tools/publisher/models/publish.py Outdated Show resolved Hide resolved

use single object of handler

57266dc

MustafaJafar self-requested a review September 27, 2024 15:54

mkolar assigned iLLiCiTiT Sep 30, 2024

MustafaJafar approved these changes Oct 3, 2024

View reviewed changes

iLLiCiTiT added 2 commits October 3, 2024 15:27

Merge branch 'develop' into enhancement/publisher-ui-does-not-log-to-…

8923dfa

…console # Conflicts: # client/ayon_core/tools/publisher/models/publish.py

print logs based on env variable

c315c96

iLLiCiTiT merged commit 74da1ce into develop Oct 3, 2024
1 check passed

iLLiCiTiT deleted the enhancement/publisher-ui-does-not-log-to-console branch October 3, 2024 13:52

This was referenced Oct 3, 2024

Publish Validation Errors show traceback in artist facing reports #937

Closed

Fusion: OpenPype Logging Handler always logs red errors messages ynput/ayon-fusion#5

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Publisher: Do not log to console #877

Publisher: Do not log to console #877

iLLiCiTiT commented Sep 10, 2024 •

edited

Loading

BigRoy commented Sep 10, 2024 •

edited

Loading

iLLiCiTiT commented Sep 10, 2024 •

edited

Loading

kalisp commented Sep 12, 2024 •

edited

Loading

iLLiCiTiT commented Sep 16, 2024

iLLiCiTiT commented Sep 30, 2024 •

edited

Loading

MustafaJafar left a comment

BigRoy commented Oct 3, 2024

iLLiCiTiT commented Oct 3, 2024 •

edited

Loading

BigRoy commented Oct 3, 2024 •

edited

Loading

MustafaJafar commented Oct 3, 2024

Publisher: Do not log to console #877

Publisher: Do not log to console #877

Conversation

iLLiCiTiT commented Sep 10, 2024 • edited Loading

Changelog Description

Additional info

Question

Testing notes:

BigRoy commented Sep 10, 2024 • edited Loading

iLLiCiTiT commented Sep 10, 2024 • edited Loading

kalisp commented Sep 12, 2024 • edited Loading

iLLiCiTiT commented Sep 16, 2024

iLLiCiTiT commented Sep 30, 2024 • edited Loading

MustafaJafar left a comment

Choose a reason for hiding this comment

BigRoy commented Oct 3, 2024

iLLiCiTiT commented Oct 3, 2024 • edited Loading

BigRoy commented Oct 3, 2024 • edited Loading

MustafaJafar commented Oct 3, 2024

iLLiCiTiT commented Sep 10, 2024 •

edited

Loading

BigRoy commented Sep 10, 2024 •

edited

Loading

iLLiCiTiT commented Sep 10, 2024 •

edited

Loading

kalisp commented Sep 12, 2024 •

edited

Loading

iLLiCiTiT commented Sep 30, 2024 •

edited

Loading

iLLiCiTiT commented Oct 3, 2024 •

edited

Loading

BigRoy commented Oct 3, 2024 •

edited

Loading