Redshift in deadline keeps saying it’s rendering when the job is done (deadline)

Hey Redshift and Thinkbox peeps!!

I got jobs in Redshift/Maya/Deadline that seem’s to stay stucked after doing its job…. I must need to right click on the job and say completed manually. So I put my alarm at night at 1, 3, 5 am… and VPN my machine to get the slaves out of the stucked mode.

Any toughts on that?

thanks everyone for any help!

sly

we are on Deadline Version: 7.1.2.1 R (53013d5bd)
On Linux

sorry forgot to give some meat to cheew on.

sly

This was cross posted on the Redshift Forum… and i’ve tried Nico’s hack to the mayaBatch.py file without sucess.

which was changing:

this:
return ‘string $rl=""; string $rp=""; float $resize=-1.; redshiftRegisterRenderer(); if( catchQuiet( eval( “redshiftGetRedshiftOptionsNode()” ) ) ) { redshiftGetRedshiftOptionsNode(true); }’

to this:
return 'string $rl=""; string $rp=""; float $resize=-1.; redshiftRegisterRenderer(); if( catchQuiet( eval( “redshiftGetRedshiftOptionsNode()” ) ) ) { eval( “redshiftGetRedshiftOptionsNode(true);”); }’

I am planning on an emergency upgrade for 7.2 but I fear its not the same problem and 7.2 may not solve it.

Please help!!! Our deadline is crazy…outputing 6300 frames at 2.4k rez… OMG!!

thanks a lot

sly

ohhh Jeez,
Forgot to mention that we have our own in-house submitter for Deadline. And I’ve read that not using Maya Batch could help.
A parameter we dont have yet in our submitter but will incorporate it tomorrow to try.

cheers

sly

Hello Sly,

Would be great to see logs, but let us know how your testing with MayaCMD jobs works out.

We have the same issue.
The rendering completes after about one minute and the rendered exr files are successfully copied to the server.

Log:

2016-02-29 13:26:42:  0: STDOUT: [Redshift] Frame done - total time for frame 45 (1/1): 57.00s
2016-02-29 13:26:42:  0: STDOUT: [Redshift] Rendering done - total time for 1 frames: 57.01s
2016-02-29 13:26:42:  0: STDOUT: Render completed.
2016-02-29 13:26:42:  0: STDOUT: mel: READY FOR INPUT
2016-02-29 13:26:42:  0: INFO: Moving output files and folders from C:/...d1aae/mayaOutput_tempyy6EO0 to I:/.../images
2016-02-29 13:26:42:  0: INFO: Moving file C:/...\TEST_v12.0045.exr to I:/...\TEST_v12.0045.exr
Success

The job was finally marked as completed after 17:17 minutes.

As you can see in the graph, the rendertime should be much lower and it happens quiet often that the job doesn’t get’s released:

We submit our jobs with the original Deadline submitter from within Maya 2016 (SP5) with the following (most important) settings:

[ ] Submit Maya Scene File [X] User MayaBatch Plugin [X] Enable local Rendering

Cheers,
Michael

Hello Michael,

Could you share some job reports showing the shorter, and longer results? I am curious if we can identify anything between them that indicates a problem, assuming your render nodes should be on par with each other. Also, have you noticed any similarities between the instances of this happening? Same machines? Same jobs? Same effect used in frames which took longer? Thanks.

Can you confirm exact version of Deadline & RedShift being used on all your slaves here? This sounds like something that was fixed in 7.2 and additional fixes in a later 7.2 point release as well.

We use Deadline 7.2.2.1 R with Maya 2016 SP5 and Redshift 1.3.28.

The render scene contains a poly plane with xgen fur on it. The plane deformation is cached with alembic, like the xgen splines. It’s a simple test scene with 10 AOVs (render passes), which should take no longer than about 2 miutes to render a frame.

Our GPU Farm Machines have the following specs:

  • 64GB RAM
  • 8 NVIDIA GeForce GTX 980 Ti
  • 2 Intel Xeon E5 (Dual 6 Core)

We are using 4 Slaves on each GPU farm machine.
They share it’s RAM. Each Slaves uses 2 GPU’s.

The following logs are from the same Slave, same scene, but different frame!


The following render job took 1:58 minutes:

2016-02-29 13:17:10:  BEGIN - CHINOOK1
2016-02-29 13:17:10:  1: Start Job timeout is disabled.
2016-02-29 13:17:10:  1: Task timeout is 1200 seconds (Regular Task Timeout)
2016-02-29 13:17:10:  1: Loaded job: TEST_v12
2016-02-29 13:17:10:  1: INFO: Executing plugin script C:...\56d4...aae\MayaBatch.py
2016-02-29 13:17:10:  1: INFO: About: Maya Batch Plugin for Deadline
2016-02-29 13:17:10:  1: INFO: The job's env will be merged with current env before rendering
2016-02-29 13:17:10:  1: INFO: Rendering with Maya version 2016.0
2016-02-29 13:17:10:  1: INFO: Setting MAYA_DISABLE_CIP (ADSK Customer Inv...) envVar to 1 
2016-02-29 13:17:10:  1: INFO: Setting MAYA_DISABLE_CER (ADSK Customer Err..) envVar to 1
2016-02-29 13:17:10:  1: INFO: Enforcing 64 bit build of Maya
2016-02-29 13:17:10:  1: INFO: Setting PYTHONHOME to C:\...\Maya2016\Python for this session
2016-02-29 13:17:10:  1: INFO: Starting monitored managed process MayaBatch
2016-02-29 13:17:10:  1: INFO: Stdout Redirection Enabled: True
2016-02-29 13:17:10:  1: INFO: Stdout Handling Enabled: True
2016-02-29 13:17:10:  1: INFO: Popup Handling Enabled: True
2016-02-29 13:17:10:  1: INFO: QT Popup Handling Enabled: False
2016-02-29 13:17:10:  1: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2016-02-29 13:17:10:  1: INFO: Using Process Tree: True
2016-02-29 13:17:10:  1: INFO: Hiding DOS Window: True
2016-02-29 13:17:10:  1: INFO: Creating New Console: False
2016-02-29 13:17:10:  1: INFO: Running as user: render
2016-02-29 13:17:10:  1: INFO: Enforcing 64 bit build of Maya
2016-02-29 13:17:10:  1: INFO: Executable: "C:\...\Maya2016\bin\MayaBatch.exe"
2016-02-29 13:17:10:  1: INFO: Argument: -prompt -file "I:\...\TEST_v12.ma" -proj "I:/../TEST"
2016-02-29 13:17:10:  1: INFO: Startup Directory: "C:\...\Maya2016\bin"
2016-02-29 13:17:10:  1: INFO: Process Priority: BelowNormal
2016-02-29 13:17:10:  1: INFO: Process Affinity: default
2016-02-29 13:17:10:  1: INFO: Process is now running
2016-02-29 13:17:10:  1: Plugin rendering frame(s): 49
2016-02-29 13:17:10:  1: INFO: Waiting until maya is ready to go
2016-02-29 13:17:21:  1: STDOUT: Initialized VP2.0 renderer {
2016-02-29 13:17:21:  1: STDOUT:   Version : 6.3.16.4. Feature Level 4.
2016-02-29 13:17:21:  1: STDOUT:   Adapter : GeForce GTX 980 Ti/PCIe/SSE2
2016-02-29 13:17:21:  1: STDOUT:   Vendor ID: 4318. Device ID : 6088
2016-02-29 13:17:21:  1: STDOUT:   Driver : .
2016-02-29 13:17:21:  1: STDOUT:   API : OpenGL V.4.5.
2016-02-29 13:17:21:  1: STDOUT:   Max texture size : 16384 * 16384.
2016-02-29 13:17:21:  1: STDOUT:   Max tex coords : 8
2016-02-29 13:17:21:  1: STDOUT:   Shader versions supported (Vertex: 4, Geometry: 4, Pixel 4).
2016-02-29 13:17:21:  1: STDOUT:   Shader compiler profile : (Best card profile)
2016-02-29 13:17:21:  1: STDOUT:   Active stereo support available : 0
2016-02-29 13:17:21:  1: STDOUT:   GPU Memory Limit : 6144 MB.
2016-02-29 13:17:21:  1: STDOUT:   CPU Memory Limit: 62149.6 MB.
2016-02-29 13:17:23:  1: STDOUT: }
2016-02-29 13:17:24:  1: STDOUT: OpenCL evaluator is attempting to initialize OpenCL.
2016-02-29 13:17:29:  1: STDOUT: Detected 1 OpenCL Platforms: 
2016-02-29 13:17:29:  1: STDOUT:  0: NVIDIA Corporation. NVIDIA CUDA. OpenCL 1.2 CUDA 8.0.10.
2016-02-29 13:17:29:  1: STDOUT:  Supported extensions: ...
2016-02-29 13:17:29:  1: STDOUT: OpenCL evaluator choosing OpenCL platform NVIDIA Corporation.
2016-02-29 13:17:29:  1: STDOUT: OpenCL evaluator is unable to find a GPU device that can share VBOs with OpenGL.
2016-02-29 13:17:34:  1: STDOUT: pymel.core : INFO : Updating pymel with pre-loaded plugins: ...
2016-02-29 13:17:34:  1: STDOUT: xgmNurbsPatch [u'containerBase', u'entity', u'dagNode', ...]
2016-02-29 13:17:34:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmNurbsPatch is cyclical: [u'containerBase', u'entity', ...]
2016-02-29 13:17:34:  1: STDOUT: xgmSubdPatch [u'containerBase', u'entity',...]
2016-02-29 13:17:34:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSubdPatch is cyclical: [u'containerBase', u'entity', ...]
2016-02-29 13:17:35:  1: STDOUT: xgmArchiveGuide [u'containerBase', u'entity', ...]
2016-02-29 13:17:35:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmArchiveGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  1: STDOUT: xgmCardGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmCardGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  1: STDOUT: xgmSphereGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSphereGuide is cyclical: [u'containerBase', u'entity', ...]
2016-02-29 13:17:35:  1: STDOUT: xgmSplineGuide [u'containerBase', u'entity', ...]
2016-02-29 13:17:35:  1: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSplineGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:42:  1: STDOUT: @ Pipeline: load startup and libraries...
2016-02-29 13:17:42:  1: STDOUT: @ Pipeline: initialize pipeline environment...
2016-02-29 13:17:42:  1: STDOUT: @ Pipeline: load necessary plugins..
2016-02-29 13:17:42:  1: STDOUT: AbcExport v1.0 using Alembic 1.5.4 (built May  8 2014 13:47:10)
2016-02-29 13:17:43:  1: STDOUT: AbcImport v1.0 using Alembic 1.5.4 (built May  8 2014 13:47:10)
2016-02-29 13:17:53:  1: STDOUT: [Redshift] Redshift for Maya 2016
2016-02-29 13:17:53:  1: STDOUT: [Redshift] Version 1.3.28, Feb 26 2016
2016-02-29 13:17:54:  1: STDOUT: Installing Redshift MEL overrides...
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/connectNodeToAttrOverride.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../2016/createMayaSoftwareCommonGlobalsTab.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/createRenderNode.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/mayaBatchRender.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/MLdeleteUnused.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/relationshipEditor.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/renderWindowPanel.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/renderWithCurrentRenderer.mel
2016-02-29 13:17:54:  1: STDOUT: 	Sourcing C:/../Redshift/../override/2016/unifiedRenderGlobalsWindow.mel
2016-02-29 13:17:54:  1: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:54:  1: STDOUT: Warning: Loading plug-in "redshift4maya" has resulted in changes to the scene that may need to be saved.
2016-02-29 13:17:57:  1: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:57:  1: STDOUT: Warning: line 1: This file is from an older version of Maya.  If saved, it will not be readable by previous versions.
2016-02-29 13:17:57:  1: STDOUT: File read in  2.3 seconds.
2016-02-29 13:17:57:  1: STDOUT: Importing XGen Collections...
2016-02-29 13:17:57:  1: STDOUT: Done.
2016-02-29 13:17:57:  1: STDOUT: Result: I:/.../TEST_v12.ma
2016-02-29 13:17:57:  1: STDOUT: mel: READY FOR INPUT
2016-02-29 13:17:58:  1: INFO: Rendering with redshift
2016-02-29 13:17:58:  1: INFO: Rendering to local drive, will copy files and folders to final location after render is complete
2016-02-29 13:17:58:  1: INFO: Creating melscript to execute
2016-02-29 13:17:58:  1: INFO: GPUs per task is greater than 0, so the following GPUs will be used by RedShift: 2,3
2016-02-29 13:17:58:  1: INFO: Executing script: C:\Users\render\AppData\Local\Temp\tmp39BE.tmp
2016-02-29 13:17:59:  1: INFO: Waiting for script to finish
2016-02-29 13:17:59:  1: STDOUT: mel: Loading scene: I:/.../TEST_v12.ma
2016-02-29 13:17:59:  1: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:59:  1: STDOUT: Warning: file: C:/Program Files/Autodesk/Maya2016/scripts/others/makeCameraRenderable.mel line 60: Found camera cameraShape1.
2016-02-29 13:18:02:  1: STDOUT: [Redshift] Redshift for Maya 2016
2016-02-29 13:18:02:  1: STDOUT: [Redshift] Version 1.3.28, Feb 26 2016
2016-02-29 13:18:02:  1: STDOUT: [Redshift] Rendering frame 49 (1/1)
2016-02-29 13:18:03:  1: STDOUT: XGen Version: C:/../Maya2016/../xgen/  Build Date: Nov 30 2015  12:10:16
2016-02-29 13:18:23:  1: STDOUT: [Redshift] Scene translation time: 21.51s
2016-02-29 13:18:23:  1: STDOUT: [Redshift] License for redshift-core 2017.01 (permanent)
2016-02-29 13:18:48:  1: STDOUT: [Redshift] Rendering time: 24.53s (2 GPU(s) used)
2016-02-29 13:19:01:  1: STDOUT: [Redshift] Saved file 'C:/Users/../TEST_v12.0049.exr' in 13.08s
2016-02-29 13:19:01:  1: STDOUT: [Redshift] Saved file 'C:/Users/../TEST_v12.P.0049.exr' in 0.23s
2016-02-29 13:19:01:  1: STDOUT: [Redshift] Frame done - total time for frame 49 (1/1): 59.51s
2016-02-29 13:19:01:  1: STDOUT: [Redshift] Rendering done - total time for 1 frames: 59.52s
2016-02-29 13:19:01:  1: STDOUT: Render completed.
2016-02-29 13:19:01:  1: STDOUT: mel: READY FOR INPUT
2016-02-29 13:19:02:  1: INFO: Moving output files and folders from C:/../mayaOutput_tempJrlou0 to I:/../images
2016-02-29 13:19:02:  1: INFO: Moving file C:/..\TEST_v12.0049.exr to I:/../images\TEST_v12.0049.exr
2016-02-29 13:19:03:  1: INFO: Moving file C:/..\TEST_v12.P.0049.exr to I:/../images\TEST_v12.P.0049.exr

The following render job took 17:17 minutes:

2016-02-29 13:17:10:  BEGIN - CHINOOK1
2016-02-29 13:17:10:  0: Start Job timeout is disabled.
2016-02-29 13:17:10:  0: Task timeout is 1200 seconds (Regular Task Timeout)
2016-02-29 13:17:10:  0: Loaded job: TEST_v12
2016-02-29 13:17:10:  0: INFO: Executing plugin script C:\...05d1aae\MayaBatch.py
2016-02-29 13:17:10:  0: INFO: About: Maya Batch Plugin for Deadline
2016-02-29 13:17:10:  0: INFO: The job's env will be merged with the current env before rendering
2016-02-29 13:17:10:  0: INFO: Rendering with Maya version 2016.0
2016-02-29 13:17:10:  0: INFO: Setting MAYA_DISABLE_CIP (ADSK Customer ..) envVariable to 1
2016-02-29 13:17:10:  0: INFO: Setting MAYA_DISABLE_CER (ADSK Customer..) envVariable to 1
2016-02-29 13:17:10:  0: INFO: Enforcing 64 bit build of Maya
2016-02-29 13:17:10:  0: INFO: Setting PYTHONHOME to C:\..\Maya2016\Python for this session
2016-02-29 13:17:10:  0: INFO: Starting monitored managed process MayaBatch
2016-02-29 13:17:10:  0: INFO: Stdout Redirection Enabled: True
2016-02-29 13:17:10:  0: INFO: Stdout Handling Enabled: True
2016-02-29 13:17:10:  0: INFO: Popup Handling Enabled: True
2016-02-29 13:17:10:  0: INFO: QT Popup Handling Enabled: False
2016-02-29 13:17:10:  0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2016-02-29 13:17:10:  0: INFO: Using Process Tree: True
2016-02-29 13:17:10:  0: INFO: Hiding DOS Window: True
2016-02-29 13:17:10:  0: INFO: Creating New Console: False
2016-02-29 13:17:10:  0: INFO: Running as user: render
2016-02-29 13:17:10:  0: INFO: Enforcing 64 bit build of Maya
2016-02-29 13:17:10:  0: INFO: Executable: "C:\Program Files\Autodesk\Maya2016\bin\MayaBatch.exe"
2016-02-29 13:17:10:  0: INFO: Argument: -prompt -file "I:\...\TEST_v12.ma" -proj "I:/.../TEST"
2016-02-29 13:17:10:  0: INFO: Startup Directory: "C:\Program Files\Autodesk\Maya2016\bin"
2016-02-29 13:17:10:  0: INFO: Process Priority: BelowNormal
2016-02-29 13:17:10:  0: INFO: Process Affinity: default
2016-02-29 13:17:10:  0: INFO: Process is now running
2016-02-29 13:17:10:  0: Plugin rendering frame(s): 48
2016-02-29 13:17:10:  0: INFO: Waiting until maya is ready to go
2016-02-29 13:17:21:  0: STDOUT: Initialized VP2.0 renderer {
2016-02-29 13:17:21:  0: STDOUT:   Version : 6.3.16.4. Feature Level 4.
2016-02-29 13:17:21:  0: STDOUT:   Adapter : GeForce GTX 980 Ti/PCIe/SSE2
2016-02-29 13:17:21:  0: STDOUT:   Vendor ID: 4318. Device ID : 6088
2016-02-29 13:17:21:  0: STDOUT:   Driver : .
2016-02-29 13:17:21:  0: STDOUT:   API : OpenGL V.4.5.
2016-02-29 13:17:21:  0: STDOUT:   Max texture size : 16384 * 16384.
2016-02-29 13:17:21:  0: STDOUT:   Max tex coords : 8
2016-02-29 13:17:21:  0: STDOUT:   Shader versions supported (Vertex: 4, Geometry: 4, Pixel 4).
2016-02-29 13:17:21:  0: STDOUT:   Shader compiler profile : (Best card profile)
2016-02-29 13:17:21:  0: STDOUT:   Active stereo support available : 0
2016-02-29 13:17:21:  0: STDOUT:   GPU Memory Limit : 6144 MB.
2016-02-29 13:17:21:  0: STDOUT:   CPU Memory Limit: 62149.6 MB.
2016-02-29 13:17:22:  0: STDOUT: }
2016-02-29 13:17:23:  0: STDOUT: OpenCL evaluator is attempting to initialize OpenCL.
2016-02-29 13:17:28:  0: STDOUT: Detected 1 OpenCL Platforms: 
2016-02-29 13:17:28:  0: STDOUT:  0: NVIDIA Corporation. NVIDIA CUDA. OpenCL 1.2 CUDA 8.0.10.
2016-02-29 13:17:28:  0: STDOUT:  Supported extensions: ...
2016-02-29 13:17:28:  0: STDOUT: OpenCL evaluator choosing OpenCL platform NVIDIA Corporation.
2016-02-29 13:17:28:  0: STDOUT: OpenCL evaluator is unable to find a GPU device that can share VBOs with OpenGL.
2016-02-29 13:17:34:  0: STDOUT: pymel.core : INFO : Updating pymel with pre-loaded plugins: mayaHIK, ..
2016-02-29 13:17:34:  0: STDOUT: xgmNurbsPatch [u'containerBase', u'entity', ...]
2016-02-29 13:17:34:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmNurbsPatch is cyclical: [u'containerBase', u'entity', ...]
2016-02-29 13:17:34:  0: STDOUT: xgmSubdPatch [u'containerBase', u'entity',  ...]
2016-02-29 13:17:34:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSubdPatch is cyclical: [u'containerBase', u'entity', ...]
2016-02-29 13:17:35:  0: STDOUT: xgmArchiveGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmArchiveGuide is cyclical: [u'containerBase', u'entity', u'dagNode', ...]
2016-02-29 13:17:35:  0: STDOUT: xgmCardGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmCardGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: xgmSphereGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSphereGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: xgmSplineGuide [u'containerBase', u'entity',  ...]
2016-02-29 13:17:35:  0: STDOUT: pymel.internal.apicache : WARNING : lineage for node xgmSplineGuide is cyclical: [u'containerBase', u'entity',  ...]
2016-02-29 13:17:42:  0: STDOUT: @ Pipeline:load startup and libraries...
2016-02-29 13:17:42:  0: STDOUT: @ Pipeline: initialize pipeline environment...
2016-02-29 13:17:42:  0: STDOUT: @ Pipeline: load necessary plugins..
2016-02-29 13:17:43:  0: STDOUT: AbcExport v1.0 using Alembic 1.5.4 (built May  8 2014 13:47:10)
2016-02-29 13:17:43:  0: STDOUT: AbcImport v1.0 using Alembic 1.5.4 (built May  8 2014 13:47:10)
2016-02-29 13:17:54:  0: STDOUT: [Redshift] Redshift for Maya 2016
2016-02-29 13:17:54:  0: STDOUT: [Redshift] Version 1.3.28, Feb 26 2016
2016-02-29 13:17:54:  0: STDOUT: Installing Redshift MEL overrides...
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../connectNodeToAttrOverride.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../createMayaSoftwareCommonGlobalsTab.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../createRenderNode.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../mayaBatchRender.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../MLdeleteUnused.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../relationshipEditor.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../renderWindowPanel.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../renderWithCurrentRenderer.mel
2016-02-29 13:17:54:  0: STDOUT: 	Sourcing C:/../Redshift/../unifiedRenderGlobalsWindow.mel
2016-02-29 13:17:54:  0: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:54:  0: STDOUT: Warning: Loading plug-in "redshift4maya" has resulted in changes to the scene that may need to be saved.
2016-02-29 13:17:55:  0: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:57:  0: STDOUT: Warning: line 1: This file is from an older version of Maya.  If saved, it will not be readable by previous versions.
2016-02-29 13:17:57:  0: STDOUT: File read in  1.9 seconds.
2016-02-29 13:17:57:  0: STDOUT: Importing XGen Collections...
2016-02-29 13:17:57:  0: STDOUT: Done.
2016-02-29 13:17:57:  0: STDOUT: Result: I:/.../TEST_v12.ma
2016-02-29 13:17:57:  0: STDOUT: mel: READY FOR INPUT
2016-02-29 13:17:58:  0: INFO: Rendering with redshift
2016-02-29 13:17:58:  0: INFO: Rendering to local drive, will copy files and folders to final location after render is complete
2016-02-29 13:17:58:  0: INFO: Creating melscript to execute
2016-02-29 13:17:58:  0: INFO: GPUs per task is greater than 0, so the following GPUs will be used by RedShift: 0,1
2016-02-29 13:17:58:  0: INFO: Executing script: C:\Users\render\AppData\Local\Temp\tmp39BF.tmp
2016-02-29 13:17:59:  0: INFO: Waiting for script to finish
2016-02-29 13:17:59:  0: STDOUT: mel: Loading scene: I:/.../TEST_v12.ma
2016-02-29 13:17:59:  0: WARNING: Strict error checking on, ignoring the following unrecognized error or warning. If it is fatal, please email support@thinkboxsoftware.com with the error message.
2016-02-29 13:17:59:  0: STDOUT: Warning: file: C:/Program Files/Autodesk/Maya2016/scripts/others/makeCameraRenderable.mel line 60: Found camera cameraShape1.
2016-02-29 13:18:13:  0: STDOUT: [Redshift] Redshift for Maya 2016
2016-02-29 13:18:13:  0: STDOUT: [Redshift] Version 1.3.28, Feb 26 2016
2016-02-29 13:18:14:  0: STDOUT: [Redshift] Rendering frame 48 (1/1)
2016-02-29 13:18:14:  0: STDOUT: [Redshift] The shader 'mountain1' (mountain) is not supported by Redshift.
2016-02-29 13:18:14:  0: STDOUT: XGen Version: C:/../Maya2016/../xgen/  Build Date: Nov 30 2015  12:10:16
2016-02-29 13:18:47:  0: STDOUT: [Redshift] Scene translation time: 32.96s
2016-02-29 13:18:47:  0: STDOUT: [Redshift] License for redshift-core 2017.01 (permanent)
2016-02-29 13:34:13:  0: STDOUT: [Redshift] Rendering time: 15m:26s (2 GPU(s) used)
2016-02-29 13:34:21:  0: STDOUT: [Redshift] Saved file 'C:/Users/../TEST_v12.0048.exr' in 8.42s
2016-02-29 13:34:22:  0: STDOUT: [Redshift] Saved file 'C:/Users/../TEST_v12.P.0048.exr' in 0.18s
2016-02-29 13:34:22:  0: STDOUT: [Redshift] Frame done - total time for frame 48 (1/1): 16m:8s
2016-02-29 13:34:22:  0: STDOUT: [Redshift] Rendering done - total time for 1 frames: 16m:8s
2016-02-29 13:34:22:  0: STDOUT: Render completed.
2016-02-29 13:34:22:  0: STDOUT: mel: READY FOR INPUT
2016-02-29 13:34:22:  0: INFO: Moving output files and folders from C:/../mayaOutput_tempFuQeT0 to I:/../images
2016-02-29 13:34:22:  0: INFO: Moving file C:/..\TEST_v12.0048.exr to I:/../images\TEST_v12.0048.exr
2016-02-29 13:34:23:  0: INFO: Moving file C:/..\TEST_v12.P.0048.exr to I:/../images\TEST_v12.P.0048.exr

This issue only happens on our farm machines. The workstations are rendering fine in time.

Another quick question inbetween:

Inside the Slaves Panel:
I see my GPU Slaves how much resources each one is using.
I think the Memory Usage doesn’t displays the current usage, instead it shows the total used memory.
Am I right? Because if the displayed RAM usage right and show the actual usage of each Slave, it would explain why those Slaves need sometimes much longer (out of RAM).

But as our current renders are just containing simple example scenes, I can’t belief the displayed output is correct.

GPU_farm_src_usage.PNG

As can be seen in your “slow” render log, Redshift rendering “time” is where all the time is being used up here. I wonder what the bottleneck is in the Redshift “rendering” part of the process? Perhaps, it is struggling with data throughput? Maya is struggling to communicate with Redshift? Do you get better scaling with a different configuration of “slaves to gpu”?

Can you increase the verbosity level of Redshift in Maya settings and re-post that log, as that should identify the bottleneck in your pipeline.

If you run multiple slaves on one of your workstations, do you get a similar render time slowdown with Redshift?

The slave panel just shows the current memory usage of the slave machine, not the individual slaves and its subprocesses. The task list, however, shows the memory usage for just the process(es) associated with that task.

Looks like the second log has this error in it:

STDOUT: [Redshift] The shader 'mountain1' (mountain) is not supported by Redshift.

Otherwise they’re pretty darn similar. It’s also missing “dagNode” here:

2016-02-29 13:17:34:  0: STDOUT: xgmNurbsPatch [u'containerBase', u'entity', ...]

We going to try different settings.
I’ll keep you posted.