Tk-desktop console silently ignoring errors

So I’m developing a toolkit app and things have been going pretty well. But, I hit a road block every time I have an error in my app settings or code. tk-desktop is silently ignoring all the exceptions my app raises during initialization even though I have the “Toggle debug logging” checkbox on. The only way I know there is an issue is when my registered commands don’t show up after loading the config for a project.

I ended up having to write a couple of scripts to manually initialize my app by extracting the relevant code from sgtk.platform.engine.__load_app and just leaving out all the try except blocks.

I was wondering if I’m missing something or if this is an actual bug. Anyone run into this before?

On the topic of testing, how are people going about testing apps? I see that sgtk has some helper classes for unit testing but I haven’t down that path yet. I’d love to hear about any workflows that people find helpful for developing apps!

1 Like

Hi Dan,

I can’t say I’m an expert in developing for toolkit and I’m pretty sure I do many things wrong still, but I’ve hit the problems you describe.

When debugging the app in tk-desktop engine, I rely heavily on the file log. The console says it will switch to the file based logging at the point it starts loading toolkit apps:

2020-05-08 02:34:01,799 [   DEBUG] [PROXY] Project-level tk-desktop engine will now switch back to file based logging.
2020-05-08 02:34:01,819 [   DEBUG] [PROXY] Switching file based std logger from 'None' to 'C:\Users\<username>\AppData\Roaming\Shotgun\Logs\tk-desktop.log'.

I don’t know if it is possible to disable this “switching” but since this file containts an extreme amount of debug data, I wouldn’t even like that. It’s preferable for me to simply tail it when I need to.

Also, one method to ensure as much information as possible when app fails to load is to catch the error in init_app method of your Application class. tk-multi-starterapp shows how to load the app module and register command but I always enclose these two methods in try/except block and use traceback module just to be sure.

Here’s how it usually looks like in the apps I’ve created:

import os
import traceback

from sgtk.platform import Application

APP_NAME = os.path.basename(os.path.dirname(os.path.abspath(__file__)))


class MyCustomToolkitApp(Application):
    """
    The app entry point. This class is responsible for initializing and tearing down
    the application, handle menu registration etc.
    """

    def init_app(self):
        """
        Called as the application is being initialized
        """

        self.log_debug("Initializing {}".format(APP_NAME))

        # first, we use the special import_module command to access the app module
        # that resides inside the python folder in the app. This is where the actual UI
        # and business logic of the app is kept. By using the import_module command,
        # toolkit's code reload mechanism will work properly.
        try:
            self.app_payload = self.import_module("app")
        except Exception as err:
            self.log_warning("Could not import module!")
            self.log_error(err.message)
            self.log_error(traceback.format_exc())

        display_name = self.get_setting("display_name")
        menu_caption = display_name

        # register command
        def menu_callback(): return self.app_payload.show_dialog(self)

        # now register the command with the engine
        try:
            self.engine.register_command(menu_caption, menu_callback)
        except Exception as err:
            self.log_warning("Could not register command!")
            self.log_error(err.message)
            self.log_error(traceback.format_exc())

Additionally, I made a simple tool to restart the engine and reload everything (as I’ve figured that template.yml is not being reloaded by shotgun provided “Reload and Restart” command) and run on a click of a (automatically generated) button for every app:
2020-05-08_02-02-14
This just saves me from writing the same restart code every time.

I’d love to hear other peoples experience though. Particularly on the topic of testing…

Cheers,
Aleksandar

5 Likes

Hey Aleksandar,

I missed that message about it switching to file logging. At a bare minimum I expected errors and exceptions to be logged to the console. I guess since each app has access to a logger, it should be possible to modify the handler that’s printing to the console and make sure that errors and exceptions are printed too. For now I’ll probably end up tailing the log file as you suggested!

That “reload and restart” button seems really useful, nice one.

Thanks a lot,
Dan

2 Likes

After taking another look at this, I believe tk-desktop app, in many cases, is simply quietly ignoring unhandled exceptions. The log file we discussed appears to contain the same logging info as the python console for me.

1 Like

Hi @Dan_Bradham they should in theory be logged. I in fact fixed this reasonably recently: https://github.com/shotgunsoftware/tk-desktop/wiki/Release-Notes#v2413

Are you running that version of tk-desktop or newer?
If you are, perhaps the bug has crept in again, or there is a situation we’ve not handled.
It would be good to get an idea of how your app errored so we can replicate a similar scenario here.
best
Phil

1 Like

Hi @philip.scadding, I am also seeing errors in Toolkit Apps that will cause the App to fail and crash but not getting anything logged to the output, even with advanced debugging enabled. The errors range in Python syntax errors as well as unable to download thumbnails in SG. I am using the tk-config-basic setup, not sure if that has anything to do with TK versions. But this is my current version setup:

Screen Shot 2020-05-11 at 8.38.21 AM

2 Likes

Hi @philip.scadding,

I’m using v2.4.14, I’ll upgrade to the latest release and see if it solves the problem.

2 Likes

@mharris I was able to replicate the issue here briefly (though I wasn’t initially using a released version, I was pointing at a certain commit), but then after switching engine versions around I couldn’t end back up in a broken state again. It did work for me though using the latest version of the tk-desktop engine v2.5.3 on the site and project configs. Please could you try updating and seeing if that fixes it?

1 Like

@philip.scadding, how do I go about updating the engine? I downloaded and installed the latest desktop app from the Apps pulldown on our site. But, it is still giving me v2.5.0.

2 Likes

It’s controlled via your site config. Do you have a PipelineConfiguration entity that has no Project assigned? If so then you will need to update that config.

1 Like

This threw me for a moment - I updated to v2.5.3 in my config and it didn’t update the About dialog until I restarted the desktop app entirely. I think you can open the python console and use the engine instance to get a more accurate view that’s dependent on your active config.

I haven’t run into the issue since upgrading, but, I also reached a relatively stable point in the development of my app. I’ll report back later this week.

2 Likes

@philip.scadding, I am using a local dev descriptor with the latest tk-config-basic which I cloned a fresh copy. That is still pointing to Engine v2.5.0, according to @mathurf’s release notes for Shotgun Basic Configuration v1.3.6 from 2 weeks ago. The Abount window still shows Engine v2.5.0. However, I see in the env/common/engines.yml file that the Desktop is pointing to what looks to be v2.5.3.

# Desktop
common.engines.tk-desktop.location:
  type: app_store
  name: tk-desktop
  version: v2.5.3
1 Like

The latest tk-config-basic release is v1.3.7 pointing to:

We reverted back the desktop engine due to a regression found, which has been fixed but we don’t have a new config release yet.

Either way, it sounds like you’ve set the version in the correct place in your config, but perhaps in the wrong config? it doesn’t sound like SG Desktop is using your config. I had a look at your SG site, and it looks like you have 5 different site configs, and it looks to me like the one with id 42 will be picked, which is pointing at a git descriptor.

1 Like

@philip.scadding, strange, I did a git clone of the tk-config-basic and then downloaded the zip source zip file from build v1.3.7 and they were not the same:

diff --git a.../engines.yml b.../engines.yml
old mode 100644
new mode 100755
index f6ddabb..bfa5d64
--- a.../engines.yml
+++ b.../engines.yml        
@@ -69,19 +69,19 @@ common.engines.tk-alias.location:
 common.engines.tk-vred.location:
   type: app_store
   name: tk-vred
-  version: v2.0.6
+  version: v2.0.5
 
 # Desktop
 common.engines.tk-desktop.location:
   type: app_store
   name: tk-desktop
-  version: v2.5.3
+  version: v2.4.14
 
 # Desktop2
 common.engines.tk-desktop2.location:
   type: app_store
   name: tk-desktop2
-  version: v1.4.0
+  version: v1.3.1
 
 # Shell
 common.engines.tk-shell.location:

Engine a is the clone, engine b is the source zip contents.

The local dev descriptor config I am testing with on our site is Id 216.

I checked your site again, but I think you will be using id 42 for the site config. The order it picks the configs in is described here.

@philip.scadding, I manage which config I am using to test/work by selecting it manually:

I only get Id 42 if I select “Dev (site)” from the option list.

Sorry for the confusion here, it is a bit confusing if you’re not aware of the inner workings of SG Desktop.

The list you are seeing there determines what config to use for that project. So selecting a config in that list will mean that any of those actions/apps you run will run with that project config.

However, the key thing to know, is that SG Desktop when it starts, bootstraps the site config (based on the order I linked). This controls how Shotgun Desktop behaves when you have not selected a project.

When you select/enter a project in the SG Desktop UI, it is actually spawning off a separate python process and bootstrapping the project config, (which may well be the site config, if there isn’t a project specific config.) This spawned bootstrapped process, then communicates back to the main SG Desktop process in order to update the UI.

All of this is to say, that you can pick the project config via the UI as you have done, but that only affects project actions. You can’t pick the SG Desktop site level config like that, and the details you get in the about box come from the config that SG Desktop bootstrapped at a non project level. So you need to make sure that both configs have the correct tk-desktop engine.
I hope that makes sense?

@philip.scadding, OK, that makes sense as to why no matter what I do I always see v2.5.0. That is what the Ids 2 and 42 are pointing at. I can update these to pull the correct versions. But, that leads back to which version, since the current git clone and v1.3.7 are different. Which one is correct and should I be using to validate that Python is catching errors when running a Toolkit App?

I’m not sure what you mean by git clone? The master branch and v1.3.7 are different if thats what you are referring to?
When pulling changes for the configs, I would always take from the releases.

Essentially we create releases for components such as tk-desktop or tk-multi-publish2, and we test those and then approve those releases for general consumption in our internal app store.

We then at a slightly slower cadence create new releases for the config’s that point to the latest component releases. So a component might be released such as tk-desktop v2.5.3, but not yet included in our latest config release.

In short, any component versions referenced in our config should be fine to use.

It isn’t as easy to see whether an individual component release is approved for use. This is because we create Github releases for them, before actually “releasing” them. And this is because historically you would run the tank updates command which would check with the internal app store to see if there is a newer version.
Configs on the other hand we only create a Github final release once we are ready to release it.

Sorry that’s probably more info than you were asking for, and perhaps still doesn’t answer your question?

1 Like

That is OK, I understand what you are saying… When I want to get something from GitHub I typically run git clone <repo.git> on the command line. Which would pull the master branch. But, you are saying it’s better, when dealing with SG configs, to grab the latest/specific release zip file?

Which would be v1.3.7:

# VRED
common.engines.tk-vred.location:
  type: app_store
  name: tk-vred
  version: v2.0.5

# Desktop
common.engines.tk-desktop.location:
  type: app_store
  name: tk-desktop
  version: v2.4.14

# Desktop2
common.engines.tk-desktop2.location:
  type: app_store
  name: tk-desktop2
  version: v1.3.1
1 Like