maya+nuuke+qube failing jobs

[adrian cruceru]

i'm having a really hard time with qube which is failing frames like crazy. we have 2 problems so far:
NUKE:
if there are not enough free licenses it fails the job in no time instead of pending it

MAYA:
i have frames that got rendered in 50 seconds and frames that took 26 hours, same scene, just a camera move nothing else, no object, shader or light anim
i have frames that took 50 minutes per frame and some 52 hours just camera anim

if i render from the shell i have no problems whatsoever but from qube it's just a pain

sometimes it marks a frame as a -3738 days to render and it's on pending state but the job is set as fail

if i look into the stderr it says maya encountered an error and then apparently it restarts the job and so on until it fails the whole job

what puzzles me is that if i kill the pending frames and resubmit the failed frames it renders ok for a while (even the frames that were failed) then it fails again and again

i don't want to resubmit every 2-3 hours cause there's no point in using qube if i have to watch the render all day long just to see if it fails or not. and btw it renders without any glitches from the shell, it's just that rendering through qube that fails.

one more thing, can i have a retry fail threshold parameter so after trying "n" times it sets the frame to failed and goes on to the next one instead of trying it forever?

thank you

[jburk]

Nuke:
You have to inform Qube how many nuke licenses you have access to, and then configure the job to consume those licenses.

Say you have 20 Nuke licenses.  Add a 'global.nuke=20' to the supervisor's "supervisor_global_resources".  Modify the job's reservations to include "global.nuke=1".  Qube will then only start up to 20 Nuke subjobs across the entire farm, even if they're split across several different jobs.

Maya:
Do the frames that run forever actually finish, or is Maya hung on the worker?  You can set a job timeout; this is the length that the entire job should run, not individual workers or frames.  the job is killed if it exceeds the job timeout value.

Does the frame render from the shell on the worker, or on your machine?

If you're rendering with mentalray in Maya, are you running out of mentalray licenses?  That would explain the "renders for a while then starts failing again".

The default frame and subjob parameter setting of '-1' should specify to never retry failed frames or subjobs.  Are you setting this value to something other than the default?

By 'trying forever', do you mean that it works on the frame overly long (like 26 hours)?  That's indicative of Maya being hung, not continually retrying.

[adrian cruceru]

Say you have 20 Nuke licenses.  Add a 'global.nuke=20' to the supervisor's "supervisor_global_resources".  Modify the job's reservations to include "global.nuke=1".  Qube will then only start up to 20 Nuke subjobs across the entire farm, even if they're split across several different jobs.

we changed that, is there a way to do it for all machines? like a remote admin from the license server or something?

Do the frames that run forever actually finish, or is Maya hung on the worker?  You can set a job timeout; this is the length that the entire job should run, not individual workers or frames.  the job is killed if it exceeds the job timeout value.

it's pretty hard to estimate the global job time, i can hardly estimate the subjobs like per frame render time, after looking at the rendertime after the job is done the rendertime varies quite a lot on per frame and i don't want to fail the job for false timeouts due to improper estimations

Does the frame render from the shell on the worker, or on your machine?

yes it does

If you're rendering with mentalray in Maya, are you running out of mentalray licenses?  That would explain the "renders for a while then starts failing again".

i think we have enough batch licenses but i have to check with my sysadmin

The default frame and subjob parameter setting of '-1' should specify to never retry failed frames or subjobs.  Are you setting this value to something other than the default?

nope

By 'trying forever', do you mean that it works on the frame overly long (like 26 hours)?  That's indicative of Maya being hung, not continually retrying.

i frankly don't know, cause the job stderr output is not that long to figure out from the beginning to the end

one thing i've noticed: the stderr output shows the image rendered twice, is this the normal behavior or something is going fishy?

one more thing that completely puzzles me: i have a frame set as failed in qube but it's rendered just fine on the disk, do i have to manually check each frame for completion? it's kind'of a good habit but i can't trust qube anymore then ...

[jburk]

you only need to define the global resource "global.nuke=20" on the supervisor; if you define it anywhere else it will have no effect.

I agree that it's hard to estimate time-to-completion and that false timeouts have to be avoided; my rule of thumb for the job timeout is to set it to 10 times what I think the render will take, and never less than 12 hours.  This catches hung renders that are unattended overnight or the weekends. 

The real fix is to figure out why your Maya processes are hanging in the first place, which is usually down to something in the scene or shaders.

What renderer are you using, and are you using the maya jobtype or one of the batchrender jobtypes?

Are the long render times usually associated with the same worker?  Are you running mentalray with the 'autorenderthreads', but not setting the job' reservations to 'host.processors=1+'.  A common scenario we see is 8 subjobs which only reserve 1 host.processor running on a 8-core box, and each subjob is a mentalray render running 8 threads, for a total of 64 mentalray threads. 

Have you tried turning up the verbosity of whatever renderer you're using?

re: false failure status - Qube's can only determine success/failure by exit codes or return values.  If you have a multi-pass render, and one of the passes fails but the beauty pass renders, Qube will still consider the frame as failed, since it's the combined statuses of all passes that is evaluated to determine pass/fail.

[adrian cruceru]

The real fix is to figure out why your Maya processes are hanging in the first place, which is usually down to something in the scene or shaders.

The thing is if i resubmit the failed frame it passes with no problems. if one thing fails it should fail every time if there's something wrong in the maya scene

What renderer are you using, and are you using the maya jobtype or one of the batchrender jobtypes?

tried both, through the maya qube menu asa render job or batch mr job

Are the long render times usually associated with the same worker?  Are you running mentalray with the 'autorenderthreads', but not setting the job' reservations to 'host.processors=1+'.  A common scenario we see is 8 subjobs which only reserve 1 host.processor running on a 8-core box, and each subjob is a mentalray render running 8 threads, for a total of 64 mentalray threads. 

we use "all" on the reservation flag

Have you tried turning up the verbosity of whatever renderer you're using?

v 5 on mray

re: false failure status - Qube's can only determine success/failure by exit codes or return values.  If you have a multi-pass render, and one of the passes fails but the beauty pass renders, Qube will still consider the frame as failed, since it's the combined statuses of all passes that is evaluated to determine pass/fail.

can i have a partial fail on this? like for multiple render layers or cameras which is good and which is not? since qube is able to parse maya's output i think this is a doable task

right now i'm having a few frames that fail at 99.5% with a signal 11 and i can't figure out why.

btw: we're using mray for maya on the farm and nukeX, fedora core 11 x64, 8 cores, 24 GB memory on each node.

[adrian cruceru]

here's the stdout for one frame (frame 50 of job 792):
=====================
got work: 792:50 - running
INFO: running frame 50 -
INFO: running cmd: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: execution successful.
[Mar 31, 2010 15:58:51] compute-10.intra.cuttingedgebkk.com : reporting status on work for: 792.2 50 - complete
[Mar 31, 2010 15:58:51] compute-10.intra.cuttingedgebkk.com : requesting work for: 792.2
[Mar 31, 2010 15:58:51] compute-10.intra.cuttingedgebkk.com :

----------------------------------

got work: 792:50 - running
INFO: running frame 50 -
INFO: running cmd: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com :

----------------------------------

got work: 792:50 - running
INFO: running frame 50 -
INFO: running cmd: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com :
=========================================

for me it looks like the frame was rendered 3 times

[adrian cruceru]

the stderr (probably truncated) is:
=========================================
...........
SCEN 0.2  progr: begin scene preprocessing for frame 50
SCEN 0.2  info : 335 geometry leaf instances (308 scheduled, 0 cached, 27 shared)
SCEN 0.2  info : 7 light leaf instances
SCEN 0.2  info : wallclock  0:00:00.02 for scene preprocessing
SCEN 0.2  info : CPU user  0:00:00.02 for scene preprocessing
SCEN 0.2  info : allocated 64 MB, max resident 64 MB
RC   0.2  info : scene extent: (-189.80,26.91,-70.43) : (135.22,139.41,70.43)
RC   0.2  info : option: scanline          off
RC   0.2  info : option: trace             on
RC   0.2  info : option:   trace depth     reflection 4, refraction 8, sum 20
RC   0.2  info : option:   acceleration    large bsp
RC   0.2  info : option:   bsp size        10
RC   0.2  info : option:   bsp depth       40
RC   0.2  info : option: shadow            sort
RC   0.2  info : option:   shadow maps       (use) (detail) (recompute)
RC   0.2  info : option: lightmap          on
RC   0.2  info : option: motion            off
RC   0.2  info : option: luminance weights 0.212671 0.71516 0.072169
RC   0.2  info : option: caustic           off
RC   0.2  info : option: globillum         off
RC   0.2  info : option: finalgather       off
RC   0.2  info : option: samples           min 0, max 3
RC   0.2  info : option:   contrast        0.01 0.01 0.01 0.01, all buffers
RC   0.2  info : option: jitter            1
RC   0.2  info : option: filter            gauss 3 3
RC   0.2  info : option: render space      object
RC   0.2  info : option: face              both
RC   0.2  info : option: field             off
RC   0.2  info : option: hair              on
RC   0.2  info : option: hardware          off
RC   0.2  info : option: task size         64
RC   0.2  info : option: pixel preview     off
RC   0.2  info : option: lens              on
RC   0.2  info : option: volume            on
RC   0.2  info : option: geometry          on
RC   0.2  info : option: displace          on
RC   0.2  info : option: premultiply       on
RC   0.2  info : option: colorclip         raw
RC   0.2  info : option: output            on
RC   0.2  info : option: merge             on
RC   0.2  info : option: fb mem management mapped
RC   0.2  info : option: type     filter     name
RC   0.2  info :         rgba_fp  yes        color
RC   0.2  info :         rgba_fp  yes        mayaGlow
RC   0.2  info :         z        yes        CAMZ:Zdepth.interiorOrbit
RC   0.2  info :         z        yes        CAMZ:depthZ.interiorOrbit
RC   0.2  info :         a_fp     yes        COV:coverage.interiorOrbit
RC   0.2  info : camera: focal length      0.681101
RC   0.2  info : camera: aperture          1.41732
RC   0.2  info : camera: aspect            1.777
RC   0.2  info : camera: resolution        1280 720
RC   0.2  info : camera: clip              0.01 1000
RC   0.2  info : camera: frame             50 50 0
RC   0.2  progr: rendering
RCI  0.2  progr: begin intersection preprocessing
RCI  0.2  info : using large BSP for eye rays
RCI  0.2  info : using large BSP for secondary rays
RCI  0.2  progr: building initial extent bsp-tree
RCI  0.2  info : leaves without shadow   : 6
RCI  0.2  info : leaves with only shadow : 0
RCI  0.2  info : leaves with both        : 329
RCI  0.2  progr: end intersection preprocessing
RCI  0.2  info : wallclock  0:00:00.00 for intersection prep.
RCI  0.2  info : CPU user  0:00:00.00 for intersection prep.
RCI  0.2  info : allocated 65 MB, max resident 78 MB
PHEN 0.2  info : -----------------------------------------------
PHEN 0.2  info : mayabase version 10.8, compiled on Jul 28 2009.
PHEN 0.2  info : -----------------------------------------------
IMG  0.6  progr: opening texture /fs1/data/personal/adi/CarDemo/sourceimages/LEATHER/Leather_Tile_01.jpg, for reading
IMG  0.6  progr: opening texture /fs1/data/personal/adi/CarDemo/sourceimages/HDRI/DH205SN.hdr, for reading
IMG  0.13 progr: opening texture /fs1/data/personal/adi/CarDemo/sourceimages/dotsNInvRed.exr, for reading
JOB  0.3  progr:     0.4%    rendered on compute-10.intra.cuttingedgebkk.com.3

.................................. bla bla from 0 to 100%..........................................

JOB  0.8  progr:    99.5%    rendered on compute-10.intra.cuttingedgebkk.com.8
JOB  0.9  progr:   100.0%    rendered on compute-10.intra.cuttingedgebkk.com.9
RC   0.2  info : rendering statistics
RC   0.2  info :   type                           number   per eye ray
RC   0.2  info :   eye rays                     13825670          1.00
RC   0.2  info :   reflection rays                887011          0.06
RC   0.2  info :   refraction rays                607477          0.04
RC   0.2  info :   shadow rays                 742422392         53.70
RC   0.2  info :   environment rays               132092          0.01
RC   0.2  info :   probe rays                 1783917704        129.03
RCI  0.2  info : main bsp tree statistics:
RCI  0.2  info : max depth         : 40
RCI  0.2  info : max leaf size     : 382
RCI  0.2  info : average depth     : 35
RCI  0.2  info : average leaf size : 8
RCI  0.2  info : leafnodes         : 19827021
RCI  0.2  info : bsp size (Kb)     : 1264458
PHEN 0.2  progr: calling output shaders
PHEN 0.2  progr: maya_shaderglow(): Computing glow...
PHEN 0.2  info : maya_shaderglow(): Glow: Filter Width .... 41
PHEN 0.2  info : maya_shaderglow():       Resolution ...... 0.638926
PHEN 0.2  info : maya_shaderglow():       Normalization ... 3.362000
PHEN 0.2  info : maya_shaderglow(): Halo: Filter Width .... 101
PHEN 0.2  info : maya_shaderglow():       Resolution ...... 0.260841
PHEN 0.2  info : maya_shaderglow():       Normalization ... 20.402000
PHEN 0.2  progr: maya_shaderglow(): Done!
PHEN 0.2  progr: writing image file /fs1/data/personal/adi/CarDemo/images/INTERIOR_5_CAMS_20/interiorOrbit/interiorOrbit.0050.exr (frame 50)
RC   0.2  progr: rendering finished
RC   0.2  info : wallclock  1:06:29.07 for rendering
RC   0.2  info : CPU user  8:20:44.24 for rendering
RC   0.2  info : allocated 1983 MB, max resident 3039 MB
GAPM 0.2  info : triangle count (including retessellation) :    26460066
PHEN 0.2  info : Reflection rays skipped by threshold: 5677
Scene /fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb completed.
requesting work for: 792.2

as you can see the frame is set as completed and the worker requested work after finishing it but it gets the same frame again

----------------------------------

got work: 792:50 - running
find: /opt/deadline: Permission denied
find: /usr/lib64/audit: Permission denied

Starting "/usr/autodesk/maya2010-x64/bin/maya"

mental ray for Maya 2010
mental ray: version 3.7.53.5, Jun 17 2009, revision 88216
mental ray: using SpiceFX assets
mental ray: SpiceFX custom startup done
mental ray: leaving custom shaders for mrfm
mental ray: mental ray for Maya - custom startup done
Error: Cannot find procedure "bonusToolsMenu".
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
File read in 16 seconds.
Warning: Can't perform polySplit23 on selection
Result: /fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb
Warning: Found camera interiorOrbitShape.
initMPS with licenseOption 0
mental ray: got 8 satellite CPUs.
Prog: (Mayatomr.Scene) : optimize animation detection: done 34 animated nodes
MEM  0.0  info : heap size limit set to 19114 MB
Info: (mental ray) : number of render thread(s): 8
JOB  0.0  info : slave rendering OFF

........ i've cut the bla bla maya outputs before starting the frame but you can see it restarts the render after it finishes

Info: (Mayatomr.Scene) : render camera: interiorOrbit
SCEN 0.2  progr: begin scene preprocessing for frame 50
SCEN 0.2  info : 335 geometry leaf instances (308 scheduled, 0 cached, 27 shared)
SCEN 0.2  info : 7 light leaf instances
SCEN 0.2  info : wallclock  0:00:00.02 for scene preprocessing
SCEN 0.2  info : CPU user  0:00:00.02 for scene preprocessing
SCEN 0.2  info : allocated 64 MB, max resident 64 MB
RC   0.2  info : scene extent: (-189.80,26.91,-70.43) : (135.22,139.41,70.43)
RC   0.2  info : option: scanline          off
RC   0.2  info : option: trace             on
RC   0.2  info : option:   trace depth     reflection 4, refraction 8, sum 20
RC   0.2  info : option:   acceleration    large bsp
RC   0.2  info : option:   bsp size        10
RC   0.2  info : option:   bsp depth       40
RC   0.2  info : option: shadow            sort
RC   0.2  info : option:   shadow maps       (use) (detail) (recompute)
RC   0.2  info : option: lightmap          on
RC   0.2  info : option: motion            off
RC   0.2  info : option: luminance weights 0.212671 0.71516 0.072169
RC   0.2  info : option: caustic           off
RC   0.2  info : option: globillum         off
RC   0.2  info : option: finalgather       off
RC   0.2  info : option: samples           min 0, max 3
RC   0.2  info : option:   contrast        0.01 0.01 0.01 0.01, all buffers
RC   0.2  info : option: jitter            1
RC   0.2  info : option: filter            gauss 3 3
RC   0.2  info : option: render space      object
RC   0.2  info : option: face              both
RC   0.2  info : option: field             off
RC   0.2  info : option: hair              on
RC   0.2  info : option: hardware          off
RC   0.2  info : option: task size         64
RC   0.2  info : option: pixel preview     off
RC   0.2  info : option: lens              on
RC   0.2  info : option: volume            on
RC   0.2  info : option: geometry          on
RC   0.2  info : option: displace          on
RC   0.2  info : option: premultiply       on
RC   0.2  info : option: colorclip         raw
RC   0.2  info : option: output            on
RC   0.2  info : option: merge             on
RC   0.2  info : option: fb mem management mapped
RC   0.2  info : option: type     filter     name
RC   0.2  info :         rgba_fp  yes        color
RC   0.2  info :         rgba_fp  yes        mayaGlow
RC   0.2  info :         z        yes        CAMZ:Zdepth.interiorOrbit
RC   0.2  info :         z        yes        CAMZ:depthZ.interiorOrbit
RC   0.2  info :         a_fp     yes        COV:coverage.interiorOrbit
RC   0.2  info : camera: focal length      0.681101
RC   0.2  info : camera: aperture          1.41732
RC   0.2  info : camera: aspect            1.777
RC   0.2  info : camera: resolution        1280 720
RC   0.2  info : camera: clip              0.01 1000
RC   0.2  info : camera: frame             50 50 0
RC   0.2  progr: rendering
RCI  0.2  progr: begin intersection preprocessing
RCI  0.2  info : using large BSP for eye rays
RCI  0.2  info : using large BSP for secondary rays
RCI  0.2  progr: building initial extent bsp-tree
RCI  0.2  info : leaves without shadow   : 6
RCI  0.2  info : leaves with only shadow : 0
RCI  0.2  info : leaves with both        : 329
RCI  0.2  progr: end intersection preprocessing
RCI  0.2  info : wallclock  0:00:00.00 for intersection prep.
RCI  0.2  info : CPU user  0:00:00.00 for intersection prep.
RCI  0.2  info : allocated 65 MB, max resident 78 MB
PHEN 0.2  info : -----------------------------------------------
PHEN 0.2  info : mayabase version 10.8, compiled on Jul 28 2009.
PHEN 0.2  info : -----------------------------------------------
IMG  0.5  progr: opening texture /fs1/data/personal/adi/CarDemo/sourceimages/LEATHER/Leather_Tile_01.jpg, for reading
IMG  0.7  progr: opening texture /fs1/data/personal/adi/CarDemo/sourceimages/HDRI/DH205SN.hdr, for reading
JOB  0.4  progr:     0.4%    rendered on compute-03.intra.cuttingedgebkk.com.4


................................ same bla bla cut due to message limits 20 characters ........

JOB  0.5  progr:    55.9%    rendered on compute-03.intra.cuttingedgebkk.com.5
JOB  0.11 progr:    56.3%    rendered on compute-03.intra.cuttingedgebkk.com.11
requesting work for: 792.3


----------------------------------

got work: 792:50 - running
find: /opt/deadline: Permission denied
find: /usr/lib64/audit: Permission denied

Starting "/usr/autodesk/maya2010-x64/bin/maya"

mental ray for Maya 2010
mental ray: version 3.7.53.5, Jun 17 2009, revision 88216
mental ray: using SpiceFX assets
mental ray: SpiceFX custom startup done
mental ray: leaving custom shaders for mrfm
mental ray: mental ray for Maya - custom startup done
Error: Cannot find procedure "bonusToolsMenu".
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
Warning: line 1: Unrecognized node type for node '_areaLight2_mrLoc'; preserving node information during this session.
File read in 17 seconds.
requesting work for: 792.3
===================================================
this frame is marked as completed. how can this be since the stderr ends with 56.3% ?
but the frame is fully rendered on disk (i've checked)

[adrian cruceru]

here's the stdout of the worker that rendered the frame:
================================
----------------------------------
-     Worker 792.3
----------------------------------
[Mar 31, 2010 9:48:46] compute-06.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 9:48:46] compute-06.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 9:48:46] compute-06.intra.cuttingedgebkk.com : got work: 792:33 - running
INFO: running frame 33 -
INFO: running cmd: "Render" -s 33 -e 33 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 33 -e 33 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
[Mar 31, 2010 11:09:48] compute-03.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 11:09:48] compute-03.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 11:09:48] compute-03.intra.cuttingedgebkk.com : got work: 792:35 - running
INFO: running frame 35 -
INFO: running cmd: "Render" -s 35 -e 35 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 35 -e 35 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: execution successful.
[Mar 31, 2010 12:36:04] compute-03.intra.cuttingedgebkk.com : reporting status on work for: 792.3 35 - complete
[Mar 31, 2010 12:36:04] compute-03.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 12:36:04] compute-03.intra.cuttingedgebkk.com : got work: 792:40 - running
INFO: running frame 40 -
INFO: running cmd: "Render" -s 40 -e 40 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 40 -e 40 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: execution successful.
[Mar 31, 2010 13:42:36] compute-03.intra.cuttingedgebkk.com : reporting status on work for: 792.3 40 - complete
[Mar 31, 2010 13:42:36] compute-03.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 13:42:36] compute-03.intra.cuttingedgebkk.com : got work: 792:50 - running
INFO: running frame 50 -
INFO: running cmd: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 14:36:25] compute-05.intra.cuttingedgebkk.com : got work: 792:50 - running
INFO: running frame 50 -
INFO: running cmd: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 50 -e 50 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com : [p792.3] job type version:
loading command line executor.
job id: 792.3
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 14:49:19] compute-05.intra.cuttingedgebkk.com : got work: 792:52 - running
INFO: running frame 52 -
INFO: running cmd: "Render" -s 52 -e 52 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 52 -e 52 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: execution successful.
[Mar 31, 2010 15:56:36] compute-05.intra.cuttingedgebkk.com : reporting status on work for: 792.3 52 - complete
[Mar 31, 2010 15:56:36] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 15:56:36] compute-05.intra.cuttingedgebkk.com : got work: 792:60 - running
INFO: running frame 60 -
INFO: running cmd: "Render" -s 60 -e 60 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 60 -e 60 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: execution successful.
[Mar 31, 2010 17:02:22] compute-05.intra.cuttingedgebkk.com : reporting status on work for: 792.3 60 - complete
[Mar 31, 2010 17:02:22] compute-05.intra.cuttingedgebkk.com : requesting work for: 792.3
[Mar 31, 2010 17:02:22] compute-05.intra.cuttingedgebkk.com : got work: 792:71 - running
INFO: running frame 71 -
INFO: running cmd: "Render" -s 71 -e 71 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
INFO: Using shell: /bin/sh
COMMAND: "Render" -s 71 -e 71 -b 1 -cam interiorOrbit -verbose 5 -proj "/fs1/data/personal/adi/CarDemo/" -renderer "mr" -autoRenderThreads  "/fs1/data/personal/adi/CarDemo/scenes/INTERIOR_5_CAMS_20.mb"
=================================
it looks like it only rendered the frame twice

i'm really puzzled here but i'm starting to feel like something is fishy with the way frames are checked as rendered and the subjob submitting mechanism.

i now understand that it is possible for a frame to render in 26 hours instead of 30 minutes.

we only have to find a cure for this. or maybe i completely misunderstood all the outputs?

[jburk]

This is turning into a support case, as this behavior is not normally reported by our customers running maya and mentalray.

Please create an account and log a case in http://pipelinefx.zendesk.com