Houdini Error Rendering Composite ROP

Stephen_Scollay · April 21, 2023, 6:55am

Hey there,

I am lost on this one and the existing similar forum posts covering similar errors I’ve found haven’t helped.

I am running a simple test with a Houdini composite ROP going into into a Deadline ROP for rendering. Other render types such as rendering geometry work fine but the Comp ROP cannot render on the farm. All files are stored in a shared server that all workers have access to and my user does have editing privileges for all read/write locations. Rendering the Comp ROP locally is fine (In fact even when on the farm it is still only running on this local comp), but when ran on the farm it fails, and I get the following log from the worker:

0: DEBUG: ManagedProcess.Execute: m_process.IsRunning(): True    m_process.IsStdoutAvailable(): False
0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
0: DEBUG: PopupHandler.CheckForPopups: Returning
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Detected Houdini version: (19, 0, 531)
0: STDOUT: Detected Houdini version: (19, 0, 531)
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: ['C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\plugins\\6441d137dd0997665cfa3772\\hrender_dl.py', '-f', '102', '102', '1', '-o', '$HIP/render/$HIPNAME.$OS.$F4.exr', '-g', '-d', '/out/comp1', '-tempdir', 'C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\jobsData\\6441d137dd0997665cfa3772\\0_tempprHN40', '-arnoldAbortOnLicenseFail', '1', 'C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip']
0: STDOUT: ['C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\plugins\\6441d137dd0997665cfa3772\\hrender_dl.py', '-f', '102', '102', '1', '-o', '$HIP/render/$HIPNAME.$OS.$F4.exr', '-g', '-d', '/out/comp1', '-tempdir', 'C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\jobsData\\6441d137dd0997665cfa3772\\0_tempprHN40', '-arnoldAbortOnLicenseFail', '1', 'C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip']
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Start: 102
0: STDOUT: Start: 102
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: End: 102
0: STDOUT: End: 102
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Increment: 1
0: STDOUT: Increment: 1
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Ignore Inputs: True
0: STDOUT: Ignore Inputs: True
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Output: $HIP/render/$HIPNAME.$OS.$F4.exr
0: STDOUT: Output: $HIP/render/$HIPNAME.$OS.$F4.exr
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Driver: /out/comp1
0: STDOUT: Driver: /out/comp1
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Input File: C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip
0: STDOUT: Input File: C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip
0: DEBUG: ManagedProcess.Execute: m_process.IsRunning(): True    m_process.IsStdoutAvailable(): True
0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
0: DEBUG: PopupHandler.CheckForPopups: Returning
0: DEBUG: ManagedProcess.HandleStdoutLine: parsing stdout: Error: Caught exception: The attempted operation failed.
0: DEBUG: ManagedProcess.HandleStdoutLine: line was matched by handler "(Error: .*)"
0: DEBUG: ManagedProcess.Execute: returning
0: Done executing plugin command of type 'Render Task'
ERROR: 0: An exception occurred: FailRenderException : Error: Caught exception: The attempted operation failed.
   at Deadline.Plugins.DeadlinePlugin.FailRender(String message) (Python.Runtime.PythonException)
  File "C:\ProgramData\Thinkbox\Deadline10\workers\THANOS\plugins\6441d137dd0997665cfa3772\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) (Deadline.Plugins.RenderPluginException)
0: Unloading plugin: Houdini
0: Executing plugin command of type 'End Job'
0: DEBUG: EndJob: called
0: DEBUG: EndJob: returning
0: Done executing plugin command of type 'End Job'
0: Render Thread - Render State transition from = 'Rendering' to = 'WaitingForTask'
Scheduler Thread - Render Thread 0 threw a major error: 
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Exception Details
RenderPluginException -- FailRenderException : Error: Caught exception: The attempted operation failed.
   at Deadline.Plugins.DeadlinePlugin.FailRender(String message) (Python.Runtime.PythonException)
  File "C:\ProgramData\Thinkbox\Deadline10\workers\THANOS\plugins\6441d137dd0997665cfa3772\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)
RenderPluginException.Cause: JobError (2)
RenderPluginException.Level: Major (1)
RenderPluginException.HasSlaveLog: True
RenderPluginException.SlaveLogFileName: C:\ProgramData\Thinkbox\Deadline10\logs\deadlineslave_renderthread_0-THANOS-0000.log
Exception.TargetSite: Deadline.Slaves.Messaging.PluginResponseMemento d(Deadline.Net.DeadlineMessage, System.Threading.CancellationToken)
Exception.Data: ( )
Exception.Source: deadline
Exception.HResult: -2146233088
  Exception.StackTrace: 
   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)
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

For any explainations please assume I am a dumb dumb as despite trying to look into how submitters function internally I havent been able to find out much.

Thanks,
Stephen

eamsler · April 25, 2023, 9:58pm

Did a quick dig here. The plugin-level debugging is enabled which makes it a lot harder to read the messages coming from Houdini. I’ve simplified and it looks like this:

0: STDOUT: Detected Houdini version: (19, 0, 531)
0: STDOUT: ['C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\plugins\\6441d137dd0997665cfa3772\\hrender_dl.py', '-f', '102', '102', '1', '-o', '$HIP/render/$HIPNAME.$OS.$F4.exr', '-g', '-d', '/out/comp1', '-tempdir', 'C:\\ProgramData\\Thinkbox\\Deadline10\\workers\\THANOS\\jobsData\\6441d137dd0997665cfa3772\\0_tempprHN40', '-arnoldAbortOnLicenseFail', '1', 'C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip']
0: STDOUT: Start: 102
0: STDOUT: End: 102
0: STDOUT: Increment: 1
0: STDOUT: Ignore Inputs: True
0: STDOUT: Output: $HIP/render/$HIPNAME.$OS.$F4.exr
0: STDOUT: Driver: /out/comp1
0: STDOUT: Input File: C:/Users/stephen.scollay/Documents/LocalFiles/DeadlineCompositeTest.hip

and what we caught on:

Error: Caught exception: The attempted operation failed.

Here’s one of those other threads:

Can you run some of that advice? We have some new advice on how to isolate Houdini:

Can you dig into that KB article and report back here? Also feedback on the KB is welcome!

mois.moshev · April 26, 2023, 6:53am

It is a bit unfortunate that the Deadline error handling kills the plugin on the first error line encountered, which in Houdini’s case often means the actual error is not shown.
We have an ugly workaround by “ignoring” some errors, but perhaps the real solution would be to let the process finish, and accumulate all errors.

Stephen_Scollay · April 28, 2023, 1:25am

Yeah, agreed, the process described above does work, although it is a bit finicky.

Stephen_Scollay · April 28, 2023, 2:00am

Heya,
the article is super useful and I greatly appreciate the example changes of the command as initially I wasn’t super sure which paths needed changing. Cheers, and the issue fixed itself so no idea what was wrong. The error was that it couldn’t access the houdini file and once it decided that it could, it was fine.
Thanks again,
Stephen

mois.moshev · April 28, 2023, 6:42am

This is really an error coming from the scene. It could be trying to change a locked hda, or access a non-existent resource. So it fixed itself after you probably changed the scene.

Stephen_Scollay · May 1, 2023, 12:24am

Awesome, Ill look into it. Not actually my scene but I will pass it on.