Issues with Rendering on Deadline Ayon 3.16.5

Hello,

My company is looking to adopt Ayon as a pipeline and we’re currently in the discovery process. Initially, we were experimenting with Openpype before the change over to Ayon.

During that time, I was able to successfully render on Deadline utilizing the Openpype Deadline plugin.

Moving over to Ayon I am now encountering issues with rendering. When attempting I am getting this particular error:

Digging deeper and making some temporary modifications to the plugin to get a more verbose error I commented out that portion of code which vaguely describes that it couldn’t extract the environments. In doing so I started to get this error:

It looks like the tempfile.json isn’t being found. Looking at the code I am not sure if it is being written at all. It looks like the filename is being referenced, but it doesn’t seem like any environment variables are being written to the json which is represented by the variable export_url in the plugin under the inject_ayon_environment() method GlobalJobPreload.py:

I would love to hear some feedback as to what might be wrong, either from what I have done, or perhaps if there is an issue with the GlobalJobPreload.py

Thanks so much,

Hello,
It’s great to see you!

the issue you are facing is Injection Failed and we may investigate to find out why it fails.

because, ayon launches apps in an enhanced environment, we need to inject the new environments in the deadline job and this whatGlobalJobPreLoad does.


Have you managed to setup deadline for Ayon properly ?
quick recap:

  • Copy ayon plugin to deadline repo
  • Configure Ayon plugin in deadline monitor
  • Configure Deadline addon in Ayon server

This guide can help.

Since the Deadline job is running the GlobalJobPreLoad it looks like he’s got that configured correctly.

@mallow for the machine this is running on - does this path exist?

image

It should be writing to your “temporary files” directory but it might just be that the process is trying to write into a folder that does not exist (or the user does not have access to).

Do you happen to have Deadline configured to “run as user” or something other custom which might influence whether the machine can access a local temporary folder?

I believe Windows uses the TMP or TEMP environment variable to decide what the temporary folder should be that is used by python’s tempfile library. (But don’t pin me to it - I just recall that being the case so take it with a grain of salt.)

The library is likely expecting that the temporary files folder at least exists and can be written to.

Hi,

Thanks for the reply, and sorry for the late reply. We managed to get it working, however in order to do so, we made some changes to the GlobalJobPreload.py.

Changes:

  1. Since we’re running the Deadline worker with a Windows environment we needed to take into account the “\” that is used to represent the path.

  2. Also, just like I mentioned in the code snippet above, it doesn’t look like the .json represented by the export_url variable was being written to, so we wrote to that .json so it wouldn’t complain about not finding it.

  3. As well as commenting out the raise RuntimeError since for some reason regardless of the input the exitcode would always return a non-zero. (Still investigating as to why)

This allowed us to render successfully in Deadline. Perhaps this isn’t the most ideal solution but it got us there. Would love to hear your guys thoughts.

I’m glad you managed to solve the problem, it’ll be good if you have some time for further investigation because your issue is a little bit strange.

I think BigRoy’s comment above is a good start, as he mentioned
is that path exists ? has the machine user enough permissions to write in that path ?
which user does deadline uses when rendering ?

  • The path doesn’t exist until I wrote to it explicitly.
  • We have a “render” user which has enough permissions to write to the file (only until I added the ability to write to the tempfile)
  • The “render” user is what Deadline is using to render.

Question about the guide above. Unlike Openpype, it looks like it is indicating that the ASH add-on is required as a service for Deadline to work?

Sorry for inconvenience.
ASH is not required for Deadline to work, I meant Get Ayon API key part
I’ll update deadline guide.

No worries and thanks for the quick clarification! At least for the time being we’re able to get it to work. When I have some more time I will investigate further but for now thanks so much for the help and replies :slight_smile:

@mustafa_jafar @BigRoy
I would like to continue the discussion “Issues with Rendering on Deadline Ayon”, as I am working along with @mallow testing Ayon.
We have just tried the last Ayon version (server 0.5.2 and client 3.17.0) with the minimum configuration to test a Houdini Redshift ROP render in deadline, it is throwing the same error reported by Mallow.
Based on out previous test and this new one, we think the log reports two main issues, one is the missing json file that once is fixed we can still see in the log the following lines:

Executing: C:/Program Files/Ynput/AYON 1.0.0-beta.5/ayon_console.exe --headless extractenvironments C:\Users\autobot\AppData\Local\Temp\20231019202312225750_536bdb34-6ebd-11ee-b959-04421a0bd3de.json --project marz_pro_test --asset BR_1001_1010 --task Lighting --app houdini/19.0.455_Core --envgroup farm
STDOUT: !!! Cannot open v4 Loging dialog in headless mode
STDOUT: !!! Please use ‘AYON_SERVER_URL’ to specify server address and ‘AYON_API_KEY’ to specify user’s token

Which point to the correct setup of the server and key, we followed the steps Mustafa suggested above.
We understand the Deadline worker is trying to execute “ayon_console.exe”, so when we tried something simple execute it with --help flag and we got the following.


The “Unknown source url” is something we do not like :slight_smile:
We also try to run the following is where we see the same error as in Deadline.

So, just wonder what are we missing or if there is something missing in “ayon_console.exe”.
If there is something else you want me to add here to help debug/solve the issue, please let me know.
Thank you for your help in advance.

Looking at the error yet knowing close to nothing about AYON my suspicion would be that the issue is still this:

STDOUT: !!! Please use ‘AYON_SERVER_URL’ to specify server address and ‘AYON_API_KEY’ to specify user’s token

I suspect that you deadline submission itself would have special environment variables submitted along that represent those values: AYON_SERVER_URL and AYON_API_KEY or that you need to specify these somewhere in the Ayon Deadline Plugin. I believe the latter is the default configuration workflow for AYON.

I suspect you need to go to Deadline:

Which is basically Step 2 - Configure plugins from deadline menu Tools > Configure PLugins of the configuration described there where you can expand the Configure AYON plugin section. Which also explains the need for the Service User, generation of the API key, etc.

Admittedly, I missed that section at first too because it was collapsed and thus can be easy to overlook.

Hi @BigRoy , thank you for your prompt answer / info
No special env vars submitted or used in any way, as I said basic configuration in the server side just to make ayon to work with houdini along with Redshift under a shot, that is pretty much we did in the server side then we configured the ayon plugin for deadline.


yep, we tried to follow the guide, but still something missing I guess.

For debugging - could you try the ayon_console step one more time but before running set the env vars:

set AYON_SERVER_URL=SERVER_URL_HERE
set AYON_API_KEY=API_KEY_HERE
ayon_console.exe -- headless

Just to see what that outputs.

Sure, here it is the outcome after setting the env vars.

Does using the actual ayon app exe works ?
I believe the executable in beta folder calls this one implicitly

~\AppData\Local\Ynput\AYON\app\AYON 0.3.2\ayon_console.exe

@Brno That Clockify Settings error seems to be the culprit I think. :slight_smile:

Is that Module/Addon disabled?

@milan @mustafa_jafar I’ve seen many reports with that Clockify error. Is there a bug or are just that many people misconfiguring AYON on first setup?

OK, I have not disable it just yet I am trying the bare minimum changes so I can have the variables somehow contain.
but my experience with previous ayon server version is that I disabled it but the errors still throws during launch time of any DCC, so I added the addon and tried to configure.
I can try to disable it for this test and see what happens, let me try.

Looking at the error logs it does seem like it ‘continues’ and thus ignores the error and just logs it for Clockify. So it might be that it’s not blocking things either - it’s just polluting the logs I suppose.

However, that means that with the env vars set it does appear to launch ayon console fine - even though it does throw the errors. If that’s the case, then next question becomes why is the Deadline render not running correctly. For that’d likely need the Deadline Render log.

Yep, the clockify is now gone and it continues with the rest of the log.


Give a minute I can get you the Deadline log.

@BigRoy here you have it.

=======================================================
Error
=======================================================
Error: Global job preload script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py': RuntimeError : Failed to run Ayon process to extract environments. (FranticX.Scripting.PythonNetException)
  File "C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py", line 609, in __main__
    inject_ayon_environment(deadlinePlugin)
  File "C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py", line 502, in inject_ayon_environment
    "Failed to run Ayon process to extract environments."
   at Python.Runtime.PyObject.Invoke(PyObject[] args)
   at Python.Runtime.PyObject.InvokeMethod(String name, PyObject[] args)
   at FranticX.Scripting.PythonNetScriptEngine.CallFunction(String moduleName, String functionName, Object[] args)
   at Deadline.Plugins.PluginWrapper.d()
   at Deadline.Plugins.PluginWrapper.StartJob(String& outMessage, AbortLevel& abortLevel)

=======================================================
Type
=======================================================
RenderPluginException

=======================================================
Stack Trace
=======================================================
   at Deadline.Plugins.SandboxedPlugin.d(DeadlineMessage bgj, CancellationToken bgk)
   at Deadline.Plugins.SandboxedPlugin.StartJob(Job job, CancellationToken cancellationToken)
   at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ajq, CancellationToken ajr)

=======================================================
Log
=======================================================
2023-10-19 16:23:09:  0: Render Thread - Render State transition from = 'ReceivedTask' to = 'Other'
2023-10-19 16:23:09:  0: Plugin will be reloaded because a new job has been loaded.
2023-10-19 16:23:09:  0: Loading Job's Plugin timeout is Disabled
2023-10-19 16:23:09:  0: SandboxedPlugin: Render Job As User disabled, running as current user 'autobot'
2023-10-19 16:23:11:  0: Loaded plugin Houdini
2023-10-19 16:23:11:  0: Executing plugin command of type 'Initialize Plugin'
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: debug logging enabled
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: m_pluginParamFilename = 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\Houdini.param'
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: m_pluginScriptFilename = 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\Houdini.py'
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: m_pluginPreLoadFilename = 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\PluginPreLoad.py'
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: m_jobPreLoadFilename = 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\JobPreLoad.py'
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Checking for Plugin Pre-Load
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Loading Plugin...
2023-10-19 16:23:11:  0: INFO: Executing plugin script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\Houdini.py'
2023-10-19 16:23:11:  0: INFO: Plugin execution sandbox using Python version 3
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: getting job user
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: setting job filenames
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Obtaining Deadline plugin object
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Setting internal variables and delegates
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Preparing Environment Variables
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Obtaining network settings
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: Initializing Deadline plugin
2023-10-19 16:23:11:  0: DEBUG: This is a simple plugin job.
2023-10-19 16:23:11:  0: INFO: About: Houdini Plugin for Deadline
2023-10-19 16:23:11:  0: INFO: The job's environment will be merged with the current environment before rendering
2023-10-19 16:23:11:  0: DEBUG: InitializePlugin: returning
2023-10-19 16:23:11:  0: Done executing plugin command of type 'Initialize Plugin'
2023-10-19 16:23:11:  0: Start Job timeout is disabled.
2023-10-19 16:23:11:  0: Task timeout is disabled.
2023-10-19 16:23:11:  0: Loaded job: mpt_BR_1001_1010_Lighting_v001_test.hip - redshift_ropTest (6531902782293632241930b3)
2023-10-19 16:23:11:  0: Skipping P: because it is already mapped
2023-10-19 16:23:11:  0: Skipping R: because it is already mapped
2023-10-19 16:23:11:  0: Skipping S: because it is already mapped
2023-10-19 16:23:11:  0: Skipping T: because it is already mapped
2023-10-19 16:23:11:  0: Error mapping J: to \\bigfoot\editing: The operation being requested was not performed because the user has not been authenticated.
2023-10-19 16:23:11:  0: Skipping K: because it is already mapped
2023-10-19 16:23:11:  0: Error mapping Z: to \\bigfoot\rez\: The operation being requested was not performed because the user has not been authenticated.
2023-10-19 16:23:11:  0: Skipping V: because it is already mapped
2023-10-19 16:23:11:  0: Skipping Q: because it is already mapped
2023-10-19 16:23:12:  0: Executing plugin command of type 'Start Job'
2023-10-19 16:23:12:  0: DEBUG: StartJob: called
2023-10-19 16:23:12:  0: DEBUG: StartJob: Checking for Job Pre-Load
2023-10-19 16:23:12:  0: DEBUG: S3BackedCache Client is not installed.
2023-10-19 16:23:12:  0: DEBUG: GlobalAssetTransferPreLoadJob: called
2023-10-19 16:23:12:  0: INFO: Executing global asset transfer preload script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalAssetTransferPreLoad.py'
2023-10-19 16:23:12:  0: INFO: Looking for legacy (pre-10.0.26) AWS Portal File Transfer...
2023-10-19 16:23:12:  0: INFO: Looking for legacy (pre-10.0.26) File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...
2023-10-19 16:23:12:  0: INFO: Could not find legacy (pre-10.0.26) AWS Portal File Transfer.
2023-10-19 16:23:12:  0: INFO: Legacy (pre-10.0.26) AWS Portal File Transfer is not installed on the system.
2023-10-19 16:23:12:  0: DEBUG: GlobalAssetTransferPreLoadJob: returning
2023-10-19 16:23:12:  0: DEBUG: GlobalPreLoadJob: called
2023-10-19 16:23:12:  0: INFO: Executing global job preload script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py'
2023-10-19 16:23:12:  0: PYTHON: *** GlobalJobPreload start ...
2023-10-19 16:23:12:  0: PYTHON: >>> Getting job ...
2023-10-19 16:23:12:  0: PYTHON: >>> Injecting Ayon environments ...
2023-10-19 16:23:12:  0: PYTHON: --- Ayon executable: C:/Program Files/Ynput/AYON 1.0.0-beta.5/ayon_console.exe
2023-10-19 16:23:12:  0: PYTHON: >>> Temporary path: C:\Users\autobot\AppData\Local\Temp\20231019202312225750_536bdb34-6ebd-11ee-b959-04421a0bd3de.json
2023-10-19 16:23:12:  0: PYTHON: >>> Executing: C:/Program Files/Ynput/AYON 1.0.0-beta.5/ayon_console.exe --headless extractenvironments C:\Users\autobot\AppData\Local\Temp\20231019202312225750_536bdb34-6ebd-11ee-b959-04421a0bd3de.json --project marz_pro_test --asset BR_1001_1010 --task Lighting --app houdini/19.0.455_Core --envgroup farm
2023-10-19 16:23:13:  0: STDOUT: !!! Cannot open v4 Login dialog in headless mode.
2023-10-19 16:23:13:  0: STDOUT: !!! Please use `AYON_SERVER_URL` to specify server address and 'AYON_API_KEY' to specify user's token.
2023-10-19 16:23:13:  0: PYTHON: Traceback (most recent call last):
2023-10-19 16:23:13:  0: PYTHON:   File "C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py", line 502, in inject_ayon_environment
2023-10-19 16:23:13:  0: PYTHON:     "Failed to run Ayon process to extract environments."
2023-10-19 16:23:13:  0: PYTHON: RuntimeError: Failed to run Ayon process to extract environments.
2023-10-19 16:23:13:  0: PYTHON: !!! Injection failed.
2023-10-19 16:23:13:  0: DEBUG: Exception in StartJob: Global job preload script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py': RuntimeError : Failed to run Ayon process to extract environments. (FranticX.Scripting.PythonNetException)
2023-10-19 16:23:13:  0:   File "C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py", line 609, in __main__
2023-10-19 16:23:13:  0:     inject_ayon_environment(deadlinePlugin)
2023-10-19 16:23:13:  0:   File "C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py", line 502, in inject_ayon_environment
2023-10-19 16:23:13:  0:     "Failed to run Ayon process to extract environments."
2023-10-19 16:23:13:  0:    at Python.Runtime.PyObject.Invoke(PyObject[] args)
2023-10-19 16:23:13:  0:    at Python.Runtime.PyObject.InvokeMethod(String name, PyObject[] args)
2023-10-19 16:23:13:  0:    at FranticX.Scripting.PythonNetScriptEngine.CallFunction(String moduleName, String functionName, Object[] args)
2023-10-19 16:23:13:  0: Done executing plugin command of type 'Start Job'

=======================================================
Details
=======================================================
Date: 10/19/2023 16:23:17
Frames: 1001-1002
Elapsed Time: 00:00:00:08
Job Submit Date: 10/19/2023 16:23:03
Job User: bortega
Average RAM Usage: 8302317056 (7%)
Peak RAM Usage: 8302317568 (7%)
Average CPU Usage: 4%
Peak CPU Usage: 11%
Used CPU Clocks (x10^6 cycles): 15146
Total CPU Clocks (x10^6 cycles): 378628

=======================================================
Worker Information
=======================================================
Worker Name: MIF-TECH000
Version: v10.1.23.6 Release (773a6289d)
Operating System: Windows 10 Pro
Running As Service: Yes
Machine User: autobot
IP Address: 10.235.130.36
MAC Address: 04:42:1A:0B:D3:DE
CPU Architecture: x64
CPUs: 28
CPU Usage: 4%
Memory Usage: 7.7 GB / 127.7 GB (6%)
Free Disk Space: 1.170 TB (268.609 GB on C:\, 929.440 GB on D:\)
Video Card: NVIDIA RTX A4000

Thank you - the issue seems to be that it definitely does not recognize the Ayon Server URL and Ayon API Key even though the GlobalJobPreLoad tries to set it for the environment here.

Let’s debug!

  1. For sake of being sure - can you double check your GlobalJobPreLoad in the Deadline repository is exactly like latest develop version? To ensure it’s not an issue from just an outdated GlobalJobPreLoad.py?
  2. If that’s the case, to improve the debugging lets log what the values are that are being set. Here in GlobalJobPreLoad add:
            print(f"Setting {env}={val}")
  1. If all are being set correctly as you expect the values should be I think maybe there’s a bug on how the values are set and propagate to the deadlinePlugin.RunProcess() call that runs the --extractenvironment call. Looking at the GlobalJobPreLoad OpenPype logic it explicitly mentions requiring its OPENPYPE_MONGO var in os.environ otherwise the run process won’t work - which might hint that we should be enforcing something similar here.

I believe that for the deadlinePlugin.RunProcess to pick up the env var we should be using deadlinePlugin.SetProcessEnvironmentVariable instead of deadlinePlugin.SetEnvironmentVariable as their documentation states:

This DeadlinePlugin.SetProcessEnvironmentVariable should be differentiated with ManagedProcess.SetEnvironmentVariable which applies to the current Plugin. If using an advanced plugin, you will want to call this function instead of SetEnvironmentVariable, as you want the environment var to be set by managed processes started by this one. SetEnvironmentVariable sets environment for this managed process, once executed.

In this instance I believe we might want to actually run both since we want it to apply to the Deadline Render Job Plugin and anything that it runs, but also to the deadlinePlugin.RunProcess call we do now.

So I suspect the issue for you might go away if you here also add:

            deadlinePlugin.SetProcessEnvironmentVariable(env, val)

Why does this only happen to you?

I’m not sure.

I might also just be wrong with point 3 and there’s another bug (e.g. point 2). However it might very well be that others might have been testing deadline with their local machine instead of a farm machine that was not preconfigured for AYON with a server, user or api key predefined, or maybe others do have the AYON_API_KEY submitted along with the Deadline Job in its job.GetJobEnvironmentKeyValue() entries - and if so I believe it comes applied tot he GlobalJobPreLoad sandbox as well, and thus is in os.environ and thus DeadlinePlugin.RunProcess() call also has the environment variables as needed.


Local cached job scripts per Job

Note: That whenever you update the GlobalJobPreLoad that you might need to resubmit the Render Job because I’ve often hit the case that the render machine kept using the cached local files of that job, like the one in this render log:

2023-10-19 16:23:12:  0: INFO: Executing global job preload script 'C:\ProgramData\Thinkbox\Deadline10\workers\MIF-TECH000\plugins\6531902782293632241930b3\GlobalJobPreLoad.py'

If that’s the case - the easiest fix I’ve found was to just Resubmit Job on the existing job and remove the original job. The new one will have a new job id and not use any cached data.

image