Hi

I am having an issue if I use PDG to create a USD file from Solaris.

If I set usdrender to look upstream for the usd file to render, PDG freaks out and renders the same 10 frames over and over again in a never ending loop. It works perfectly if I actually create the usd file and just path usdrender to look for that exact file on disk.

I can only test on 18.0499 right now so I am not sure if this was a bug that was fixed at a later stage or if it is something I need to do to stop Houdini looping over itself. Best Mark

If you are using non-commercial license you should set the Output File parm on ropusd1 to `$HIP/USD/$HIPNAME.$OS.usdnc` because that's what will end up being written.

Is the endless rendering occurring with Local Scheduler as well? Do you have the deadline log files? Maybe the jobs are being restarted for some reason.

Hi Chris.

Thanks for getting back to me. I will try renaming the usd. If it is still looping I will copy out the
deadline log file as well. It might be me being daft, but I have not found any documentation before about usdnc formats.

Just to make sure I am correct. Is this right for education?

-You can generate an usd file straight from Houdini but if you are making one via PDG remotely use the usdnc format instead.

-other education usd version will be usdanc, usdznc and usdcnc.

-I can have the master "render.usdnc" file that references other usd files, and these referenced files are fine being normal animation.usd etc.

have I got this correct?

Thanks for all the help.

Best

> Just to make sure I am correct. Is this right for education?

Actually, I probably saw this when I opened your file because I have apprentice license available instead of educational. So in your case you might not have a problem (you should generate .usd instead of .usdnc) so you don't need to modify the Output File path on the ROP USD.

Hi Chris

Thing are still going wrong. So I have zipped up my entire scene (made a new small one). This is with H10.0.499 Windows education version.

In the Stage context you can see my TOP LOP.

-If I generate the USD_to_render_file locally. And then submit that to the farm using the "submit graph as job" on the deadline scheduler all is OK.

-If I use PDG to generate the USD_to_render_file, followed by the USD_render LOP. All remotely on deadline by pressing the "submit graph as job" on the deadline scheduler. It does not work. It loops over itself. I am only rendering 5 frames but as you can see from my deadline screengrab, it seems to keep spanwing way too many renders which all error. I have tried USD and USDNC

Something is going wrong with reading the USD file if it was created via deadline. Although the actual create of said USD file is fine. It is almost as if PDG is not sure how to pick the file up. I have an error log from deadline as well. Best

=======================================================

Error

=======================================================

Error: PDGDeadline exception: Traceback (most recent call last):

File "C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND03\plugins\5ff876cb72f3b3700c5b8220\PDGDeadline.py", line 334, in RenderTasks

self.FailRender('Process returned non-zero exit code: {}'.format(exitCode))

FailRenderException: Process returned non-zero exit code: 1

at Deadline.Plugins.DeadlinePlugin.FailRender(String message)



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

=======================================================

2021-01-08 15:15:04: 0: Loading Job's Plugin timeout is Disabled

2021-01-08 15:15:06: 0: Executing plugin command of type 'Sync Files for Job'

2021-01-08 15:15:06: 0: All job files are already synchronized

2021-01-08 15:15:07: 0: Synchronizing Plugin PDGDeadline from P:/MW10AAH/deadline_test_02/pdgtemp/29448/plugins\PDGDeadline took: 0 seconds

2021-01-08 15:15:07: 0: Done executing plugin command of type 'Sync Files for Job'

2021-01-08 15:15:07: 0: Executing plugin command of type 'Initialize Plugin'

2021-01-08 15:15:07: 0: INFO: Executing plugin script 'C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND03\plugins\5ff876cb72f3b3700c5b8220\PDGDeadline.py'

2021-01-08 15:15:08: 0: INFO: *********** PDGDeadline InitializeProcess

2021-01-08 15:15:08: 0: INFO: About: PDG Plugin for Deadline

2021-01-08 15:15:08: 0: INFO: Render Job As User disabled, running as current user 'renderfarm'

2021-01-08 15:15:08: 0: INFO: The job's environment will be merged with the current environment before rendering

2021-01-08 15:15:08: 0: Done executing plugin command of type 'Initialize Plugin'

2021-01-08 15:15:08: 0: Start Job timeout is disabled.

2021-01-08 15:15:08: 0: Task timeout is 2700 seconds (Regular Task Timeout)

2021-01-08 15:15:08: 0: Loaded job: render_job (5ff876cb72f3b3700c5b8220)

2021-01-08 15:15:08: 0: Executing plugin command of type 'Start Job'

2021-01-08 15:15:08: 0: DEBUG: S3BackedCache Client is not installed.

2021-01-08 15:15:08: 0: INFO: Executing global asset transfer preload script 'C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND03\plugins\5ff876cb72f3b3700c5b8220\GlobalAssetTransferPreLoad.py'

2021-01-08 15:15:08: 0: INFO: Looking for AWS Portal File Transfer...

2021-01-08 15:15:08: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...

2021-01-08 15:15:08: 0: INFO: Could not find AWS Portal File Transfer.

2021-01-08 15:15:08: 0: INFO: AWS Portal File Transfer is not installed on the system.

2021-01-08 15:15:08: 0: Done executing plugin command of type 'Start Job'

2021-01-08 15:15:08: 0: Plugin rendering frame(s): 16

2021-01-08 15:15:08: 0: Executing plugin command of type 'Render Task'

2021-01-08 15:15:08: 0: INFO: StartFrame: 16

2021-01-08 15:15:08: 0: INFO: Startup Directory: P:/MW10AAH/deadline_test_02/pdgtemp/29448

2021-01-08 15:15:08: 0: INFO: Looking for task file: P:/MW10AAH/deadline_test_02/pdgtemp/29448/job_854cd6add4a74fe0867836da97daa3b9\task_16.txt

2021-01-08 15:15:08: 0: CheckPathMapping: Swapped "$PYTHON" with "C:\Program Files\Side Effects Software\Houdini 18.0.499\python27\python.exe"

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable HOUDINI_PATH to P:/MW10AAH/deadline_test_02/pdgtemp/29448;&

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_JOBID to DL_JOB_ID

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable HOUDINI_MAXTHREADS to 0

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_JOBID_VAR to PDG_JOBID

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/29448

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_DIR to P:/MW10AAH/deadline_test_02

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_RESULT_CLIENT_ID to cda59fdd84df42f8b2d92da6ef84bcd8

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_RESULT_SERVER to 147.197.248.206:59572

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_SCRIPTDIR to P:/MW10AAH/deadline_test_02/pdgtemp/29448/scripts

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_MQ_CONN_FILE to P:/MW10AAH/deadline_test_02/pdgtemp/29448/job_854cd6add4a74fe0867836da97daa3b9/pdgmq_server.txt

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_HTTP_PORT to None

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_USE_PDGNET to 1

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_SHARED_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/29448

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_JOBUSE_PDGNET to 1

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_PYATTRIB_LOADER to

2021-01-08 15:15:08: 0: INFO: Setting os PATH with HFS: C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\System32\OpenSSH\;C:\Users\renderfarm\AppData\Local\Microsoft\WindowsApps;;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PATH to C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\System32\OpenSSH\;C:\Users\renderfarm\AppData\Local\Microsoft\WindowsApps;;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/29448

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_SHARED_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/29448

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_SCRIPTDIR to P:/MW10AAH/deadline_test_02/pdgtemp/29448/scripts

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_DIR to P:/MW10AAH/deadline_test_02

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PYTHON to

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_JOBID to 5ff876cb72f3b3700c5b8220

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_JOB_BATCH_NAME to PDG_test_01 username

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_ITEM_NAME to usdrender1_5_4

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_INDEX to 24

2021-01-08 15:15:08: 0: INFO: Submit as job: False

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_SUBMIT_AS_JOB to False

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_RESULT_SERVER to 147.197.248.206:59572

2021-01-08 15:15:08: 0: INFO: PDG_RESULT_SERVER: 147.197.248.206:59572

2021-01-08 15:15:08: 0: INFO: Setting Process Environment Variable PDG_HTTP_PORT to None

2021-01-08 15:15:08: 0: INFO: PDG_HTTP_PORT: None

2021-01-08 15:15:08: 0: INFO: Task Executable: C:\Program Files\Side Effects Software\Houdini 18.0.499\python27\python.exe

2021-01-08 15:15:08: 0: INFO: Task Arguments: "P:/MW10AAH/deadline_test_02/pdgtemp/29448/scripts/usdrender.py" "--hfs" "C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499"

2021-01-08 15:15:08: 0: INFO: Invoking: Run Process

2021-01-08 15:15:09: 0: STDOUT: C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin/husk -o P:/MW10AAH/deadline_test_02/render/PDG_test_01.usdrender1.<F4>.exr --frame 5 --verbose Ca2 P:/MW10AAH/deadline_test_02/usd/usd_render_files/PDG_test_01.ropusd1.usdnc

2021-01-08 15:15:49: 0: STDOUT: EnvControl: HOUDINI_USER_PREF_DIR missing __HVER__, ignored.

2021-01-08 15:15:49: 0: STDOUT: = = = Houdini Package log = = =

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0010_3Delight_for_Houdini.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0020_Alicevision.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0030_MOPS.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0040_MegascansPlugin.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0060_UHConfig_01.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0070_Lynx.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0080_dmnk_tools.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0090_SideFXLabs18.0.json'

2021-01-08 15:15:49: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/hoodle.json'

2021-01-08 15:15:49: 0: STDOUT: C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin/husk version 18.0.499

2021-01-08 15:15:49: 0: STDOUT: Loading: P:/MW10AAH/deadline_test_02/usd/usd_render_files/PDG_test_01.ropusd1.usdnc

2021-01-08 15:15:49: 0: STDOUT: WARNING: Entered non-commercial session mode.

2021-01-08 15:15:49: 0: STDOUT: No camera specified, using '/cameras/renderCamera'

2021-01-08 15:15:49: 0: STDOUT: Load Wall Clock Time: 0:00:32.95

2021-01-08 15:15:49: 0: STDOUT: >>> Render P:/MW10AAH/deadline_test_02/render/PDG_test_01.usdrender1.0005.exr

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 0%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 0%

2021-01-08 15:15:49: 0: STDOUT: Light Tree: 0 lights

2021-01-08 15:15:49: 0: STDOUT: Uniform List: 1 lights

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 1%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 95%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 96%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 97%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 98%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 99%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 100%

2021-01-08 15:15:49: 0: STDOUT: ALF_PROGRESS 100%

2021-01-08 15:15:49: 0: STDOUT: Ray Counts

2021-01-08 15:15:49: 0: STDOUT: primary: 2,156,424

2021-01-08 15:15:49: 0: STDOUT: indirect: 1,211,732

2021-01-08 15:15:49: 0: STDOUT: occlusion: 259,975

2021-01-08 15:15:49: 0: STDOUT: light geo: 0

2021-01-08 15:15:49: 0: STDOUT: probe: 0

2021-01-08 15:15:49: 0: STDOUT: total: 3,628,131

2021-01-08 15:15:49: 0: STDOUT: Frame Wall Clock Time: 0:00:02.99

2021-01-08 15:15:49: 0: STDOUT: Total Wall Clock Time: 0:00:36.63

2021-01-08 15:15:49: 0: STDOUT: Total CPU Time: 0:00:10.65

2021-01-08 15:15:49: 0: STDOUT: System CPU Time Only: 0:00:08.28

2021-01-08 15:15:49: 0: STDOUT: Current Memory Usage: 913.03 MB

2021-01-08 15:15:49: 0: STDOUT: Peak Memory Usage: 913.03 MB

2021-01-08 15:15:49: 0: STDOUT: 15:15:49 PDG_RESULT: usdrender1_5_4;-1;u'__PDG_DIR__/render/PDG_test_01.usdrender1.0005.exr';file/image;0

2021-01-08 15:15:49: 0: STDOUT: 15:15:49 Failed RPC reportResultData with error: PDGnet RPC get-reply failed (error 99999: nonnumeric port: 'None'). Retry 1/4

2021-01-08 15:15:50: 0: STDOUT: 15:15:49 Failed RPC reportResultData with error: PDGnet RPC get-reply failed (error 99999: nonnumeric port: 'None'). Retry 2/4

2021-01-08 15:15:50: 0: STDOUT: 15:15:50 Failed RPC reportResultData with error: PDGnet RPC get-reply failed (error 99999: nonnumeric port: 'None'). Retry 3/4

2021-01-08 15:15:50: 0: STDOUT: 15:15:50 Failed RPC reportResultData with error: PDGnet RPC get-reply failed (error 99999: nonnumeric port: 'None'). Retry 4/4

2021-01-08 15:15:51: 0: STDOUT: 15:15:51 Failed RPC reportResultData with error: PDGnet RPC get-reply failed (error 99999: nonnumeric port: 'None')

2021-01-08 15:15:51: 0: STDOUT: 15:15:51 Failed RPC: reportResultData ()

2021-01-08 15:15:51: 0: STDOUT: Traceback (most recent call last):

2021-01-08 15:15:51: 0: STDOUT: File "P:/MW10AAH/deadline_test_02/pdgtemp/29448/scripts/usdrender.py", line 204, in <module>

2021-01-08 15:15:51: 0: STDOUT: main()

2021-01-08 15:15:51: 0: STDOUT: File "P:/MW10AAH/deadline_test_02/pdgtemp/29448/scripts/usdrender.py", line 175, in main

2021-01-08 15:15:51: 0: STDOUT: work_item.addResultData(imagefile, 'file/image')

2021-01-08 15:15:51: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\29448\scripts\pdgjson.py", line 772, in addResultData

2021-01-08 15:15:51: 0: STDOUT: server_addr=self._server)

2021-01-08 15:15:51: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\29448\scripts\pdgcmd.py", line 514, in reportResultData

2021-01-08 15:15:51: 0: STDOUT: _invokeRpcFn(proxy, 'reportResultData')

2021-01-08 15:15:51: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\29448\scripts\pdgcmd.py", line 271, in _invokeRpcFn

2021-01-08 15:15:51: 0: STDOUT: return _invokePDGNetRpcFn(fn, fn_name, *args)

2021-01-08 15:15:51: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\29448\scripts\pdgcmd.py", line 306, in _invokePDGNetRpcFn

2021-01-08 15:15:51: 0: STDOUT: raise RuntimeError(msg)

2021-01-08 15:15:51: 0: STDOUT: RuntimeError: Failed RPC: reportResultData ()

2021-01-08 15:15:51: 0: Done executing plugin command of type 'Render Task'



=======================================================

Details

=======================================================

Date: 01/08/2021 15:15:53

Frames: 16

Elapsed Time: 00:00:00:50

Job Submit Date: 01/08/2021 15:14:19

Job User: renderfarm

Average RAM Usage: 4544632832 (7%)

Peak RAM Usage: 4813185024 (8%)

Average CPU Usage: 4%

Peak CPU Usage: 15%

Used CPU Clocks (x10^6 cycles): 118908

Total CPU Clocks (x10^6 cycles): 2972685



=======================================================

Worker Information

=======================================================

Worker Name: CTA-B12-REND03

Version: v10.1.4.1 Release (cb470ce90)

Operating System: Windows 10 Education

Running As Service: No

Machine User: renderfarm

IP Address: 147.197.248.203

MAC Address: 0C:C4:7A:E1:4C:34

CPU Architecture: x64

CPUs: 32

CPU Usage: 6%

Memory Usage: 4.5 GB / 63.9 GB (7%)

Free Disk Space: 41.086 GB

Video Card: Microsoft Basic Display Adapter

Hi Again Chris.

Rather than edit the post above I will right here. I think I have manage to fix it. To render remotely the ropusd file was on "all frames in one batch" but the usdrender lop also needs to be "all frames in one batch". I think this my my misunderstanding on my part on what "all frames in one batch" actually means. For the usdrender lop all frames in one batch does not render all frames in one batch (one CPU) it still distributes the frames to multiple CPUs. OK. This did work once. Ands then stopped working. by eck PDG is very random. I have the deadline error log..

=======================================================
Error
=======================================================
Error: PDGDeadline exception: Traceback (most recent call last):
File "C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND25\plugins\5ff8881c02a1ce6e08da7cb1\PDGDeadline.py", line 334, in RenderTasks
self.FailRender('Process returned non-zero exit code: {}'.format(exitCode))
FailRenderException: Process returned non-zero exit code: 1
at Deadline.Plugins.DeadlinePlugin.FailRender(String message)

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
=======================================================
2021-01-08 16:29:13: 0: Loading Job's Plugin timeout is Disabled
2021-01-08 16:29:15: 0: Executing plugin command of type 'Sync Files for Job'
2021-01-08 16:29:15: 0: All job files are already synchronized
2021-01-08 16:29:15: 0: Synchronizing Plugin PDGDeadline from P:/MW10AAH/deadline_test_02/pdgtemp/23792/plugins\PDGDeadline took: 0 seconds
2021-01-08 16:29:15: 0: Done executing plugin command of type 'Sync Files for Job'
2021-01-08 16:29:15: 0: Executing plugin command of type 'Initialize Plugin'
2021-01-08 16:29:16: 0: INFO: Executing plugin script 'C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND25\plugins\5ff8881c02a1ce6e08da7cb1\PDGDeadline.py'
2021-01-08 16:29:16: 0: INFO: *********** PDGDeadline InitializeProcess
2021-01-08 16:29:16: 0: INFO: About: PDG Plugin for Deadline
2021-01-08 16:29:16: 0: INFO: Render Job As User disabled, running as current user 'renderfarm'
2021-01-08 16:29:16: 0: INFO: The job's environment will be merged with the current environment before rendering
2021-01-08 16:29:16: 0: Done executing plugin command of type 'Initialize Plugin'
2021-01-08 16:29:16: 0: Start Job timeout is disabled.
2021-01-08 16:29:16: 0: Task timeout is 2700 seconds (Regular Task Timeout)
2021-01-08 16:29:16: 0: Loaded job: render_job (5ff8881c02a1ce6e08da7cb1)
2021-01-08 16:29:16: 0: Executing plugin command of type 'Start Job'
2021-01-08 16:29:16: 0: DEBUG: S3BackedCache Client is not installed.
2021-01-08 16:29:16: 0: INFO: Executing global asset transfer preload script 'C:\Users\renderfarm\AppData\Local\Thinkbox\Deadline10\slave\CTA-B12-REND25\plugins\5ff8881c02a1ce6e08da7cb1\GlobalAssetTransferPreLoad.py'
2021-01-08 16:29:16: 0: INFO: Looking for AWS Portal File Transfer...
2021-01-08 16:29:16: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...
2021-01-08 16:29:16: 0: INFO: Could not find AWS Portal File Transfer.
2021-01-08 16:29:16: 0: INFO: AWS Portal File Transfer is not installed on the system.
2021-01-08 16:29:16: 0: Done executing plugin command of type 'Start Job'
2021-01-08 16:29:16: 0: Plugin rendering frame(s): 3
2021-01-08 16:29:16: 0: Executing plugin command of type 'Render Task'
2021-01-08 16:29:16: 0: INFO: StartFrame: 3
2021-01-08 16:29:16: 0: INFO: Startup Directory: P:/MW10AAH/deadline_test_02/pdgtemp/23792
2021-01-08 16:29:16: 0: INFO: Looking for task file: P:/MW10AAH/deadline_test_02/pdgtemp/23792/job_f16ad774b9ee481fa3c0505b0a857b6d\task_3.txt
2021-01-08 16:29:16: 0: CheckPathMapping: Swapped "$PYTHON" with "C:\Program Files\Side Effects Software\Houdini 18.0.499\python27\python.exe"
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable HOUDINI_PATH to P:/MW10AAH/deadline_test_02/pdgtemp/23792;&
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_JOBID to DL_JOB_ID
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable HOUDINI_MAXTHREADS to 0
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_JOBID_VAR to PDG_JOBID
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/23792
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_DIR to P:/MW10AAH/deadline_test_02
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_RESULT_CLIENT_ID to 4dfa02d038a846139961a8f6aae717ee
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_RESULT_SERVER to 147.197.248.203:53614
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_SCRIPTDIR to P:/MW10AAH/deadline_test_02/pdgtemp/23792/scripts
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_MQ_CONN_FILE to P:/MW10AAH/deadline_test_02/pdgtemp/23792/job_f16ad774b9ee481fa3c0505b0a857b6d/pdgmq_server.txt
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_HTTP_PORT to None
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_USE_PDGNET to 1
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_SHARED_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/23792
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_JOBUSE_PDGNET to 1
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_PYATTRIB_LOADER to
2021-01-08 16:29:16: 0: INFO: Setting os PATH with HFS: C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\System32\OpenSSH\;C:\Users\renderfarm\AppData\Local\Microsoft\WindowsApps;;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PATH to C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\Library\bin;C:\Program Files\Thinkbox\Deadline10\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\System32\OpenSSH\;C:\Users\renderfarm\AppData\Local\Microsoft\WindowsApps;;C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/23792
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_SHARED_TEMP to P:/MW10AAH/deadline_test_02/pdgtemp/23792
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_SCRIPTDIR to P:/MW10AAH/deadline_test_02/pdgtemp/23792/scripts
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_DIR to P:/MW10AAH/deadline_test_02
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable HFS to C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PYTHON to
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_JOBID to 5ff8881c02a1ce6e08da7cb1
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_JOB_BATCH_NAME to PDG_test_01 username
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_ITEM_NAME to usdrender110
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_INDEX to 10
2021-01-08 16:29:16: 0: INFO: Submit as job: False
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_SUBMIT_AS_JOB to False
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_RESULT_SERVER to 147.197.248.203:53614
2021-01-08 16:29:16: 0: INFO: PDG_RESULT_SERVER: 147.197.248.203:53614
2021-01-08 16:29:16: 0: INFO: Setting Process Environment Variable PDG_HTTP_PORT to None
2021-01-08 16:29:16: 0: INFO: PDG_HTTP_PORT: None
2021-01-08 16:29:16: 0: INFO: Task Executable: C:\Program Files\Side Effects Software\Houdini 18.0.499\python27\python.exe
2021-01-08 16:29:16: 0: INFO: Task Arguments: "P:/MW10AAH/deadline_test_02/pdgtemp/23792/scripts/usdrender.py" "--hfs" "C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499"
2021-01-08 16:29:16: 0: INFO: Invoking: Run Process
2021-01-08 16:29:17: 0: STDOUT: C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin/husk -o P:/MW10AAH/deadline_test_02/render/PDG_test_01.usdrender1.<F4>.exr --frame 1 --frame-count 5 --frame-inc 1 --verbose Ca2 P:/MW10AAH/deadline_test_02/usd/usd_render_files/PDG_test_01.ropusd1.usdnc
2021-01-08 16:29:33: 0: STDOUT: EnvControl: HOUDINI_USER_PREF_DIR missing __HVER__, ignored.
2021-01-08 16:29:33: 0: STDOUT: = = = Houdini Package log = = =
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0010_3Delight_for_Houdini.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0020_Alicevision.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0030_MOPS.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0040_MegascansPlugin.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0060_UHConfig_01.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0070_Lynx.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0080_dmnk_tools.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/0090_SideFXLabs18.0.json'
2021-01-08 16:29:33: 0: STDOUT: Processing 'C:/Docs/houdini18.0/packages/hoodle.json'
2021-01-08 16:29:33: 0: STDOUT: C:/PROGRA~1/SIDEEF~1/HOUDIN~1.499/bin/husk version 18.0.499
2021-01-08 16:29:33: 0: STDOUT: Loading: P:/MW10AAH/deadline_test_02/usd/usd_render_files/PDG_test_01.ropusd1.usdnc
2021-01-08 16:29:33: 0: STDOUT: WARNING: Entered non-commercial session mode.
2021-01-08 16:29:33: 0: STDOUT: No camera specified, using '/cameras/renderCamera'
2021-01-08 16:29:33: 0: STDOUT: Load Wall Clock Time: 0:00:15.79
2021-01-08 16:29:33: 0: STDOUT: 16:29:33 PDG_START: usdrender110;0
2021-01-08 16:29:33: 0: STDOUT: Traceback (most recent call last):
2021-01-08 16:29:33: 0: STDOUT: File "P:/MW10AAH/deadline_test_02/pdgtemp/23792/scripts/usdrender.py", line 204, in <module>
2021-01-08 16:29:33: 0: STDOUT: main()
2021-01-08 16:29:33: 0: STDOUT: File "P:/MW10AAH/deadline_test_02/pdgtemp/23792/scripts/usdrender.py", line 187, in main
2021-01-08 16:29:33: 0: STDOUT: sub_item.setJobState(workItemState.Cooking)
2021-01-08 16:29:33: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\23792\scripts\pdgjson.py", line 594, in setJobState
2021-01-08 16:29:33: 0: STDOUT: pdgcmd.execStartCook(name, self.batchIndex, self._server)
2021-01-08 16:29:33: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\23792\scripts\pdgcmd.py", line 434, in execStartCook
2021-01-08 16:29:33: 0: STDOUT: _invokeRpc(s, "start_cook_batch", item_name, subindex, theJobid)
2021-01-08 16:29:33: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\23792\scripts\pdgcmd.py", line 267, in _invokeRpc
2021-01-08 16:29:33: 0: STDOUT: return _invokeRpcFn(fn, fn_name, *args)
2021-01-08 16:29:33: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\23792\scripts\pdgcmd.py", line 271, in _invokeRpcFn
2021-01-08 16:29:33: 0: STDOUT: return _invokePDGNetRpcFn(fn, fn_name, *args)
2021-01-08 16:29:33: 0: STDOUT: File "P:\MW10AAH\deadline_test_02\pdgtemp\23792\scripts\pdgcmd.py", line 286, in _invokePDGNetRpcFn
2021-01-08 16:29:33: 0: STDOUT: if fn.lasterror == 5 or fn.lasterror == 6:
2021-01-08 16:29:33: 0: STDOUT: AttributeError: 'PDGNetRPCMessage' object has no attribute 'lasterror'
2021-01-08 16:29:34: 0: Done executing plugin command of type 'Render Task'

=======================================================
Details
=======================================================
Date: 01/08/2021 16:29:36
Frames: 3
Elapsed Time: 00:00:00:24
Job Submit Date: 01/08/2021 16:28:12
Job User: renderfarm
Average RAM Usage: 4135449600 (7%)
Peak RAM Usage: 4319981568 (7%)
Average CPU Usage: 1%
Peak CPU Usage: 3%
Used CPU Clocks (x10^6 cycles): 12688
Total CPU Clocks (x10^6 cycles): 1268738

=======================================================
Worker Information
=======================================================
Worker Name: CTA-B12-REND25
Version: v10.1.4.1 Release (cb470ce90)
Operating System: Windows 10 Education
Running As Service: No
Machine User: renderfarm
IP Address: 147.197.248.225
MAC Address: 0C:C4:7A:E1:56:BC
CPU Architecture: x64
CPUs: 32
CPU Usage: 3%
Memory Usage: 4.0 GB / 63.9 GB (6%)
Free Disk Space: 40.989 GB
Video Card: Microsoft Basic Display Adapter


Best

Could you try setting PDG_USE_PDGNET=0 in your Houdini environment? This will cause the deadline scheduler to use a different method for communicating back to Houdini.

I think this may be a bug that was fixed in subsequent builds of 18.0.

Hi. Thanks for that. I will test whrn we update our farm best