Render failing with channel references (Houdini / Arnold / Deadline)

Hi all,
I am having a really fustrating issue submitting a houdini / arnold job to deadline.
It seems that having channel references in the output picture paramater seems to cause deadline to fail with a runtime exception. It seems isolated to the ar_picture (output path) paramater. I can use channel references in other parms. When I change the channel reference to a plain string path it all works, but we need reference a custom tool to create the output path. I have also tried using python instead but I get an “unexpandedString” error and deadline does not allow me to submit.

Has anyone had this type of thing before?

Houdini 19.5.305
htoa 6.1.3.1
deadline 10.1.23.6

example of chanel reference

This is the log from deadline when I use channel references
=======================================================
Error

FailRenderException : Error: Caught exception: The attempted operation failed.
at Deadline.Plugins.DeadlinePlugin.FailRender(String message) (Python.Runtime.PythonException)
File “C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\Houdini.py”, line 438, in HandleStdoutError
self.FailRender(self.GetRegexMatch(1))
at Python.Runtime.Dispatcher.Dispatch(ArrayList args)
at __FranticX_Processes_ManagedProcess_StdoutHandlerDelegateDispatcher.Invoke()
at FranticX.Processes.ManagedProcess.RegexHandlerCallback.CallFunction()
at FranticX.Processes.ManagedProcess.e(String di, Boolean dj)
at FranticX.Processes.ManagedProcess.Execute(Boolean waitForExit)
at Deadline.Plugins.DeadlinePlugin.DoRenderTasks()
at Deadline.Plugins.PluginWrapper.RenderTasks(Task task, String& outMessage, AbortLevel& abortLevel)
at Deadline.Plugins.PluginWrapper.RenderTasks(Task task, String& outMessage, AbortLevel& abortLevel)

=======================================================
Type

RenderPluginException

=======================================================
Stack Trace

at Deadline.Plugins.SandboxedPlugin.d(DeadlineMessage bgj, CancellationToken bgk)
at Deadline.Plugins.SandboxedPlugin.RenderTask(Task task, CancellationToken cancellationToken)
at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ajq, CancellationToken ajr)

=======================================================
Log

2022-08-23 16:25:47: 0: Loading Job’s Plugin timeout is Disabled
2022-08-23 16:25:47: 0: SandboxedPlugin: Render Job As User disabled, running as current user ‘roger’
2022-08-23 16:25:50: 0: Executing plugin command of type ‘Initialize Plugin’
2022-08-23 16:25:50: 0: INFO: Executing plugin script ‘C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\Houdini.py’
2022-08-23 16:25:51: 0: INFO: Plugin execution sandbox using Python version 3
2022-08-23 16:25:51: 0: INFO: About: Houdini Plugin for Deadline
2022-08-23 16:25:51: 0: INFO: The job’s environment will be merged with the current environment before rendering
2022-08-23 16:25:51: 0: Done executing plugin command of type ‘Initialize Plugin’
2022-08-23 16:25:51: 0: Start Job timeout is disabled.
2022-08-23 16:25:51: 0: Task timeout is disabled.
2022-08-23 16:25:51: 0: Loaded job: h19_5_test_v001 - /obj/ropnet1/pc_render_rop1/new_test (6304e1c3df8f3319bc8dc377)
2022-08-23 16:25:51: 0: Executing plugin command of type ‘Start Job’
2022-08-23 16:25:51: 0: DEBUG: S3BackedCache Client is not installed.
2022-08-23 16:25:51: 0: INFO: Executing global asset transfer preload script ‘C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\GlobalAssetTransferPreLoad.py’
2022-08-23 16:25:51: 0: INFO: Looking for legacy (pre-10.0.26) AWS Portal File Transfer…
2022-08-23 16:25:51: 0: INFO: Looking for legacy (pre-10.0.26) File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2022-08-23 16:25:51: 0: INFO: Could not find legacy (pre-10.0.26) AWS Portal File Transfer.
2022-08-23 16:25:51: 0: INFO: Legacy (pre-10.0.26) AWS Portal File Transfer is not installed on the system.
2022-08-23 16:25:51: 0: Done executing plugin command of type ‘Start Job’
2022-08-23 16:25:51: 0: Plugin rendering frame(s): 1001-1010
2022-08-23 16:25:51: 0: Executing plugin command of type ‘Render Task’
2022-08-23 16:25:51: 0: INFO: Starting Houdini Job
2022-08-23 16:25:51: 0: INFO: Stdout Redirection Enabled: True
2022-08-23 16:25:51: 0: INFO: Stdout Handling Enabled: True
2022-08-23 16:25:51: 0: INFO: Popup Handling Enabled: True
2022-08-23 16:25:51: 0: INFO: QT Popup Handling Enabled: False
2022-08-23 16:25:51: 0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2022-08-23 16:25:51: 0: INFO: Using Process Tree: True
2022-08-23 16:25:51: 0: INFO: Hiding DOS Window: True
2022-08-23 16:25:51: 0: INFO: Creating New Console: False
2022-08-23 16:25:51: 0: INFO: Running as user: roger
2022-08-23 16:25:51: 0: INFO: Enforcing 64 bit build
2022-08-23 16:25:51: 0: INFO: Executable: “\yarn\distros\houdini\versions\Houdini 19.5.303\bin\hython.exe”
2022-08-23 16:25:51: 0: INFO: Argument: “C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\hrender_dl.py” -f 1001 1010 1 -o “chs("../../test/test_string")” -d /obj/ropnet1/pc_render_rop1/new_test -tempdir “C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\jobsData\6304e1c3df8f3319bc8dc377\0_tempMm0s10” -arnoldAbortOnLicenseFail 1 “C:/ProgramData/Thinkbox/Deadline10/workers/bcat03/jobsData/6304e1c3df8f3319bc8dc377/h19_5_test_v001.hip”
2022-08-23 16:25:51: 0: INFO: Full Command: “\yarn\distros\houdini\versions\Houdini 19.5.303\bin\hython.exe” “C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\hrender_dl.py” -f 1001 1010 1 -o “chs("../../test/test_string")” -d /obj/ropnet1/pc_render_rop1/new_test -tempdir “C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\jobsData\6304e1c3df8f3319bc8dc377\0_tempMm0s10” -arnoldAbortOnLicenseFail 1 “C:/ProgramData/Thinkbox/Deadline10/workers/bcat03/jobsData/6304e1c3df8f3319bc8dc377/h19_5_test_v001.hip”
2022-08-23 16:25:51: 0: INFO: Startup Directory: “\yarn\distros\houdini\versions\Houdini 19.5.303\bin”
2022-08-23 16:25:51: 0: INFO: Process Priority: BelowNormal
2022-08-23 16:25:51: 0: INFO: Process Affinity: default
2022-08-23 16:25:51: 0: INFO: Process is now running
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | log started Tue Aug 23 16:25:55 2022
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | Arnold 7.1.3.0 [a8020120] windows clang-10.0.1 oiio-2.4.1 osl-1.12.0 vdb-7.1.1 adlsdk-6.3.1.44 clmhub-2.0.0.235 rlm-14.1.3 optix-6.6.0 2022/08/01 13:27:49
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | running on bcat03, pid=5040
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | 1 x AMD Ryzen 9 5950X 16-Core Processor (16 cores, 32 logical) with 49056MB
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | NVIDIA driver version 512.15 (Optix 60802)
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | GPU 0: NVIDIA GeForce GTX 1060 6GB @ 1847MHz (compute 6.1) with 6143MB (3927MB available) (NVLink:0)
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | Windows 10 (version 10.0, build 19044)
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB | soft limit for open files changed from 8192 to 2048
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 414MB |
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | [color_manager_ocio] default ocio.config found in \yarn\distros\arnold\htoa\h19_latest\latest\scripts\bin…/ocio/configs/arnold/config.ocio
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | loading plugins from //yarn/distros/arnold/plugins/lentil/lentil_v2.4_20220714/lentil2.4.0-Windows-ai7.1.1.0/bin …
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | cryptomatte.dll: cryptomatte uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | cryptomatte.dll: cryptomatte_filter uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | cryptomatte.dll: cryptomatte_manifest_driver uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 433MB | lentil.dll: lentil_camera uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | lentil.dll: lentil_filter uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | lentil.dll: imager_lentil uses Arnold 7.1.1.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | loaded 6 plugins from 2 lib(s) in 0:00.07
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | loading plugins from \yarn\distros\arnold\htoa\h19_latest\latest\scripts\bin…\plugins …
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | alembic_proc.dll: alembic uses Arnold 7.1.3.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 434MB | htoa_mandelbulb_proc.dll: mandelbulb uses Arnold 7.1.3.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 447MB | usd_proc.dll: usd uses Arnold 7.1.3.0
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 447MB | loaded 3 plugins from 3 lib(s) in 0:00.25
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 454MB | [htoa_op] Begin registration …
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 465MB | [obj_procedurals] Registering procedurals …
2022-08-23 16:25:58: 0: STDOUT: 00:00:02 465MB | [obj_procedurals] procedural registration done.
2022-08-23 16:25:59: 0: STDOUT: 00:00:03 472MB | [rop_operators] Registering operators …
2022-08-23 16:25:59: 0: STDOUT: 00:00:03 472MB | [rop_operators] operator registration done.
2022-08-23 16:26:00: 0: STDOUT: 00:00:04 506MB | [vop_shaders] Registering shaders …
2022-08-23 16:26:00: 0: STDOUT: 00:00:04 511MB | [vop_shaders] shader registration done.
2022-08-23 16:26:00: 0: STDOUT: 00:00:04 511MB | [vop_imagers] Registering imagers …
2022-08-23 16:26:00: 0: STDOUT: 00:00:04 511MB | [vop_imagers] imager registration done.
2022-08-23 16:26:00: 0: STDOUT: 00:00:04 511MB | [htoa_op] USD shader translation registration
2022-08-23 16:26:01: 0: STDOUT: 00:00:05 528MB | [htoa_op] End registration.
2022-08-23 16:26:01: 0: STDOUT: 00:00:05 528MB |
2022-08-23 16:26:01: 0: STDOUT: 00:00:05 528MB | releasing resources
2022-08-23 16:26:01: 0: STDOUT: 00:00:05 507MB | Arnold shutdown
2022-08-23 16:26:19: 0: STDOUT: Detected Houdini version: (19, 5, 303)
2022-08-23 16:26:19: 0: STDOUT: [‘C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\plugins\6304e1c3df8f3319bc8dc377\hrender_dl.py’, ‘-f’, ‘1001’, ‘1010’, ‘1’, ‘-o’, ‘chs(../../test/test_string)’, ‘-d’, ‘/obj/ropnet1/pc_render_rop1/new_test’, ‘-tempdir’, ‘C:\ProgramData\Thinkbox\Deadline10\workers\bcat03\jobsData\6304e1c3df8f3319bc8dc377\0_tempMm0s10’, ‘-arnoldAbortOnLicenseFail’, ‘1’, ‘C:/ProgramData/Thinkbox/Deadline10/workers/bcat03/jobsData/6304e1c3df8f3319bc8dc377/h19_5_test_v001.hip’]
2022-08-23 16:26:19: 0: STDOUT: Start: 1001
2022-08-23 16:26:19: 0: STDOUT: End: 1010
2022-08-23 16:26:19: 0: STDOUT: Increment: 1
2022-08-23 16:26:19: 0: STDOUT: Ignore Inputs: False
2022-08-23 16:26:19: 0: STDOUT: Output: chs(../../test/test_string)
2022-08-23 16:26:19: 0: STDOUT: Driver: /obj/ropnet1/pc_render_rop1/new_test
2022-08-23 16:26:19: 0: STDOUT: Input File: C:/ProgramData/Thinkbox/Deadline10/workers/bcat03/jobsData/6304e1c3df8f3319bc8dc377/h19_5_test_v001.hip
2022-08-23 16:26:21: 0: STDOUT: LOADING POLYCAT PIPELINE \yarn\projects\pipeline\development\pc_houdini_init_.py
2022-08-23 16:26:21: 0: STDOUT: Begin Path Mapping
2022-08-23 16:26:24: 0: STDOUT: b’’
2022-08-23 16:26:26: 0: STDOUT: b’’
2022-08-23 16:26:26: 0: STDOUT: End Path Mapping
2022-08-23 16:26:26: 0: STDOUT: ROP type: arnold
2022-08-23 16:26:26: 0: STDOUT: Enabled log to console
2022-08-23 16:26:26: 0: STDOUT: Set verbosity to detailed
2022-08-23 16:26:26: 0: STDOUT: Set Arnold abort on license fail to 1
2022-08-23 16:26:26: 0: STDOUT: Begin path mapping Arnold procedurals
2022-08-23 16:26:26: 0: STDOUT: Rendering frame 1001 to 1010
2022-08-23 16:26:27: 0: STDOUT: Traceback (most recent call last):
2022-08-23 16:26:27: 0: Done executing plugin command of type ‘Render Task’

=======================================================
Details

Date: 08/23/2022 16:26:31
Frames: 1001-1010
Elapsed Time: 00:00:00:43
Job Submit Date: 08/23/2022 16:18:43
Job User: roger
Average RAM Usage: 12940763136 (26%)
Peak RAM Usage: 14195908608 (28%)
Average CPU Usage: 5%
Peak CPU Usage: 15%
Used CPU Clocks (x10^6 cycles): 212465
Total CPU Clocks (x10^6 cycles): 4249294

=======================================================
Worker Information

Worker Name: bcat03
Version: v10.1.23.6 Release (773a6289d)
Operating System: Windows 10 Pro
Running As Service: No
Machine User: roger
IP Address: 192.168.4.127
MAC Address: D8:5E:D3:26:8D:82
CPU Architecture: x64
CPUs: 32
CPU Usage: 3%
Memory Usage: 12.9 GB / 47.9 GB (26%)
Free Disk Space: 985.370 GB (74.921 GB on C:, 89.238 MB on D:, 42.958 GB on E:, 796.228 GB on F:, 71.175 GB on G:)
Video Card: NVIDIA GeForce GTX 1060 6GB

hi did you find a solution yet?

I am having a very similar issue with Arnold and Mantra throwing a bunch of non sense errors like “Caught exception: The attempted operation failed.”

It was fine if I added an extension to the end.
ex…
chs('./test_string').exr

by the way ,do you pass double quotes?
I use single.

Hey,
The only solution that I could find at the time was to use python .format method with a bunch of hou.parm.eval / evalAsString methods to build out the path which in our case leaves you with a awfully long expression…

Interesting that adding the extension at the end forces it to work…if I run into this again I will give that a try.