Hi Seelan,

While I'm debugging the above, there's something else that I would love to get your help with.
When running a TOPs dependency tree using “Submit Graph as Job” I'm running into 2 problems:
- custom Python modules don't get picked up
- custom environment variables are not being passed along

We're always launching our Houdini scenes in a specific show/sequence/shot environment.
The “PYTHONPATH” env variable specifies where to pick up custom Python modules and we're also passing some env variables such as “$SHOW”, “$SEQ”, “$SHOT” and so on.

If I run the same TOPs graph using “Dirty and cook selected mode”, it works just fine.

Here's a log in which I have a custom OTL in the /OUT/ context that imports some custom modules, on top of that I have a Python Script TOP printing some environment variables using "print os.environ for example.

Can I please get your feedback on this? Is there something that I'm doing wrong on my side?

=======================================================
Error
=======================================================
Error: Process returned non-zero exit code: 1
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 arh)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ahl)

=======================================================
Log
=======================================================
2019-09-20 12:27:09: 0: Loading Job's Plugin timeout is Disabled
2019-09-20 12:27:11: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-20 12:27:11: 0: All job files are already synchronized
2019-09-20 12:27:11: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/plugins\PDGDeadline took: 0 seconds
2019-09-20 12:27:11: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-20 12:27:11: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-20 12:27:12: 0: INFO: Executing plugin script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85280829c0293e6ccadb10\PDGDeadline.py’
2019-09-20 12:27:12: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-20 12:27:12: 0: INFO: About: PDG Plugin for Deadline
2019-09-20 12:27:12: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper01’
2019-09-20 12:27:12: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-20 12:27:12: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-20 12:27:12: 0: Start Job timeout is disabled.
2019-09-20 12:27:12: 0: Task timeout is disabled.
2019-09-20 12:27:12: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d85280829c0293e6ccadb10)
2019-09-20 12:27:12: 0: Executing plugin command of type ‘Start Job’
2019-09-20 12:27:12: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85280829c0293e6ccadb10\GlobalJobPreLoad.py’
2019-09-20 12:27:12: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-20 12:27:12: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-20 12:27:12: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-20 12:27:12: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-20 12:27:12: 0: Done executing plugin command of type ‘Start Job’
2019-09-20 12:27:12: 0: Plugin rendering frame(s): 0
2019-09-20 12:27:12: 0: Executing plugin command of type ‘Render Task’
2019-09-20 12:27:12: 0: INFO: StartFrame: 0
2019-09-20 12:27:12: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860
2019-09-20 12:27:12: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/job_16b1c15bc93844828ed0837ccdb46a28\task_0.txt
2019-09-20 12:27:12: 0: INFO: Setting PATH: C:\Program Files\Thinkbox\Deadline10\bin\;C:\Program Files (x86)\Common Files\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Python27;C:\python27\lib\site-packages;C:\Python27\Scripts;C:\Program Files\MongoDB\Server\3.4\bin;C:\Program Files\Sublime Text 3;C:\Program Files\Git\cmd;C:\WINDOWS\System32\OpenSSH\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper01\AppData\Local\Microsoft\WindowsApps;C:\Users\Stormripper01\AppData\Local\GitHubDesktop\bin;%USERPROFILE%\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.384/bin
2019-09-20 12:27:12: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 12:27:12: 0: INFO: Task Executable: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 12:27:12: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/scripts/top.py –report none –hip P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip –toppath /obj/topnet1
2019-09-20 12:27:12: 0: INFO: Invoking: Run Process
2019-09-20 12:27:19: 0: STDOUT: Running Houdini 17.5.384
2019-09-20 12:27:19: 0: STDOUT: Loading .hip file P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip.
2019-09-20 12:27:23: 0: STDOUT: Error running event handler:
2019-09-20 12:27:23: 0: STDOUT: Traceback (most recent call last):
2019-09-20 12:27:23: 0: STDOUT: File “opdef:/storm:river/deadlineoutsubmitter::0.5?PythonModule”, line 10, in <module>
2019-09-20 12:27:23: 0: STDOUT: File “Z:\tools\python\deadline\HoudiniJobInterpreter.py”, line 24, in <module>
2019-09-20 12:27:23: 0: STDOUT: from sbHou import sbException, sbCam, sbShotInfo, sbNaming
2019-09-20 12:27:23: 0: STDOUT: ImportError: No module named sbHou
2019-09-20 12:27:23: 0: STDOUT: Given Node ‘topnet1’, Cooking Node ‘objectTest’
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 OnStartCook()
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 PDGMQ as separate task: False
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Local Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-20 12:27:24: 0: STDOUT: Remote Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Starting deadline command process
2019-09-20 12:27:24: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:27:24: 0: STDOUT: client:
2019-09-20 12:27:24: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:27:24: 0: STDOUT: client:
2019-09-20 12:27:24: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:27:24: 0: STDOUT: client: 12:27:23 onStopCook()
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Cancelling tick timer
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Stopping shared servers
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 No root job running in onStopCook
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Stopping MQ Relay server
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 MQ Relay stopped
2019-09-20 12:27:24: 0: STDOUT: 12:27:23 Stopping deadline command process
2019-09-20 12:27:24: 0: STDOUT: From node pythonscript1:
2019-09-20 12:27:24: 0: STDOUT: pythonscript1 failed to run script: Traceback (most recent call last):
2019-09-20 12:27:24: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:27:25: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:27:25: 0: STDOUT: return self.data
2019-09-20 12:27:25: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:27:25: 0: STDOUT: pythonscript1_2 failed to run script: Traceback (most recent call last):
2019-09-20 12:27:25: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:27:25: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:27:25: 0: STDOUT: return self.data
2019-09-20 12:27:25: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:27:25: 0: STDOUT: pythonscript1_1 failed to run script: Traceback (most recent call last):
2019-09-20 12:27:25: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:27:25: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:27:25: 0: STDOUT: return self.data
2019-09-20 12:27:25: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:27:25: 0: STDOUT: Traceback (most recent call last):
2019-09-20 12:27:25: 0: STDOUT: File “P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/scripts/top.py”, line 223, in <module>
2019-09-20 12:27:25: 0: STDOUT: exit(1)
2019-09-20 12:27:25: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\site.py”, line 351, in __call__
2019-09-20 12:27:25: 0: STDOUT: raise SystemExit(code)
2019-09-20 12:27:25: 0: STDOUT: SystemExit: 1
2019-09-20 12:27:25: 0: Done executing plugin command of type ‘Render Task’

=======================================================
Details
=======================================================
Date: 09/20/2019 12:27:28
Frames: 0
Elapsed Time: 00:00:00:18
Job Submit Date: 09/20/2019 12:27:04
Job User: stormripper01
Average RAM Usage: 16131113984 (12%)
Peak RAM Usage: 16179605504 (12%)
Average CPU Usage: 7%
Peak CPU Usage: 11%
Used CPU Clocks (x10^6 cycles): 118088
Total CPU Clocks (x10^6 cycles): 1686969

=======================================================
Slave Information
=======================================================
Slave Name: STORMRIPPER01
Version: v10.0.9.4 Release (b6c080b1a)
Operating System: Windows 10 Pro
Running As Service: No
Machine User: Stormripper01
IP Address: 192.168.100.10
MAC Address: 00:0A:CD:2D:29:5C
CPU Architecture: x64
CPUs: 32
CPU Usage: 5%
Memory Usage: 15.0 GB / 127.9 GB (11%)
Free Disk Space: 1.406 TB (58.347 GB on C:\, 1.349 TB on D:\)
Video Card: NVIDIA GeForce GTX 1080

You'll need to turn on Inherit Local Environment in the Task Environment section under Job Parms on the TOP Deadline scheduler. This will forward your Houdini envs to each work item.

You can also set specific environments using the Key-Value parm below that called Environment Key-Values. This sets individual envs for Deadline jobs.

Hi Seelan,

Thanks for the reply. After checking this parameter, I'm getting the same errors in the log.
Should I expect that environment variables such as PYTHONPATH or CLIENT, SHOW, SEQ, SHOT are being inherited now or do I still need to import those manually using the Key-Value parm below?

2019-09-20 12:28:20: 0: Loading Job's Plugin timeout is Disabled
2019-09-20 12:28:22: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-20 12:28:22: 0: All job files are already synchronized
2019-09-20 12:28:22: 0: Plugin PDGDeadline was already synchronized.
2019-09-20 12:28:22: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-20 12:28:22: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-20 12:28:22: 0: INFO: Executing plugin script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85280829c0293e6ccadb10\PDGDeadline.py’
2019-09-20 12:28:23: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-20 12:28:23: 0: INFO: About: PDG Plugin for Deadline
2019-09-20 12:28:23: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper01’
2019-09-20 12:28:23: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-20 12:28:23: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-20 12:28:23: 0: Start Job timeout is disabled.
2019-09-20 12:28:23: 0: Task timeout is disabled.
2019-09-20 12:28:23: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d85280829c0293e6ccadb10)
2019-09-20 12:28:23: 0: Executing plugin command of type ‘Start Job’
2019-09-20 12:28:23: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85280829c0293e6ccadb10\GlobalJobPreLoad.py’
2019-09-20 12:28:23: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-20 12:28:23: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-20 12:28:23: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-20 12:28:23: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-20 12:28:23: 0: Done executing plugin command of type ‘Start Job’
2019-09-20 12:28:23: 0: Plugin rendering frame(s): 0
2019-09-20 12:28:23: 0: Executing plugin command of type ‘Render Task’
2019-09-20 12:28:23: 0: INFO: StartFrame: 0
2019-09-20 12:28:23: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860
2019-09-20 12:28:23: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/job_16b1c15bc93844828ed0837ccdb46a28\task_0.txt
2019-09-20 12:28:23: 0: INFO: Setting PATH: C:\Program Files\Thinkbox\Deadline10\bin\;C:\Program Files (x86)\Common Files\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Python27;C:\python27\lib\site-packages;C:\Python27\Scripts;C:\Program Files\MongoDB\Server\3.4\bin;C:\Program Files\Sublime Text 3;C:\Program Files\Git\cmd;C:\WINDOWS\System32\OpenSSH\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper01\AppData\Local\Microsoft\WindowsApps;C:\Users\Stormripper01\AppData\Local\GitHubDesktop\bin;%USERPROFILE%\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.384/bin
2019-09-20 12:28:23: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 12:28:23: 0: INFO: Task Executable: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 12:28:23: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/scripts/top.py –report none –hip P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip –toppath /obj/topnet1
2019-09-20 12:28:23: 0: INFO: Invoking: Run Process
2019-09-20 12:28:29: 0: STDOUT: Running Houdini 17.5.384
2019-09-20 12:28:29: 0: STDOUT: Loading .hip file P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip.
2019-09-20 12:28:33: 0: STDOUT: Error running event handler:
2019-09-20 12:28:33: 0: STDOUT: Traceback (most recent call last):
2019-09-20 12:28:33: 0: STDOUT: File “opdef:/storm:river/deadlineoutsubmitter::0.5?PythonModule”, line 10, in <module>
2019-09-20 12:28:33: 0: STDOUT: File “Z:\tools\python\deadline\HoudiniJobInterpreter.py”, line 24, in <module>
2019-09-20 12:28:33: 0: STDOUT: from sbHou import sbException, sbCam, sbShotInfo, sbNaming
2019-09-20 12:28:33: 0: STDOUT: ImportError: No module named sbHou
2019-09-20 12:28:33: 0: STDOUT: Given Node ‘topnet1’, Cooking Node ‘objectTest’
2019-09-20 12:28:34: 0: STDOUT: 12:28:33 OnStartCook()
2019-09-20 12:28:34: 0: STDOUT: 12:28:33 PDGMQ as separate task: False
2019-09-20 12:28:34: 0: STDOUT: 12:28:33 Local Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-20 12:28:34: 0: STDOUT: Remote Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-20 12:28:34: 0: STDOUT: 12:28:33 Starting deadline command process
2019-09-20 12:28:34: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:28:34: 0: STDOUT: client:
2019-09-20 12:28:34: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:28:34: 0: STDOUT: client:
2019-09-20 12:28:34: 0: STDOUT: Checking ENV variables ———————————————-
2019-09-20 12:28:34: 0: STDOUT: client: 12:28:33 onStopCook()
2019-09-20 12:28:34: 0: STDOUT: 12:28:33 Cancelling tick timer
2019-09-20 12:28:35: 0: STDOUT: 12:28:33 Stopping shared servers
2019-09-20 12:28:35: 0: STDOUT: 12:28:33 No root job running in onStopCook
2019-09-20 12:28:35: 0: STDOUT: 12:28:33 Stopping MQ Relay server
2019-09-20 12:28:35: 0: STDOUT: 12:28:33 MQ Relay stopped
2019-09-20 12:28:35: 0: STDOUT: 12:28:33 Stopping deadline command process
2019-09-20 12:28:35: 0: STDOUT: From node pythonscript1:
2019-09-20 12:28:35: 0: STDOUT: pythonscript1_2 failed to run script: Traceback (most recent call last):
2019-09-20 12:28:35: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:28:35: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:28:35: 0: STDOUT: return self.data
2019-09-20 12:28:35: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:28:35: 0: STDOUT: pythonscript1_1 failed to run script: Traceback (most recent call last):
2019-09-20 12:28:35: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:28:35: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:28:35: 0: STDOUT: return self.data
2019-09-20 12:28:35: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:28:35: 0: STDOUT: pythonscript1 failed to run script: Traceback (most recent call last):
2019-09-20 12:28:35: 0: STDOUT: File “pythonscript1_script”, line 13, in <module>
2019-09-20 12:28:35: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\os.py”, line 425, in __getitem__
2019-09-20 12:28:36: 0: STDOUT: return self.data
2019-09-20 12:28:36: 0: STDOUT: KeyError: ('CLIENT',)
2019-09-20 12:28:36: 0: STDOUT: Traceback (most recent call last):
2019-09-20 12:28:36: 0: STDOUT: File “P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/18860/scripts/top.py”, line 223, in <module>
2019-09-20 12:28:36: 0: STDOUT: exit(1)
2019-09-20 12:28:36: 0: STDOUT: File “C:/houdini/17.5.384/python27\lib\site.py”, line 351, in __call__
2019-09-20 12:28:36: 0: STDOUT: raise SystemExit(code)
2019-09-20 12:28:36: 0: STDOUT: SystemExit: 1
2019-09-20 12:28:36: 0: Done executing plugin command of type ‘Render Task’
2019-09-20 12:28:36: 0: Executing plugin command of type ‘End Job’
2019-09-20 12:28:36: 0: Done executing plugin command of type ‘End Job’
2019-09-20 12:28:38: Scheduler Thread - Render Thread 0 threw a major error:
2019-09-20 12:28:38: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2019-09-20 12:28:38: Exception Details
2019-09-20 12:28:38: RenderPluginException – Error: Process returned non-zero exit code: 1
2019-09-20 12:28:38: at Deadline.Plugins.PluginWrapper.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage, AbortLevel& abortLevel)
2019-09-20 12:28:38: RenderPluginException.Cause: JobError (2)
2019-09-20 12:28:38: RenderPluginException.Level: Major (1)
2019-09-20 12:28:38: RenderPluginException.HasSlaveLog: True
2019-09-20 12:28:38: RenderPluginException.SlaveLogFileName: C:\ProgramData\Thinkbox\Deadline10\logs\deadlineslave_renderthread_0-STORMRIPPER01-0000.log
2019-09-20 12:28:38: Exception.Data: ( )
2019-09-20 12:28:38: Exception.TargetSite: Deadline.Slaves.Messaging.PluginResponseMemento d(Deadline.Net.DeadlineMessage)
2019-09-20 12:28:38: Exception.Source: deadline
2019-09-20 12:28:38: Exception.HResult: -2146233088
2019-09-20 12:28:38: Exception.StackTrace:
2019-09-20 12:28:38: at Deadline.Plugins.SandboxedPlugin.d(DeadlineMessage arh)
2019-09-20 12:28:38: at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
2019-09-20 12:28:38: at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ahl)
2019-09-20 12:28:38: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2019-09-20 12:28:55: Skipping pending job scan because it is not required at this time
2019-09-20 12:28:55: Skipping repository repair because it is not required at this time
2019-09-20 12:28:55: Skipping house cleaning because it is not required at this time
2019-09-20 12:29:57: Skipping pending job scan because it is not required at this time
2019-09-20 12:29:57: Skipping repository repair because it is not required at this time
2019-09-20 12:29:57: Skipping house cleaning because it is not required at this time
2019-09-20 12:31:02: Skipping pending job scan because it is not required at this time
2019-09-20 12:31:02: Skipping repository repair because it is not required at this time
2019-09-20 12:31:02: Skipping house cleaning because it is not required at this time
2019-09-20 12:32:07: Skipping pending job scan because it is not required at this time
2019-09-20 12:32:07: Skipping repository repair because it is not required at this time
2019-09-20 12:32:07: Skipping house cleaning because it is not required at this time
2019-09-20 12:33:13: Skipping pending job scan because it is not required at this time
2019-09-20 12:33:13: Skipping repository repair because it is not required at this time
2019-09-20 12:33:13: Skipping house cleaning because it is not required at this time
2019-09-20 12:34:15: Skipping pending job scan because it is not required at this time
2019-09-20 12:34:15: Skipping repository repair because it is not required at this time
2019-09-20 12:34:15: Skipping house cleaning because it is not required at this time
2019-09-20 12:35:19: Skipping pending job scan because it is not required at this time
2019-09-20 12:35:19: Skipping repository repair because it is not required at this time
2019-09-20 12:35:19: Skipping house cleaning because it is not required at this time
2019-09-20 12:36:22: Skipping pending job scan because it is not required at this time
2019-09-20 12:36:22: Skipping repository repair because it is not required at this time
2019-09-20 12:36:22: Skipping house cleaning because it is not required at this time
2019-09-20 12:37:30: Skipping pending job scan because it is not required at this time
2019-09-20 12:37:30: Skipping repository repair because it is not required at this time
2019-09-20 12:37:30: Skipping house cleaning because it is not required at this time
2019-09-20 12:38:34: Skipping pending job scan because it is not required at this time
2019-09-20 12:38:34: Skipping repository repair because it is not required at this time
2019-09-20 12:38:34: Skipping house cleaning because it is not required at this time
2019-09-20 12:39:37: Skipping pending job scan because it is not required at this time
2019-09-20 12:39:37: Skipping repository repair because it is not required at this time
2019-09-20 12:39:37: Skipping house cleaning because it is not required at this time
2019-09-20 12:40:39: Skipping pending job scan because it is not required at this time
2019-09-20 12:40:39: Skipping repository repair because it is not required at this time
2019-09-20 12:40:39: Skipping house cleaning because it is not required at this time
2019-09-20 12:41:46: Skipping pending job scan because it is not required at this time
2019-09-20 12:41:46: Skipping repository repair because it is not required at this time
2019-09-20 12:41:46: Skipping house cleaning because it is not required at this time
2019-09-20 12:42:47: Skipping pending job scan because it is not required at this time
2019-09-20 12:42:47: Skipping repository repair because it is not required at this time
2019-09-20 12:42:47: Skipping house cleaning because it is not required at this time
2019-09-20 12:43:54: Skipping pending job scan because it is not required at this time
2019-09-20 12:43:54: Skipping repository repair because it is not required at this time
2019-09-20 12:43:54: Skipping house cleaning because it is not required at this time
2019-09-20 12:44:57: Skipping pending job scan because it is not required at this time
2019-09-20 12:44:57: Skipping repository repair because it is not required at this time
2019-09-20 12:44:57: Skipping house cleaning because it is not required at this time
2019-09-20 12:46:00: Skipping pending job scan because it is not required at this time
2019-09-20 12:46:00: Skipping repository repair because it is not required at this time
2019-09-20 12:46:00: Skipping house cleaning because it is not required at this time
2019-09-20 12:47:06: Skipping pending job scan because it is not required at this time
2019-09-20 12:47:06: Skipping repository repair because it is not required at this time
2019-09-20 12:47:06: Skipping house cleaning because it is not required at this time
2019-09-20 12:48:07: Skipping pending job scan because it is not required at this time
2019-09-20 12:48:07: Skipping repository repair because it is not required at this time
2019-09-20 12:48:07: Skipping house cleaning because it is not required at this time
2019-09-20 12:49:13: Skipping pending job scan because it is not required at this time
2019-09-20 12:49:13: Skipping repository repair because it is not required at this time
2019-09-20 12:49:13: Skipping house cleaning because it is not required at this time
2019-09-20 12:50:19: Skipping pending job scan because it is not required at this time
2019-09-20 12:50:19: Skipping repository repair because it is not required at this time
2019-09-20 12:50:19: Skipping house cleaning because it is not required at this time
2019-09-20 12:51:23: Skipping pending job scan because it is not required at this time
2019-09-20 12:51:23: Skipping repository repair because it is not required at this time
2019-09-20 12:51:23: Skipping house cleaning because it is not required at this time
2019-09-20 12:52:30: Skipping pending job scan because it is not required at this time
2019-09-20 12:52:30: Skipping repository repair because it is not required at this time
2019-09-20 12:52:30: Skipping house cleaning because it is not required at this time
2019-09-20 12:53:36: Skipping pending job scan because it is not required at this time
2019-09-20 12:53:36: Skipping repository repair because it is not required at this time
2019-09-20 12:53:36: Skipping house cleaning because it is not required at this time
2019-09-20 12:54:38: Skipping pending job scan because it is not required at this time
2019-09-20 12:54:38: Skipping repository repair because it is not required at this time
2019-09-20 12:54:38: Skipping house cleaning because it is not required at this time
2019-09-20 12:55:41: Skipping pending job scan because it is not required at this time
2019-09-20 12:55:41: Skipping repository repair because it is not required at this time
2019-09-20 12:55:41: Skipping house cleaning because it is not required at this time
2019-09-20 12:56:44: Skipping pending job scan because it is not required at this time
2019-09-20 12:56:44: Skipping repository repair because it is not required at this time
2019-09-20 12:56:44: Skipping house cleaning because it is not required at this time
2019-09-20 12:57:45: Skipping pending job scan because it is not required at this time
2019-09-20 12:57:45: Skipping repository repair because it is not required at this time
2019-09-20 12:57:45: Skipping house cleaning because it is not required at this time
2019-09-20 12:58:49: Skipping pending job scan because it is not required at this time
2019-09-20 12:58:49: Skipping repository repair because it is not required at this time
2019-09-20 12:58:49: Skipping house cleaning because it is not required at this time
2019-09-20 12:59:55: Skipping pending job scan because it is not required at this time
2019-09-20 12:59:55: Skipping repository repair because it is not required at this time
2019-09-20 12:59:55: Skipping house cleaning because it is not required at this time
2019-09-20 13:01:02: Skipping pending job scan because it is not required at this time
2019-09-20 13:01:02: Skipping repository repair because it is not required at this time
2019-09-20 13:01:02: Skipping house cleaning because it is not required at this time
2019-09-20 13:02:05: Skipping pending job scan because it is not required at this time
2019-09-20 13:02:05: Skipping repository repair because it is not required at this time
2019-09-20 13:02:05: Skipping house cleaning because it is not required at this time
2019-09-20 13:03:08: Skipping pending job scan because it is not required at this time
2019-09-20 13:03:08: Skipping repository repair because it is not required at this time
2019-09-20 13:03:08: Skipping house cleaning because it is not required at this time
2019-09-20 13:04:09: Skipping pending job scan because it is not required at this time
2019-09-20 13:04:09: Skipping repository repair because it is not required at this time
2019-09-20 13:04:09: Skipping house cleaning because it is not required at this time
2019-09-20 13:05:17: Skipping pending job scan because it is not required at this time
2019-09-20 13:05:17: Skipping repository repair because it is not required at this time
2019-09-20 13:05:17: Skipping house cleaning because it is not required at this time
2019-09-20 13:06:18: Skipping pending job scan because it is not required at this time
2019-09-20 13:06:18: Skipping repository repair because it is not required at this time
2019-09-20 13:06:18: Skipping house cleaning because it is not required at this time
2019-09-20 13:07:24: Skipping pending job scan because it is not required at this time
2019-09-20 13:07:24: Skipping repository repair because it is not required at this time
2019-09-20 13:07:24: Skipping house cleaning because it is not required at this time
2019-09-20 13:08:31: Skipping pending job scan because it is not required at this time
2019-09-20 13:08:31: Skipping repository repair because it is not required at this time
2019-09-20 13:08:31: Skipping house cleaning because it is not required at this time
2019-09-20 13:09:37: Skipping pending job scan because it is not required at this time
2019-09-20 13:09:37: Skipping repository repair because it is not required at this time
2019-09-20 13:09:37: Skipping house cleaning because it is not required at this time
2019-09-20 13:10:43: Skipping pending job scan because it is not required at this time
2019-09-20 13:10:43: Skipping repository repair because it is not required at this time
2019-09-20 13:10:43: Skipping house cleaning because it is not required at this time
2019-09-20 13:11:48: Skipping pending job scan because it is not required at this time
2019-09-20 13:11:48: Skipping repository repair because it is not required at this time
2019-09-20 13:11:48: Skipping house cleaning because it is not required at this time
2019-09-20 13:12:51: Skipping pending job scan because it is not required at this time
2019-09-20 13:12:51: Skipping repository repair because it is not required at this time
2019-09-20 13:12:51: Skipping house cleaning because it is not required at this time
2019-09-20 13:13:57: Skipping pending job scan because it is not required at this time
2019-09-20 13:13:57: Skipping repository repair because it is not required at this time
2019-09-20 13:13:57: Skipping house cleaning because it is not required at this time
2019-09-20 13:15:03: Skipping pending job scan because it is not required at this time
2019-09-20 13:15:03: Skipping repository repair because it is not required at this time
2019-09-20 13:15:03: Skipping house cleaning because it is not required at this time
2019-09-20 13:16:06: Skipping pending job scan because it is not required at this time
2019-09-20 13:16:06: Skipping repository repair because it is not required at this time
2019-09-20 13:16:06: Skipping house cleaning because it is not required at this time
2019-09-20 13:17:10: Skipping pending job scan because it is not required at this time
2019-09-20 13:17:10: Skipping repository repair because it is not required at this time
2019-09-20 13:17:10: Skipping house cleaning because it is not required at this time
2019-09-20 13:18:16: Skipping pending job scan because it is not required at this time
2019-09-20 13:18:16: Skipping repository repair because it is not required at this time
2019-09-20 13:18:16: Skipping house cleaning because it is not required at this time
2019-09-20 13:19:17: Skipping pending job scan because it is not required at this time
2019-09-20 13:19:17: Skipping repository repair because it is not required at this time
2019-09-20 13:19:17: Skipping house cleaning because it is not required at this time
2019-09-20 13:20:24: Skipping pending job scan because it is not required at this time
2019-09-20 13:20:24: Skipping repository repair because it is not required at this time
2019-09-20 13:20:24: Skipping house cleaning because it is not required at this time
2019-09-20 13:21:28: Skipping pending job scan because it is not required at this time
2019-09-20 13:21:28: Skipping repository repair because it is not required at this time
2019-09-20 13:21:28: Skipping house cleaning because it is not required at this time
2019-09-20 13:22:34: Skipping pending job scan because it is not required at this time
2019-09-20 13:22:34: Skipping repository repair because it is not required at this time
2019-09-20 13:22:34: Skipping house cleaning because it is not required at this time
2019-09-20 13:23:38: Skipping pending job scan because it is not required at this time
2019-09-20 13:23:38: Skipping repository repair because it is not required at this time
2019-09-20 13:23:38: Skipping house cleaning because it is not required at this time
2019-09-20 13:24:43: Skipping pending job scan because it is not required at this time
2019-09-20 13:24:43: Skipping repository repair because it is not required at this time
2019-09-20 13:24:43: Skipping house cleaning because it is not required at this time
2019-09-20 13:25:49: Skipping pending job scan because it is not required at this time
2019-09-20 13:25:49: Skipping repository repair because it is not required at this time
2019-09-20 13:25:49: Skipping house cleaning because it is not required at this time
2019-09-20 13:26:54: Skipping pending job scan because it is not required at this time
2019-09-20 13:26:54: Skipping repository repair because it is not required at this time
2019-09-20 13:26:54: Skipping house cleaning because it is not required at this time
2019-09-20 13:27:58: Skipping pending job scan because it is not required at this time
2019-09-20 13:27:58: Skipping repository repair because it is not required at this time
2019-09-20 13:27:58: Skipping house cleaning because it is not required at this time
2019-09-20 13:29:02: Skipping pending job scan because it is not required at this time
2019-09-20 13:29:02: Skipping repository repair because it is not required at this time
2019-09-20 13:29:02: Skipping house cleaning because it is not required at this time
2019-09-20 13:30:07: Skipping pending job scan because it is not required at this time
2019-09-20 13:30:07: Skipping repository repair because it is not required at this time
2019-09-20 13:30:07: Skipping house cleaning because it is not required at this time
2019-09-20 13:31:08: Skipping pending job scan because it is not required at this time
2019-09-20 13:31:08: Skipping repository repair because it is not required at this time
2019-09-20 13:31:08: Skipping house cleaning because it is not required at this time
2019-09-20 13:32:11: Skipping pending job scan because it is not required at this time
2019-09-20 13:32:11: Skipping repository repair because it is not required at this time
2019-09-20 13:32:11: Skipping house cleaning because it is not required at this time
2019-09-20 13:33:14: Skipping pending job scan because it is not required at this time
2019-09-20 13:33:14: Skipping repository repair because it is not required at this time
2019-09-20 13:33:14: Skipping house cleaning because it is not required at this time
2019-09-20 13:34:16: Skipping pending job scan because it is not required at this time
2019-09-20 13:34:16: Skipping repository repair because it is not required at this time
2019-09-20 13:34:16: Skipping house cleaning because it is not required at this time
2019-09-20 13:35:18: Skipping pending job scan because it is not required at this time
2019-09-20 13:35:18: Skipping repository repair because it is not required at this time
2019-09-20 13:35:18: Skipping house cleaning because it is not required at this time
2019-09-20 13:36:22: Skipping pending job scan because it is not required at this time
2019-09-20 13:36:22: Skipping repository repair because it is not required at this time
2019-09-20 13:36:22: Skipping house cleaning because it is not required at this time
2019-09-20 13:37:23: Skipping pending job scan because it is not required at this time
2019-09-20 13:37:23: Skipping repository repair because it is not required at this time
2019-09-20 13:37:23: Skipping house cleaning because it is not required at this time
2019-09-20 13:38:31: Skipping pending job scan because it is not required at this time
2019-09-20 13:38:31: Skipping repository repair because it is not required at this time
2019-09-20 13:38:31: Skipping house cleaning because it is not required at this time
2019-09-20 13:39:34: Skipping pending job scan because it is not required at this time
2019-09-20 13:39:34: Skipping repository repair because it is not required at this time
2019-09-20 13:39:34: Skipping house cleaning because it is not required at this time
2019-09-20 13:40:41: Skipping pending job scan because it is not required at this time
2019-09-20 13:40:41: Skipping repository repair because it is not required at this time
2019-09-20 13:40:41: Skipping house cleaning because it is not required at this time
2019-09-20 13:41:47: Skipping pending job scan because it is not required at this time
2019-09-20 13:41:47: Skipping repository repair because it is not required at this time
2019-09-20 13:41:47: Skipping house cleaning because it is not required at this time
2019-09-20 13:42:48: Skipping pending job scan because it is not required at this time
2019-09-20 13:42:48: Skipping repository repair because it is not required at this time
2019-09-20 13:42:48: Skipping house cleaning because it is not required at this time
2019-09-20 13:43:49: Skipping pending job scan because it is not required at this time
2019-09-20 13:43:49: Skipping repository repair because it is not required at this time
2019-09-20 13:43:49: Skipping house cleaning because it is not required at this time
2019-09-20 13:44:50: Skipping pending job scan because it is not required at this time
2019-09-20 13:44:50: Skipping repository repair because it is not required at this time
2019-09-20 13:44:50: Skipping house cleaning because it is not required at this time
2019-09-20 13:45:54: Skipping pending job scan because it is not required at this time
2019-09-20 13:45:54: Skipping repository repair because it is not required at this time
2019-09-20 13:45:54: Skipping house cleaning because it is not required at this time
2019-09-20 13:46:56: Skipping pending job scan because it is not required at this time
2019-09-20 13:46:56: Skipping repository repair because it is not required at this time
2019-09-20 13:46:56: Skipping house cleaning because it is not required at this time
2019-09-20 13:47:57: Skipping pending job scan because it is not required at this time
2019-09-20 13:47:57: Skipping repository repair because it is not required at this time
2019-09-20 13:47:57: Skipping house cleaning because it is not required at this time
2019-09-20 13:49:03: Skipping pending job scan because it is not required at this time
2019-09-20 13:49:03: Skipping repository repair because it is not required at this time
2019-09-20 13:49:03: Skipping house cleaning because it is not required at this time
2019-09-20 13:50:05: Skipping pending job scan because it is not required at this time
2019-09-20 13:50:05: Skipping repository repair because it is not required at this time
2019-09-20 13:50:05: Skipping house cleaning because it is not required at this time
2019-09-20 13:51:06: Skipping pending job scan because it is not required at this time
2019-09-20 13:51:06: Skipping repository repair because it is not required at this time
2019-09-20 13:51:06: Skipping house cleaning because it is not required at this time
2019-09-20 13:52:10: Skipping pending job scan because it is not required at this time
2019-09-20 13:52:10: Skipping repository repair because it is not required at this time
2019-09-20 13:52:10: Skipping house cleaning because it is not required at this time
2019-09-20 13:53:16: Skipping pending job scan because it is not required at this time
2019-09-20 13:53:16: Skipping repository repair because it is not required at this time
2019-09-20 13:53:16: Skipping house cleaning because it is not required at this time
2019-09-20 13:54:17: Skipping pending job scan because it is not required at this time
2019-09-20 13:54:17: Skipping repository repair because it is not required at this time
2019-09-20 13:54:17: Skipping house cleaning because it is not required at this time
2019-09-20 13:55:17: Skipping pending job scan because it is not required at this time
2019-09-20 13:55:17: Skipping repository repair because it is not required at this time
2019-09-20 13:55:17: Skipping house cleaning because it is not required at this time
2019-09-20 13:56:22: Skipping pending job scan because it is not required at this time
2019-09-20 13:56:22: Skipping repository repair because it is not required at this time
2019-09-20 13:56:22: Skipping house cleaning because it is not required at this time
2019-09-20 13:57:26: Skipping pending job scan because it is not required at this time
2019-09-20 13:57:26: Skipping repository repair because it is not required at this time
2019-09-20 13:57:26: Skipping house cleaning because it is not required at this time
2019-09-20 13:58:32: Skipping pending job scan because it is not required at this time
2019-09-20 13:58:32: Skipping repository repair because it is not required at this time
2019-09-20 13:58:32: Skipping house cleaning because it is not required at this time
2019-09-20 13:59:38: Skipping pending job scan because it is not required at this time
2019-09-20 13:59:38: Skipping repository repair because it is not required at this time
2019-09-20 13:59:38: Skipping house cleaning because it is not required at this time
2019-09-20 14:00:44: Skipping pending job scan because it is not required at this time
2019-09-20 14:00:44: Skipping repository repair because it is not required at this time
2019-09-20 14:00:44: Skipping house cleaning because it is not required at this time
2019-09-20 14:01:46: Skipping pending job scan because it is not required at this time
2019-09-20 14:01:46: Skipping repository repair because it is not required at this time
2019-09-20 14:01:46: Skipping house cleaning because it is not required at this time
2019-09-20 14:02:51: Skipping pending job scan because it is not required at this time
2019-09-20 14:02:51: Skipping repository repair because it is not required at this time
2019-09-20 14:02:51: Skipping house cleaning because it is not required at this time
2019-09-20 14:03:57: Skipping pending job scan because it is not required at this time
2019-09-20 14:03:57: Skipping repository repair because it is not required at this time
2019-09-20 14:03:57: Skipping house cleaning because it is not required at this time
2019-09-20 14:05:02: Skipping pending job scan because it is not required at this time
2019-09-20 14:05:02: Skipping repository repair because it is not required at this time
2019-09-20 14:05:02: Skipping house cleaning because it is not required at this time
2019-09-20 14:06:04: Skipping pending job scan because it is not required at this time
2019-09-20 14:06:04: Skipping repository repair because it is not required at this time
2019-09-20 14:06:04: Skipping house cleaning because it is not required at this time
2019-09-20 14:07:06: Skipping pending job scan because it is not required at this time
2019-09-20 14:07:06: Skipping repository repair because it is not required at this time
2019-09-20 14:07:06: Skipping house cleaning because it is not required at this time
2019-09-20 14:08:10: Skipping pending job scan because it is not required at this time
2019-09-20 14:08:10: Skipping repository repair because it is not required at this time
2019-09-20 14:08:10: Skipping house cleaning because it is not required at this time
2019-09-20 14:09:14: Skipping pending job scan because it is not required at this time
2019-09-20 14:09:14: Skipping repository repair because it is not required at this time
2019-09-20 14:09:14: Skipping house cleaning because it is not required at this time
2019-09-20 14:10:20: Skipping pending job scan because it is not required at this time
2019-09-20 14:10:20: Skipping repository repair because it is not required at this time
2019-09-20 14:10:20: Skipping house cleaning because it is not required at this time
2019-09-20 14:11:24: Skipping pending job scan because it is not required at this time
2019-09-20 14:11:24: Skipping repository repair because it is not required at this time
2019-09-20 14:11:24: Skipping house cleaning because it is not required at this time
2019-09-20 14:11:47: 0: Loading Job's Plugin timeout is Disabled
2019-09-20 14:11:48: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-20 14:11:48: 0: All job files are already synchronized
2019-09-20 14:11:49: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/plugins\PDGDeadline took: 0 seconds
2019-09-20 14:11:49: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-20 14:11:49: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-20 14:11:49: 0: INFO: Executing plugin script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85408f29c029165c93efc4\PDGDeadline.py’
2019-09-20 14:11:49: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-20 14:11:49: 0: INFO: About: PDG Plugin for Deadline
2019-09-20 14:11:49: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper01’
2019-09-20 14:11:49: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-20 14:11:49: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-20 14:11:50: 0: Start Job timeout is disabled.
2019-09-20 14:11:50: 0: Task timeout is disabled.
2019-09-20 14:11:50: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d85408f29c029165c93efc4)
2019-09-20 14:11:50: 0: Executing plugin command of type ‘Start Job’
2019-09-20 14:11:50: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85408f29c029165c93efc4\GlobalJobPreLoad.py’
2019-09-20 14:11:50: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-20 14:11:50: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-20 14:11:50: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-20 14:11:50: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-20 14:11:50: 0: Done executing plugin command of type ‘Start Job’
2019-09-20 14:11:50: 0: Plugin rendering frame(s): 0
2019-09-20 14:11:50: 0: Executing plugin command of type ‘Render Task’
2019-09-20 14:11:50: 0: INFO: StartFrame: 0
2019-09-20 14:11:50: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216
2019-09-20 14:11:50: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/job_62b0210711dd4658ad5ecfa06aeceb1c\task_0.txt
2019-09-20 14:11:50: 0: INFO: Setting PATH: C:\Program Files\Thinkbox\Deadline10\bin\;C:\Program Files (x86)\Common Files\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Python27;C:\python27\lib\site-packages;C:\Python27\Scripts;C:\Program Files\MongoDB\Server\3.4\bin;C:\Program Files\Sublime Text 3;C:\Program Files\Git\cmd;C:\WINDOWS\System32\OpenSSH\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper01\AppData\Local\Microsoft\WindowsApps;C:\Users\Stormripper01\AppData\Local\GitHubDesktop\bin;%USERPROFILE%\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.384/bin
2019-09-20 14:11:50: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 14:11:50: 0: INFO: Task Executable: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 14:11:50: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/scripts/top.py –report none –hip P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip –toppath /obj/topnet1
2019-09-20 14:11:50: 0: INFO: Invoking: Run Process
2019-09-20 14:12:07: 0: STDOUT: Running Houdini 17.5.384
2019-09-20 14:12:07: 0: STDOUT: Loading .hip file P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip.
2019-09-20 14:12:10: 0: STDOUT: Given Node ‘topnet1’, Cooking Node ‘objectTest’
2019-09-20 14:15:27: Scheduler Thread - Task “0_0-0” could not be found because job with ID 5d85408f29c029165c93efc4 does not exist
2019-09-20 14:15:27: Scheduler Thread - Cancelling task…
2019-09-20 14:15:27: 0: Executing plugin command of type ‘Cancel Task’
2019-09-20 14:15:27: 0: Done executing plugin command of type ‘Cancel Task’
2019-09-20 14:15:27: 0: Done executing plugin command of type ‘Render Task’
2019-09-20 14:15:27: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2019-09-20 14:15:28: 0: Executing plugin command of type ‘End Job’
2019-09-20 14:15:28: 0: Done executing plugin command of type ‘End Job’
2019-09-20 14:15:29: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2019-09-20 14:15:31: Skipping pending job scan because it is not required at this time
2019-09-20 14:15:31: Skipping repository repair because it is not required at this time
2019-09-20 14:15:31: Skipping house cleaning because it is not required at this time
2019-09-20 14:16:13: 0: Loading Job's Plugin timeout is Disabled
2019-09-20 14:16:15: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-20 14:16:15: 0: All job files are already synchronized
2019-09-20 14:16:15: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/plugins\PDGDeadline took: 0 seconds
2019-09-20 14:16:15: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-20 14:16:15: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-20 14:16:16: 0: INFO: Executing plugin script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85419929c0292a283a4412\PDGDeadline.py’
2019-09-20 14:16:16: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-20 14:16:16: 0: INFO: About: PDG Plugin for Deadline
2019-09-20 14:16:16: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper01’
2019-09-20 14:16:16: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-20 14:16:16: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-20 14:16:16: 0: Start Job timeout is disabled.
2019-09-20 14:16:16: 0: Task timeout is disabled.
2019-09-20 14:16:16: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d85419929c0292a283a4412)
2019-09-20 14:16:16: 0: Executing plugin command of type ‘Start Job’
2019-09-20 14:16:16: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper01\AppData\Local\Thinkbox\Deadline10\slave\stormripper01\plugins\5d85419929c0292a283a4412\GlobalJobPreLoad.py’
2019-09-20 14:16:16: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-20 14:16:16: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-20 14:16:16: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-20 14:16:16: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-20 14:16:16: 0: Done executing plugin command of type ‘Start Job’
2019-09-20 14:16:16: 0: Plugin rendering frame(s): 0
2019-09-20 14:16:17: 0: Executing plugin command of type ‘Render Task’
2019-09-20 14:16:17: 0: INFO: StartFrame: 0
2019-09-20 14:16:17: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216
2019-09-20 14:16:17: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/job_fd182b3b7ccc47dc88628deff3e31863\task_0.txt
2019-09-20 14:16:17: 0: INFO: Setting PATH: C:\Program Files\Thinkbox\Deadline10\bin\;C:\Program Files (x86)\Common Files\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Python27;C:\python27\lib\site-packages;C:\Python27\Scripts;C:\Program Files\MongoDB\Server\3.4\bin;C:\Program Files\Sublime Text 3;C:\Program Files\Git\cmd;C:\WINDOWS\System32\OpenSSH\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper01\AppData\Local\Microsoft\WindowsApps;C:\Users\Stormripper01\AppData\Local\GitHubDesktop\bin;%USERPROFILE%\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.384/bin
2019-09-20 14:16:17: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 14:16:17: 0: INFO: Task Executable: C:/houdini/17.5.384/bin/hython.exe
2019-09-20 14:16:17: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/scripts/top.py –report none –hip P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip –toppath /obj/topnet1
2019-09-20 14:16:17: 0: INFO: Invoking: Run Process
2019-09-20 14:16:34: 0: STDOUT: Running Houdini 17.5.384
2019-09-20 14:16:34: 0: STDOUT: Loading .hip file P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip.
2019-09-20 14:16:38: 0: STDOUT: Given Node ‘topnet1’, Cooking Node ‘objectTest’
Success

The environment vars defined in the hip file, and your OS env, will be copied into the Deadline job when you turn on that toggle. Make sure your save your hip file after making that change. When using Submit Graph as Job, you must save your hip file for the latest changes to be used in the cook since it uses the hip file on the farm machine.

If still an issue, please try with the next daily build (Houdini 17.5.386 or newer). I fixed a pathing issue when using a TOP Python Script node with Submit Graph as Job, though I don't see you getting that error.

As a way to debug your tasks, you can open up a generated task file in a text editor to see the env variables, task command, and arguments being provided. For example, from your previous log, here is one of your task files:
2019-09-20 14:16:17: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/2216/job_fd182b3b7ccc47dc88628deff3e31863\task_0.txt

Hi Seelan,

Hope you had a good weekend.
Let's continue the debugging
After installing 17.5.386 I'm now facing a new error that prevents my job from cooking at all after clicking on “Submit Graph As Job”, saying “Error: Executable ”python.exe“ is not rooted, and does not exist in the current directory or in the PATH.”
I verified the “task_0.txt” in the pdgtemp directory which is being created for the job and it contains a “PYTHONHOME” variable which points to “C:/houdini/17.5.386/python27”. I verified that this directory exists on the slave, which it does.

=======================================================
Error
=======================================================
Error: Executable “python.exe” is not rooted, and does not exist in the current directory or in the PATH. (System.Exception)
at FranticX.Processes.MonitoredPrograms.StartMonitoredProgram_Internal(String name, String executable, String arguments, String startupDirectory, IDictionary environmentVariables, Boolean useExtraEnvironmentVariablesOnly, Boolean runAsUser, String userName, String domain, String password, Boolean useSu, Boolean preserveEnvironment, Boolean setHomeVariable)
at FranticX.Processes.MonitoredPrograms.StartMonitoredProgram(String name, String executable, String arguments, String startupDirectory, IDictionary environmentVariables, Boolean useExtraEnvironmentVariablesOnly)
at Deadline.Plugins.DeadlinePlugin.StartMonitoredProgramAsUser(String name, String executable, String arguments, String startupDirectory, String userName, String domain, String password, Boolean useSu, Boolean preserveEnvironment, Boolean setHomeVariable)
at Deadline.Plugins.DeadlinePlugin.StartMonitoredProgram(String name, String executable, String arguments, String startupDirectory)
at Python.Runtime.Dispatcher.TrueDispatch(ArrayList args)
at Python.Runtime.Dispatcher.Dispatch(ArrayList args)
at Deadline.Plugins.DeadlinePlugin.RenderTasks()
at Deadline.Plugins.DeadlinePlugin.DoRenderTasks()
at Deadline.Plugins.PluginWrapper.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage, AbortLevel& abortLevel)
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 arh)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ahl)

=======================================================
Log
=======================================================
2019-09-23 08:37:16: 0: Loading Job's Plugin timeout is Disabled
2019-09-23 08:37:17: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-23 08:37:17: 0: All job files are already synchronized
2019-09-23 08:37:17: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004/plugins\PDGDeadline took: 0 seconds
2019-09-23 08:37:17: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-23 08:37:17: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-23 08:37:18: 0: INFO: Executing plugin script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d88e6a729c02900e4a7478f\PDGDeadline.py’
2019-09-23 08:37:18: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-23 08:37:18: 0: INFO: About: PDG Plugin for Deadline
2019-09-23 08:37:18: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper05’
2019-09-23 08:37:18: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-23 08:37:18: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-23 08:37:18: 0: Start Job timeout is disabled.
2019-09-23 08:37:18: 0: Task timeout is disabled.
2019-09-23 08:37:18: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d88e6a729c02900e4a7478f)
2019-09-23 08:37:18: 0: Executing plugin command of type ‘Start Job’
2019-09-23 08:37:18: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d88e6a729c02900e4a7478f\GlobalJobPreLoad.py’
2019-09-23 08:37:18: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-23 08:37:18: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-23 08:37:18: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-23 08:37:18: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-23 08:37:18: 0: Done executing plugin command of type ‘Start Job’
2019-09-23 08:37:18: 0: Plugin rendering frame(s): 0
2019-09-23 08:37:19: 0: Executing plugin command of type ‘Render Task’
2019-09-23 08:37:19: 0: INFO: StartFrame: 0
2019-09-23 08:37:19: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004
2019-09-23 08:37:19: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004/job_c1db2a8817be4a3cabe39003bd13b31f\task_0.txt
2019-09-23 08:37:19: 0: INFO: Starting monitor program: python.exe P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004/scripts/pdgmq.py –xmlport 0 –relayport 0 –connectionfile P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004/job_c1db2a8817be4a3cabe39003bd13b31f/pdgmq_server.txt –start
2019-09-23 08:37:19: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/21004
2019-09-23 08:37:19: 0: INFO: File “python.exe” is not rooted, checking current directory
2019-09-23 08:37:19: 0: INFO: File “python.exe” is not rooted and is not in the current directory, checking PATH
2019-09-23 08:37:19: 0: INFO: File “python.exe” is not rooted, is not in the current directory, and does not exist in PATH
2019-09-23 08:37:19: 0: Done executing plugin command of type ‘Render Task’

=======================================================
Details
=======================================================
Date: 09/23/2019 08:37:21
Frames: 0
Elapsed Time: 00:00:00:05
Job Submit Date: 09/23/2019 08:37:12
Job User: stormripper01
Average RAM Usage: 8525713408 (7%)
Peak RAM Usage: 8525713408 (7%)
Average CPU Usage: 1%
Peak CPU Usage: 1%
Used CPU Clocks (x10^6 cycles): 1004
Total CPU Clocks (x10^6 cycles): 100362

=======================================================
Slave Information
=======================================================
Slave Name: STORMRIPPER05
Version: v10.0.9.4 Release (b6c080b1a)
Operating System: Windows 10 Pro
Running As Service: No
Machine User: Stormripper05
IP Address: 192.168.100.50
MAC Address: 00:0A:CD:31:31:7D
CPU Architecture: x64
CPUs: 32
CPU Usage: 3%
Memory Usage: 7.9 GB / 127.9 GB (6%)
Free Disk Space: 1.867 TB (49.248 GB on C:\, 1.819 TB on D:\)
Video Card: NVIDIA GeForce GTX 1080

You'll need to add the python installed on your system in your OS environment, or provide the path explicitly on the TOP Deadline scheduler, under Paths > Python. Typically on Windows, the path is C:/Python27/python.exe

Also please see for setup instructions for the TOP Deadline scheduler: https://www.sidefx.com/docs/houdini/nodes/top/deadlinescheduler.html [www.sidefx.com]

Hi Seelan,

Still struggling with the submission. I manually set the Python parameter on the Deadline Scheduler, see attached image.
While running 17.5.386 I'm trying to submit a single wedge to Deadline using “Submit Graph As Job”.
Interestingly, I see now 4 tasks in the Deadline Monitor, all of them failing. See the second image which I attached.

The log of the first Deadline job item is unique, the logs of items 2-4 are pretty much identical.

Here's the log for Deadline job item 1:

=======================================================
Error
=======================================================
Error: Process returned non-zero exit code: 1
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 arh)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ahl)

=======================================================
Log
=======================================================
2019-09-23 12:16:42: 0: Loading Job's Plugin timeout is Disabled
2019-09-23 12:16:44: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-23 12:16:44: 0: All job files are already synchronized
2019-09-23 12:16:44: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/13328/plugins\PDGDeadline took: 0 seconds
2019-09-23 12:16:44: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-23 12:16:44: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-23 12:16:45: 0: INFO: Executing plugin script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d89198f29c0292ab816923f\PDGDeadline.py’
2019-09-23 12:16:45: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-23 12:16:45: 0: INFO: About: PDG Plugin for Deadline
2019-09-23 12:16:45: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper05’
2019-09-23 12:16:45: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-23 12:16:45: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-23 12:16:45: 0: Start Job timeout is disabled.
2019-09-23 12:16:45: 0: Task timeout is disabled.
2019-09-23 12:16:45: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d89198f29c0292ab816923f)
2019-09-23 12:16:45: 0: Executing plugin command of type ‘Start Job’
2019-09-23 12:16:45: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d89198f29c0292ab816923f\GlobalJobPreLoad.py’
2019-09-23 12:16:45: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-23 12:16:45: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-23 12:16:45: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-23 12:16:45: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-23 12:16:45: 0: Done executing plugin command of type ‘Start Job’
2019-09-23 12:16:45: 0: Plugin rendering frame(s): 0
2019-09-23 12:16:45: 0: Executing plugin command of type ‘Render Task’
2019-09-23 12:16:45: 0: INFO: StartFrame: 0
2019-09-23 12:16:45: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/13328
2019-09-23 12:16:45: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/13328/job_a8f9ff73b51044dc8cd7d1b87d72b19c\task_0.txt
2019-09-23 12:16:45: 0: INFO: Setting PATH: 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:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper05\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.386/bin
2019-09-23 12:16:45: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.386/bin/hython.exe
2019-09-23 12:16:45: 0: INFO: Task Executable: C:/houdini/17.5.386/bin/hython.exe
2019-09-23 12:16:45: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/13328/scripts/top.py –report none –hip P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip –toppath /obj/topnet1
2019-09-23 12:16:45: 0: INFO: Invoking: Run Process
2019-09-23 12:16:55: 0: STDOUT: Running Houdini 17.5.386
2019-09-23 12:16:55: 0: STDOUT: Loading .hip file P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip.
2019-09-23 12:17:00: 0: STDOUT: Given Node ‘topnet1’, Cooking Node ‘objectTest’
2019-09-23 12:17:18: 0: STDOUT: Traceback (most recent call last):
2019-09-23 12:17:18: 0: STDOUT: File “C:/houdini/17.5.386/houdini/pdg/types\schedulers\tbdeadline.py”, line 779, in onSchedule
2019-09-23 12:17:18: 0: STDOUT: self._waitStartRelayServer(self.rootjob_id, local_conn_file)
2019-09-23 12:17:18: 0: STDOUT: File “C:/houdini/17.5.386/houdini/pdg/types\schedulers\tbdeadline.py”, line 1710, in _waitStartRelayServer
2019-09-23 12:17:18: 0: STDOUT: raise CookError(fail_msg)
2019-09-23 12:17:18: 0: STDOUT: CookError: Failed to connect to MQ server at STORMRIPPER01 with error: “Failed to connect to PDGMQ: Timed out”!
2019-09-23 12:17:18: 0: STDOUT: Enable “Use IP Address for PDGMQ” in case of DNS issues.
2019-09-23 12:17:35: 0: STDOUT: 12:16:59 OnStartCook()
2019-09-23 12:17:35: 0: STDOUT: 12:16:59 PDGMQ as separate task: False
2019-09-23 12:17:35: 0: STDOUT: 12:16:59 Local Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-23 12:17:35: 0: STDOUT: Remote Working Dir: P:/stormborn/tst/wow/wow_0050/houdini
2019-09-23 12:17:35: 0: STDOUT: 12:16:59 Starting deadline command process
2019-09-23 12:17:35: 0: STDOUT: 12:17:00 onSchedule: objectTest_ropfetch1_1 - 0
2019-09-23 12:17:35: 0: STDOUT: 12:17:00 Starting root job with PDGMQ server as monitor program
2019-09-23 12:17:35: 0: STDOUT: 12:17:00 Task 0 file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/8564/job_febd826711414a9c92f447d50352b3f4/task_0.txt
2019-09-23 12:17:35: 0: STDOUT: 12:17:00 Setting job directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/8564/job_febd826711414a9c92f447d50352b3f4
2019-09-23 12:17:35: 0: STDOUT: 12:17:00 Job file=P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/8564/job_febd826711414a9c92f447d50352b3f4/pdg_dl_job.txt
2019-09-23 12:17:35: 0: STDOUT: Plugin file=P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/8564/job_febd826711414a9c92f447d50352b3f4/pdg_dl_plugin.txt
2019-09-23 12:17:35: 0: STDOUT: 12:17:03 Root job: 5d891a2e59715f3060d86225
2019-09-23 12:17:35: 0: STDOUT: 12:17:14 Got PDGMQ server info: PDG_MQ STORMRIPPER01 64930 64931
2019-09-23 12:17:35: 0: STDOUT: ## Message Queue Server Running
2019-09-23 12:17:35: 0: STDOUT: 12:17:14 Starting MQ Relay server
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 onStopCook()
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Cancelling tick timer
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Stopping shared servers
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Failing root job
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Submitting FailJob: 5d891a2e59715f3060d86225
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Root job has been stopped
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Setting timeout for MQ server monitor program
2019-09-23 12:17:36: 0: STDOUT: 12:17:18 Stopping MQ Relay server
2019-09-23 12:17:36: 0: STDOUT: 12:17:35 MQ Relay stopped
2019-09-23 12:17:36: 0: STDOUT: 12:17:35 Stopping deadline command process
2019-09-23 12:17:36: 0: STDOUT: From node deadlinescheduler1:
2019-09-23 12:17:36: 0: STDOUT: Error running callback ‘onSchedule’: Failed to connect to MQ server at STORMRIPPER01 with error: “Failed to connect to PDGMQ: Timed out”!
2019-09-23 12:17:36: 0: STDOUT: Enable “Use IP Address for PDGMQ” in case of DNS issues.
2019-09-23 12:17:36: 0: STDOUT: Traceback (most recent call last):
2019-09-23 12:17:36: 0: STDOUT: File “C:/houdini/17.5.386/houdini/pdg/types\schedulers\tbdeadline.py”, line 779, in onSchedule
2019-09-23 12:17:36: 0: STDOUT: self._waitStartRelayServer(self.rootjob_id, local_conn_file)
2019-09-23 12:17:36: 0: STDOUT: File “C:/houdini/17.5.386/houdini/pdg/types\schedulers\tbdeadline.py”, line 1710, in _waitStartRelayServer
2019-09-23 12:17:36: 0: STDOUT: raise CookError(fail_msg)
2019-09-23 12:17:36: 0: STDOUT: CookError: Failed to connect to MQ server at STORMRIPPER01 with error: “Failed to connect to PDGMQ: Timed out”!
2019-09-23 12:17:37: 0: STDOUT: Enable “Use IP Address for PDGMQ” in case of DNS issues.
2019-09-23 12:17:37: 0: STDOUT: Traceback (most recent call last):
2019-09-23 12:17:37: 0: STDOUT: File “P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/13328/scripts/top.py”, line 223, in <module>
2019-09-23 12:17:37: 0: STDOUT: exit(1)
2019-09-23 12:17:37: 0: STDOUT: File “C:/houdini/17.5.386/python27\lib\site.py”, line 351, in __call__
2019-09-23 12:17:37: 0: STDOUT: raise SystemExit(code)
2019-09-23 12:17:37: 0: STDOUT: SystemExit: 1
2019-09-23 12:17:37: 0: Done executing plugin command of type ‘Render Task’

=======================================================
Details
=======================================================
Date: 09/23/2019 12:17:40
Frames: 0
Elapsed Time: 00:00:00:57
Job Submit Date: 09/23/2019 12:14:24
Job User: stormripper01
Average RAM Usage: 8825560064 (7%)
Peak RAM Usage: 9100795904 (7%)
Average CPU Usage: 2%
Peak CPU Usage: 11%
Used CPU Clocks (x10^6 cycles): 114652
Total CPU Clocks (x10^6 cycles): 5732561

=======================================================
Slave Information
=======================================================
Slave Name: STORMRIPPER05
Version: v10.0.9.4 Release (b6c080b1a)
Operating System: Windows 10 Pro
Running As Service: No
Machine User: Stormripper05
IP Address: 192.168.100.50
MAC Address: 00:0A:CD:31:31:7D
CPU Architecture: x64
CPUs: 32
CPU Usage: 0%
Memory Usage: 8.5 GB / 127.9 GB (6%)
Free Disk Space: 1.867 TB (49.112 GB on C:\, 1.819 TB on D:\)
Video Card: NVIDIA GeForce GTX 1080

——————————————————————————————–
Here the log for Deadline job item #2:

=======================================================
Error
=======================================================
Error: Process returned non-zero exit code: 1
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 arh)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.c(TaskLogWriter ahl)

=======================================================
Log
=======================================================
2019-09-23 12:15:54: 0: Loading Job's Plugin timeout is Disabled
2019-09-23 12:15:55: 0: Executing plugin command of type ‘Sync Files for Job’
2019-09-23 12:15:55: 0: All job files are already synchronized
2019-09-23 12:15:55: 0: Synchronizing Plugin PDGDeadline from P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/plugins\PDGDeadline took: 0 seconds
2019-09-23 12:15:55: 0: Done executing plugin command of type ‘Sync Files for Job’
2019-09-23 12:15:56: 0: Executing plugin command of type ‘Initialize Plugin’
2019-09-23 12:15:56: 0: INFO: Executing plugin script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d8919e429c02958a8f5ee4d\PDGDeadline.py’
2019-09-23 12:15:56: 0: INFO: *********** PDGDeadline InitializeProcess
2019-09-23 12:15:56: 0: INFO: About: PDG Plugin for Deadline
2019-09-23 12:15:56: 0: INFO: Render Job As User disabled, running as current user ‘Stormripper05’
2019-09-23 12:15:56: 0: INFO: The job's environment will be merged with the current environment before rendering
2019-09-23 12:15:56: 0: Done executing plugin command of type ‘Initialize Plugin’
2019-09-23 12:15:57: 0: Start Job timeout is disabled.
2019-09-23 12:15:57: 0: Task timeout is disabled.
2019-09-23 12:15:57: 0: Loaded job: PDG tst_wow_0050_wrk_pdgDeadlineTest_v001 (5d8919e429c02958a8f5ee4d)
2019-09-23 12:15:57: 0: Executing plugin command of type ‘Start Job’
2019-09-23 12:15:57: 0: INFO: Executing global job preload script ‘C:\Users\Stormripper05\AppData\Local\Thinkbox\Deadline10\slave\stormripper05\plugins\5d8919e429c02958a8f5ee4d\GlobalJobPreLoad.py’
2019-09-23 12:15:57: 0: INFO: Looking for AWS Portal File Transfer…
2019-09-23 12:15:57: 0: INFO: Looking for File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py…
2019-09-23 12:15:57: 0: INFO: Could not find AWS Portal File Transfer.
2019-09-23 12:15:57: 0: INFO: AWS Portal File Transfer is not installed on the system.
2019-09-23 12:15:57: 0: Done executing plugin command of type ‘Start Job’
2019-09-23 12:15:57: 0: Plugin rendering frame(s): 0
2019-09-23 12:15:57: 0: Executing plugin command of type ‘Render Task’
2019-09-23 12:15:57: 0: INFO: StartFrame: 0
2019-09-23 12:15:57: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068
2019-09-23 12:15:57: 0: INFO: Looking for task file: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/job_d3f6de2532c8477ab06ff688cbe3c7f9\task_0.txt
2019-09-23 12:15:57: 0: INFO: Starting monitor program: C:/houdini/17.5.386/python27/python.exe P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/scripts/pdgmq.py –xmlport 0 –relayport 0 –connectionfile P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/job_d3f6de2532c8477ab06ff688cbe3c7f9/pdgmq_server.txt –start
2019-09-23 12:15:57: 0: INFO: Startup Directory: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068
2019-09-23 12:15:57: 0: INFO: Starting monitored program: PDGMonitor
2019-09-23 12:15:57: 0: INFO: Program executable: C:/houdini/17.5.386/python27/python.exe
2019-09-23 12:15:57: 0: INFO: Program arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/scripts/pdgmq.py –xmlport 0 –relayport 0 –connectionfile P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/job_d3f6de2532c8477ab06ff688cbe3c7f9/pdgmq_server.txt –start
2019-09-23 12:15:58: 0: PDG_MQ STORMRIPPER05 51320 51321
2019-09-23 12:15:58: 0: ## Message Queue Server Running
2019-09-23 12:15:58: 0: INFO: Got MQ server info: PDG_MQ STORMRIPPER05 51320 51321
2019-09-23 12:15:58: 0: ## Message Queue Server Running
2019-09-23 12:15:58: 0: INFO: Setting PATH: 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:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Users\Stormripper05\AppData\Local\Microsoft\WindowsApps;;C:/houdini/17.5.386/bin
2019-09-23 12:15:58: 0: INFO: $HYTHON mapped to: C:/houdini/17.5.386/bin/hython.exe
2019-09-23 12:15:58: 0: INFO: Task Executable: C:/houdini/17.5.386/bin/hython.exe
2019-09-23 12:15:58: 0: INFO: Task Arguments: P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/scripts/rop.py -p P:/stormborn/tst/wow/wow_0050/houdini/tst_wow_0050_wrk_pdgDeadlineTest_v001.hip -n /obj/topnet1/objectTest/ropnet1/geometry1 -to /obj/topnet1/objectTest -i objectTest_ropfetch1_1 -fs 1 -fe 1 -fi 1
2019-09-23 12:15:58: 0: INFO: Invoking: Run Process
2019-09-23 12:16:08: 0: 0.0 mps, avg=0.0ms, max=0.0ms
2019-09-23 12:16:09: 0: STDOUT: Traceback (most recent call last):
2019-09-23 12:16:09: 0: STDOUT: File “P:/stormborn/tst/wow/wow_0050/houdini/pdgtemp/3068/scripts/rop.py”, line 486, in <module>
2019-09-23 12:16:09: 0: STDOUT: hostname,port = os.environ.split(':')
2019-09-23 12:16:09: 0: STDOUT: ValueError: need more than 1 value to unpack
2019-09-23 12:16:09: 0: Done executing plugin command of type ‘Render Task’

=======================================================
Details
=======================================================
Date: 09/23/2019 12:16:13
Frames: 0
Elapsed Time: 00:00:00:18
Job Submit Date: 09/23/2019 12:15:48
Job User: stormripper01
Average RAM Usage: 8725241856 (7%)
Peak RAM Usage: 8725241856 (7%)
Average CPU Usage: 2%
Peak CPU Usage: 6%
Used CPU Clocks (x10^6 cycles): 30034
Total CPU Clocks (x10^6 cycles): 1501668

=======================================================
Slave Information
=======================================================
Slave Name: STORMRIPPER05
Version: v10.0.9.4 Release (b6c080b1a)
Operating System: Windows 10 Pro
Running As Service: No
Machine User: Stormripper05
IP Address: 192.168.100.50
MAC Address: 00:0A:CD:31:31:7D
CPU Architecture: x64
CPUs: 32
CPU Usage: 0%
Memory Usage: 8.1 GB / 127.9 GB (6%)
Free Disk Space: 1.867 TB (49.112 GB on C:\, 1.819 TB on D:\)
Video Card: NVIDIA GeForce GTX 1080

I verified the file:
P:\stormborn\tst\wow\wow_0050\houdini\pdgtemp\888\job_2746b6dbbbba4eb48c5add87f70be733\task_0.txt
And it turns out the “pdg_result_server” points to an empty string.
“pdg_result_server”: “”

Looks like the result reporting mechanism is failing due to not being able to resolve STORMRIPPER01 (hostname) to an IP address. Do you have DNS enabled?

You can try enabling the Use IP Address for PDGMQ option on the TOP Deadline scheduler under the Deadline section. See screenshot.

Any tips on solving the “Error: Executable “python.exe” is not rooted, and does not exist in the current directory or in the PATH” problem?
I´m getting the same on one of my machines.

guilhermecasagrandi
Any tips on solving the “Error: Executable “python.exe” is not rooted, and does not exist in the current directory or in the PATH” problem?
I´m getting the same on one of my machines.

You'll need to add python executable location to each of your machines' system $PATH environment variable. On Windows, it is usually C:/Python27. Or you can use Houdini's built-in python at $HFS/python27.

Another option, if all your machines have common python location, is to specify it on the TOP Deadline scheduler's Python parm under Job Parms.

Check docs here: https://www.sidefx.com/docs/houdini/nodes/top/deadlinescheduler.html [www.sidefx.com]

Hi Seelan,

I encountered this error when submitting a PDG task to the deadline

It's just that these two nodes that need to install other programs are reporting an error, and the tasks of the other nodes above are normal