Houdini render error (.hip file)

Ovo · September 27, 2022, 7:00am

Hi everyone,

For the past few weeks we are having some errors when launching jobs in Houdini
to the rendering machines.
This has happened so far on 2-3 PCs (all Win10Pro) but its sporadical and not on the same frame or scene.

I attach the last part of the log that has the majority of the informations:

2022-09-23 09:55:13: 0: STDOUT: Output: ${PRISMJOB}/01_Workflow/Shots/${PRISM_SEQUENCE}-${PRISM_SHOT}/Rendering/3dRender/${PRISM_CATEGORY}/chs('version')/${OS}/${OS}.${F4}.exr
2022-09-23 09:55:13: 0: STDOUT: Driver: /out/shot_3046-00100_Crowd_Shin_Honjin_Shadow
2022-09-23 09:55:13: 0: STDOUT: Input File: K:/CG/KDM2/01_Workflow/Shots/3044-00010/Scenefiles/fx/Crowd/shot_3044-00010_fx_Crowd_v0052__dts_.hip
2022-09-23 09:55:34: 0: STDOUT: crowdsource9.userdata(0): Unexpected end of file
2022-09-23 09:55:36: 0: STDOUT: Traceback (most recent call last):
2022-09-23 09:55:36: 0: STDOUT: File “C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\632d01db62d7b5a32820f0a3\hrender_dl.py”, line 406, in
2022-09-23 09:55:36: 0: STDOUT: hou.hipFile.load( inputFile )
2022-09-23 09:55:36: 0: STDOUT: File “C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/houdini/python2.7libs\hou.py”, line 40345, in load
2022-09-23 09:55:36: 0: STDOUT: return hou.hipFile_load(*args, **kwargs)
2022-09-23 09:55:36: 0: STDOUT: hou.OperationFailed: The attempted operation failed.
2022-09-23 09:55:36: 0: STDOUT: Error loading: K:/CG/KDM2/01_Workflow/Shots/3044-00010/Scenefiles/fx/Crowd/shot_3044-00010_fx_Crowd_v0052__dts.hip
2022-09-23 09:55:36: 0: STDOUT: Error: Unexpected end of .hip file
2022-09-23 09:55:36: 0: Done executing plugin command of type ‘Render Task’

From my understanding the process is trying to access a network drive for the file,
but for some reason cannot load it/find it and that is causing the error.
An option could be a network issue, the machine loses connection to the network and so to the
drive, causing the error, but I am investigating both the DCs and NAS but everything looks ok.

So, I would like to ask you if this problem may have some other other causes which I could look into.

Thank you in advance for the help.
Have a nice day.

anthonygelatka · September 27, 2022, 8:59am

Error loading: K:/CG/KDM2/01_Workflow/Shots/3044-00010/Scenefiles/fx/Crowd/shot_3044-00010_fx_Crowd_v0052__dts .hip
Error: Unexpected end of .hip file

sounds like the file has the issue, can you confirm the file does open on the rendering machine?

are you using the same python version?

Ovo · September 29, 2022, 2:47am

Hi, and thank you for getting back!

I double checked with the guys, the file can open on both the working machine and the render one.
Also we are using the same Python version.

I attach here 2 logs, both are the same job, from the same user, on same machine.
One completed successfully, the other failed.

Again, I checked for network isssued on that time frame but found nothing…

Successful Job:

=======================================================
Log
=======================================================
2022-09-26 21:59:22:  0: Loading Job's Plugin timeout is Disabled
2022-09-26 21:59:23:  0: Executing plugin command of type 'Sync Files for Job'
2022-09-26 21:59:23:  0: All job files are already synchronized
2022-09-26 21:59:24:  0: Plugin dlHoudini was already synchronized.
2022-09-26 21:59:24:  0: Done executing plugin command of type 'Sync Files for Job'
2022-09-26 21:59:24:  0: Executing plugin command of type 'Initialize Plugin'
2022-09-26 21:59:24:  0: INFO: Executing plugin script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\dlHoudini.py'
2022-09-26 21:59:24:  0: INFO: About: Houdini Plugin for Deadline
2022-09-26 21:59:24:  0: INFO: Render Job As User disabled, running as current user 'render'
2022-09-26 21:59:24:  0: INFO: The job's environment will be merged with the current environment before rendering
2022-09-26 21:59:24:  0: Done executing plugin command of type 'Initialize Plugin'
2022-09-26 21:59:24:  0: Start Job timeout is disabled.
2022-09-26 21:59:24:  0: Task timeout is disabled.
2022-09-26 21:59:24:  0: Loaded job: spCache : /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2 (63319f1c05a7822190190b8f)
2022-09-26 21:59:25:  0: Executing plugin command of type 'Start Job'
2022-09-26 21:59:25:  0: DEBUG: S3BackedCache Client is not installed.
2022-09-26 21:59:25:  0: INFO: Executing global asset transfer preload script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\GlobalAssetTransferPreLoad.py'
2022-09-26 21:59:25:  0: INFO: Looking for legacy (pre-10.0.26) AWS Portal File Transfer...
2022-09-26 21:59:25:  0: INFO: Looking for legacy (pre-10.0.26) File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...
2022-09-26 21:59:25:  0: INFO: Could not find legacy (pre-10.0.26) AWS Portal File Transfer.
2022-09-26 21:59:25:  0: INFO: Legacy (pre-10.0.26) AWS Portal File Transfer is not installed on the system.
2022-09-26 21:59:25:  0: INFO: Executing job preload script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\JobPreLoad.py'
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable HOUDINI_PATH to C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;&
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [HOUDINI_PATH] : C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;& ( converted from C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;&)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VRAY_APPSDK to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VRAY_APPSDK] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable HSITE to 
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [HSITE] :  ( converted from )
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VRAY_UI_DS_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VRAY_UI_DS_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VFH_HOME to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VFH_HOME] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VRAY_AUTH_CLIENT_FILE_PATH to Y:\System\V-Ray\vray_builds\vrlclient
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VRAY_AUTH_CLIENT_FILE_PATH] : Y:\System\V-Ray\vray_builds\vrlclient ( converted from Y:\System\V-Ray\vray_builds\vrlclient)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable PYTHONPATH to U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs;
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [PYTHONPATH] : U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs; ( converted from U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs;)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VFH_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VFH_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable HOUDINI_OTLSCAN_PATH to U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [HOUDINI_OTLSCAN_PATH] : U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls ( converted from U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable PATH to C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [PATH] : C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin ( converted from C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable VRAY_OSL_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [VRAY_OSL_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable SP_CACHE to X:/Caches/2022-101_MHF
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [SP_CACHE] : X:/Caches/2022-101_MHF ( converted from X:/Caches/2022-101_MHF)
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable HOUDINI_SCRIPT_PATH to U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts
2022-09-26 21:59:25:  0: INFO: SetEnv with Pathmap > [HOUDINI_SCRIPT_PATH] : U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts ( converted from U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts)
2022-09-26 21:59:25:  0: Done executing plugin command of type 'Start Job'
2022-09-26 21:59:25:  0: Plugin rendering frame(s): 901-1173
2022-09-26 21:59:25:  0: Executing plugin command of type 'Render Task'
2022-09-26 21:59:25:  0: INFO: Set HOUDINI_PATHMAP to {"/Volumes/Data/":"X:/", "/Volumes/Data2/":"Y:/", "/Volumes/Data3/":"Z:/", "/Volumes/Data4/":"W:/", "/Volumes/Data4/Job/2019-112_TND2/":"T:/", "/Volumes/Data8_1/":"U:/"}
2022-09-26 21:59:25:  0: INFO: Setting Process Environment Variable HOUDINI_PATHMAP to {"/Volumes/Data/":"X:/", "/Volumes/Data2/":"Y:/", "/Volumes/Data3/":"Z:/", "/Volumes/Data4/":"W:/", "/Volumes/Data4/Job/2019-112_TND2/":"T:/", "/Volumes/Data8_1/":"U:/"}
2022-09-26 21:59:25:  0: INFO: Starting Houdini Job
2022-09-26 21:59:25:  0: INFO: Stdout Redirection Enabled: True
2022-09-26 21:59:25:  0: INFO: Stdout Handling Enabled: True
2022-09-26 21:59:25:  0: INFO: Popup Handling Enabled: True
2022-09-26 21:59:25:  0: INFO: QT Popup Handling Enabled: False
2022-09-26 21:59:25:  0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2022-09-26 21:59:25:  0: INFO: Using Process Tree: True
2022-09-26 21:59:25:  0: INFO: Hiding DOS Window: True
2022-09-26 21:59:25:  0: INFO: Creating New Console: False
2022-09-26 21:59:25:  0: INFO: Running as user: render
2022-09-26 21:59:25:  0: INFO: Executable: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin\Hython.exe"
2022-09-26 21:59:25:  0: INFO: Argument: C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\hyKick.py -d /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2/render -f 901 1173 1 U:/Job/2022-101_MHF/CG/01_Workflow/Shots/MHF-101-003-0030/Scenefiles/fx/Fire/shot_MHF-101-003-0030_fx_Fire_v0015__ksa_.hip
2022-09-26 21:59:25:  0: INFO: Full Command: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin\Hython.exe" C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\hyKick.py -d /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2/render -f 901 1173 1 U:/Job/2022-101_MHF/CG/01_Workflow/Shots/MHF-101-003-0030/Scenefiles/fx/Fire/shot_MHF-101-003-0030_fx_Fire_v0015__ksa_.hip
2022-09-26 21:59:25:  0: INFO: Startup Directory: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin"
2022-09-26 21:59:25:  0: INFO: Process Priority: BelowNormal
2022-09-26 21:59:25:  0: INFO: Process Affinity: default
2022-09-26 21:59:25:  0: INFO: Process is now running
2022-09-26 21:59:27:  0: STDOUT: [2022/Sep/26|21:59:27] VFH |    Info| * Build number:13797 hash:23c40ef from 02 Jun 2021 01:52
2022-09-26 21:59:49:  0: STDOUT: -------------------------------------
2022-09-26 21:59:49:  0: STDOUT: -------------------------------------
2022-09-26 21:59:49:  0: STDOUT:  START :  hyKick.py
2022-09-26 21:59:49:  0: STDOUT: -------------------------------------
2022-09-26 21:59:49:  0: STDOUT: -------------------------------------
2022-09-26 22:01:09:  0: STDOUT: [2022/Sep/26|22:01:09] VFH |    Info| * V-Ray 4.30.03
2022-09-26 22:01:26:  0: STDOUT: unlock Parent HDA
2022-09-26 22:01:26:  0: STDOUT: render : /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2/render
2022-09-26 22:06:22:  0: STDOUT: Rendering 273 frames ( from 901 to 1173 by 1)
2022-09-26 22:06:22:  0: STDOUT: 22:01:26 render frame 901 (1 of 273)
2022-09-26 22:06:22:  0: STDOUT: 22:01:29 render frame 902 (2 of 273)

Error Job

=======================================================
Error
=======================================================
Error: Renderer returned non-zero error code, 1. Check the log for more information.
   at Deadline.Plugins.PluginWrapper.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage, AbortLevel& abortLevel)

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

=======================================================
Stack Trace
=======================================================
   at Deadline.Plugins.SandboxedPlugin.d(DeadlineMessage bbh, CancellationToken bbi)
   at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame, CancellationToken cancellationToken)
   at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter adv, CancellationToken adw)

=======================================================
Log
=======================================================
2022-09-26 21:57:20:  0: Loading Job's Plugin timeout is Disabled
2022-09-26 21:57:22:  0: Executing plugin command of type 'Sync Files for Job'
2022-09-26 21:57:22:  0: All job files are already synchronized
2022-09-26 21:57:22:  0: Plugin dlHoudini was already synchronized.
2022-09-26 21:57:22:  0: Done executing plugin command of type 'Sync Files for Job'
2022-09-26 21:57:22:  0: Executing plugin command of type 'Initialize Plugin'
2022-09-26 21:57:22:  0: INFO: Executing plugin script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\dlHoudini.py'
2022-09-26 21:57:23:  0: INFO: About: Houdini Plugin for Deadline
2022-09-26 21:57:23:  0: INFO: Render Job As User disabled, running as current user 'render'
2022-09-26 21:57:23:  0: INFO: The job's environment will be merged with the current environment before rendering
2022-09-26 21:57:23:  0: Done executing plugin command of type 'Initialize Plugin'
2022-09-26 21:57:23:  0: Start Job timeout is disabled.
2022-09-26 21:57:23:  0: Task timeout is disabled.
2022-09-26 21:57:23:  0: Loaded job: spCache : /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2 (63319f1c05a7822190190b8f)
2022-09-26 21:57:23:  0: Executing plugin command of type 'Start Job'
2022-09-26 21:57:23:  0: DEBUG: S3BackedCache Client is not installed.
2022-09-26 21:57:23:  0: INFO: Executing global asset transfer preload script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\GlobalAssetTransferPreLoad.py'
2022-09-26 21:57:23:  0: INFO: Looking for legacy (pre-10.0.26) AWS Portal File Transfer...
2022-09-26 21:57:23:  0: INFO: Looking for legacy (pre-10.0.26) File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...
2022-09-26 21:57:23:  0: INFO: Could not find legacy (pre-10.0.26) AWS Portal File Transfer.
2022-09-26 21:57:23:  0: INFO: Legacy (pre-10.0.26) AWS Portal File Transfer is not installed on the system.
2022-09-26 21:57:23:  0: INFO: Executing job preload script 'C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\JobPreLoad.py'
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable HOUDINI_PATH to C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;&
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [HOUDINI_PATH] : C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;& ( converted from C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0;C:/Prism/Plugins/Apps/Houdini/Integration;U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/other;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home;Y:/System/Houdini/common/plugins/Deadline10//HoudiniSubmitter;&)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VRAY_APPSDK to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VRAY_APPSDK] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable HSITE to 
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [HSITE] :  ( converted from )
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VRAY_UI_DS_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VRAY_UI_DS_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\ui)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VFH_HOME to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VFH_HOME] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VRAY_AUTH_CLIENT_FILE_PATH to Y:\System\V-Ray\vray_builds\vrlclient
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VRAY_AUTH_CLIENT_FILE_PATH] : Y:\System\V-Ray\vray_builds\vrlclient ( converted from Y:\System\V-Ray\vray_builds\vrlclient)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable PYTHONPATH to U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs;
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [PYTHONPATH] : U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs; ( converted from U:\Job\2022-101_MHF\CG\00_Pipeline\Apps\Houdini\houdini\python2.7libs;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\python27;Y:\System\Houdini\common\plugins\spCache\python2.7libs;Y:\System\Deadline\DeadlineRepository10\api\python;Y:\System\Houdini\common\plugins\Deadline10\python2.7libs;)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VFH_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VFH_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin;Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\vfh_home\bin)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable HOUDINI_OTLSCAN_PATH to U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [HOUDINI_OTLSCAN_PATH] : U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls ( converted from U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/otls;Y:/System/Houdini/common/plugins/spCache/otls;Y:/System/Houdini/common/otls;;@/otls)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable PATH to C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [PATH] : C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin ( converted from C:\Prism\PythonLibs\Python27\pywin32_system32;C:\PROGRA~1\SIDEEF~1\HOUDIN~1.597\python27\lib\site-packages-forced\PySide2;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/python27;C:/Users/sawada/houdini18.0/packages/../SideFXLabs/597-embedded/SideFXLabs18.0/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/bin;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/toolkit/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/appsdk/bin;Y:/System/V-Ray/vray_builds/houdini/houdini18.0.597_43003_nightly/vfh_home/bin;C:/Program Files/Python39/Scripts/;C:/Program Files/Python39/;C:/Windows/system32;C:/Windows;C:/Windows/System32/Wbem;C:/Windows/System32/WindowsPowerShell/v1.0/;C:/Windows/System32/OpenSSH/;C:/Program Files (x86)/NVIDIA Corporation/PhysX/Common;C:/WINDOWS/system32;C:/WINDOWS;C:/WINDOWS/System32/Wbem;C:/WINDOWS/System32/WindowsPowerShell/v1.0/;C:/WINDOWS/System32/OpenSSH/;C:/Program Files/Python39/Tools/scripts;C:/Users/sawada/AppData/Local/Microsoft/WindowsApps;C:/Users/sawada/AppData/Local/Programs/Microsoft VS Code/bin)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable VRAY_OSL_PATH to Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [VRAY_OSL_PATH] : Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin ( converted from Y:\System\V-Ray\vray_builds\houdini\houdini18.0.597_43003_nightly\appsdk\bin)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable SP_CACHE to X:/Caches/2022-101_MHF
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [SP_CACHE] : X:/Caches/2022-101_MHF ( converted from X:/Caches/2022-101_MHF)
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable HOUDINI_SCRIPT_PATH to U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts
2022-09-26 21:57:23:  0: INFO: SetEnv with Pathmap > [HOUDINI_SCRIPT_PATH] : U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts ( converted from U:/Job/2022-101_MHF/CG/00_Pipeline/Apps/Houdini/houdini/scripts;Y:/System/Houdini/common/plugins/spCache/scripts;;@/scripts)
2022-09-26 21:57:23:  0: Done executing plugin command of type 'Start Job'
2022-09-26 21:57:23:  0: Plugin rendering frame(s): 901-1173
2022-09-26 21:57:23:  0: Executing plugin command of type 'Render Task'
2022-09-26 21:57:23:  0: INFO: Set HOUDINI_PATHMAP to {"/Volumes/Data/":"X:/", "/Volumes/Data2/":"Y:/", "/Volumes/Data3/":"Z:/", "/Volumes/Data4/":"W:/", "/Volumes/Data4/Job/2019-112_TND2/":"T:/", "/Volumes/Data8_1/":"U:/"}
2022-09-26 21:57:23:  0: INFO: Setting Process Environment Variable HOUDINI_PATHMAP to {"/Volumes/Data/":"X:/", "/Volumes/Data2/":"Y:/", "/Volumes/Data3/":"Z:/", "/Volumes/Data4/":"W:/", "/Volumes/Data4/Job/2019-112_TND2/":"T:/", "/Volumes/Data8_1/":"U:/"}
2022-09-26 21:57:23:  0: INFO: Starting Houdini Job
2022-09-26 21:57:23:  0: INFO: Stdout Redirection Enabled: True
2022-09-26 21:57:23:  0: INFO: Stdout Handling Enabled: True
2022-09-26 21:57:23:  0: INFO: Popup Handling Enabled: True
2022-09-26 21:57:23:  0: INFO: QT Popup Handling Enabled: False
2022-09-26 21:57:23:  0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2022-09-26 21:57:23:  0: INFO: Using Process Tree: True
2022-09-26 21:57:23:  0: INFO: Hiding DOS Window: True
2022-09-26 21:57:23:  0: INFO: Creating New Console: False
2022-09-26 21:57:23:  0: INFO: Running as user: render
2022-09-26 21:57:23:  0: INFO: Executable: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin\Hython.exe"
2022-09-26 21:57:23:  0: INFO: Argument: C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\hyKick.py -d /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2/render -f 901 1173 1 U:/Job/2022-101_MHF/CG/01_Workflow/Shots/MHF-101-003-0030/Scenefiles/fx/Fire/shot_MHF-101-003-0030_fx_Fire_v0015__ksa_.hip
2022-09-26 21:57:23:  0: INFO: Full Command: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin\Hython.exe" C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\hyKick.py -d /obj/Layout_WindowF_OE/spCache_Fire_window_2F_07_Add2/render -f 901 1173 1 U:/Job/2022-101_MHF/CG/01_Workflow/Shots/MHF-101-003-0030/Scenefiles/fx/Fire/shot_MHF-101-003-0030_fx_Fire_v0015__ksa_.hip
2022-09-26 21:57:23:  0: INFO: Startup Directory: "C:\Program Files\Side Effects Software\Houdini 18.0.597\bin"
2022-09-26 21:57:23:  0: INFO: Process Priority: BelowNormal
2022-09-26 21:57:23:  0: INFO: Process Affinity: default
2022-09-26 21:57:23:  0: INFO: Process is now running
2022-09-26 21:57:25:  0: STDOUT: [2022/Sep/26|21:57:25] VFH |    Info| * Build number:13797 hash:23c40ef from 02 Jun 2021 01:52
2022-09-26 21:57:54:  0: STDOUT: -------------------------------------
2022-09-26 21:57:54:  0: STDOUT: -------------------------------------
2022-09-26 21:57:54:  0: STDOUT:  START :  hyKick.py
2022-09-26 21:57:54:  0: STDOUT: -------------------------------------
2022-09-26 21:57:54:  0: STDOUT: -------------------------------------
2022-09-26 21:59:17:  0: STDOUT: Traceback (most recent call last):
2022-09-26 21:59:17:  0: STDOUT:   File "C:\Users\render\AppData\Local\Thinkbox\Deadline10\slave\Ryzen9-R02\plugins\63319f1c05a7822190190b8f\hyKick.py", line 156, in <module>
2022-09-26 21:59:17:  0: STDOUT:     hip = hou.hipFile.load(args.hip)
2022-09-26 21:59:17:  0: STDOUT:   File "C:/PROGRA~1/SIDEEF~1/HOUDIN~1.597/houdini/python2.7libs\hou.py", line 40345, in load
2022-09-26 21:59:17:  0: STDOUT:     return _hou.hipFile_load(*args, **kwargs)
2022-09-26 21:59:17:  0: STDOUT: hou.OperationFailed: The attempted operation failed.
2022-09-26 21:59:17:  0: STDOUT: Error loading: U:/Job/2022-101_MHF/CG/01_Workflow/Shots/MHF-101-003-0030/Scenefiles/fx/Fire/shot_MHF-101-003-0030_fx_Fire_v0015__ksa_.hip
2022-09-26 21:59:17:  0: STDOUT: Error:       Syntax error in file: '{' expected.
2022-09-26 21:59:17:  0: STDOUT:              Invalid .hip file header
2022-09-26 21:59:17:  0: INFO: Process exit code: 1
2022-09-26 21:59:17:  0: Done executing plugin command of type 'Render Task'

Thank you again for the help.

Render_Log_Ok_and_error.zip (8.5 KB)

Guilherme · September 29, 2022, 1:50pm

Hi. I would change this “chs(‘version’)”
Deadline can’t handle that. Try setting the version using env vars under edit → alias and variables.

Guilherme · September 29, 2022, 1:51pm

And, It’s wrongly written. It should be chs("version"), but I would use env vars nevertheless.