Reading MR render log

Become a member of the CGSociety

Connect, Share, and Learn with our Large Growing CG Art Community. It's Free!

THREAD CLOSED
 
Thread Tools Search this Thread Display Modes
  09 September 2012
Reading MR render log

When you turn on progress messages(and i even do not talk about detail messages) a lot of information came out. How to leran what does it mean?
Particular question: how to guess what is the most time consuming part of scene(which shader, light or geometry slowest)? What is most memory consuming part of rendering process?
And what does all this "JOB 0.6" "MEM 0.1 " mean.
Think its awesome way for optimizing renders and finding problems, but dont know how to start get deep into it.
__________________
3D animation blog
 
  09 September 2012
I only have a basic knowledge of this I got from Boav Livny's book a while back. I'd love to know how to use some of that info to optimize scenes as well. JOB = the mental ray module currently executing the task. 0.6 = computer and thread processing the task...I think. Been a little while since I went through that. That's all I've got I'd like to here further input here as well.
__________________
If animation is the illusion of life, then life is the illusion of reality.


"On ne sort pas DU REVE."

 
  09 September 2012
Thanks for tip, Justin, will get this book!

__________________
3D animation blog
 
  09 September 2012
Yep that's the one! Unfortunately a lot of the info is dated now but I still go back and reference it quite a bit. Very technical and very good. It was my main source of technical mental ray info for quite some time.
__________________
If animation is the illusion of life, then life is the illusion of reality.


"On ne sort pas DU REVE."

 
  09 September 2012
API
construction of elements in the scene database
DB
storage management of elements in the scene database
DISP
communication with real-time image viewers
ECHO
print the scene database in .mi format to stdout
API
construction of elements in the scene database
GAP
Geometry Approximation (tessellation into triangles)
GAPM
Geometry Approximation
GEOM
geometry modeling conversions
GEOT
geometry conversion for tessellation, a sub-module of GAP
IMG
image file access, disk read/write/map, and conversion
JOB
job control (3.x)
LIB
library of mathematical and other functions
LINK
dynamic linking of shader and shader libraries
MAIN
startup and interpretation of the command line
MEM
unstructured memory management (malloc replacement)
MI
mi scene file parser, converts text file into API calls
MSG
low-level message passing and thread management
PAR
high-level parallel message routing
PHEN
Phenomenon management and evaluation
RC
Rendering Component, front-end management module
RCB
RC sub-module handling triangle boxes
RCC RC
sub-module handling contours
RCGI
RC sub-module handling caustics and global illumination
RCH
RC sub-module handling hair rendering
RCHW
RC sub-module handling hardware rendering
RCI RC
sub-module handling scanline rendering and ray tracing
RCFG
RC sub-module handling final gathering
RCLM
RC sub-module handling light mapping
RCRM
RC sub-module handling the rasterizer
SCENE
structured scene database memory management
SURF
Subdivision surface geometry and modeling


API 0.1 error 301031: file.mi, line 123: call to undeclared function "X"
As for the rest of the header:

0 = Two characters (or more) for the number of the machine on the network, if network parallelism is used. Machine 0 is always the client machine where the rendering machine was started.

. = The decimal point separate host number and thread number. It is replaced by a colon if the thread is started by an application that mental ray is integrated into, rather than mental ray itself.

1 = Two characters (or more) for the thread number, if thread parallelism is used. Thread 0 is the mainline thread. Thread n is a special network communication (network parallelism only).
error = Six characters for the message level: fatal, error, warn, info, progr (progress), debugm and vdebg (verbose debug).

301031 = Seven characters for the fatal, error, or warning code number. The other message classes omit the number. The number uniquely identifies the message; it is intended for applications that mental ray is built into that need to know about problems without having to analyze an English text string. The number begins with a module ID (30 means API), severity (1 for (fatal) errors, 2 for warnings) and a sequential three-digit number that is arbitrary but unique for the module and severity.

The remainder of the message is a plain English description. Shader and Phenomenon scene elements.
 
  09 September 2012
Ok, what about finding the most time and memory consuming objects/shaders?
__________________
3D animation blog
 
  09 September 2012
Originally Posted by kiryha: Ok, what about finding the most time and memory consuming objects/shaders?
Good question. I wouldnt mind knowing what particular objects and/or shaders slow down renders.
__________________
Demo - Exterior
 
  09 September 2012
Look at the end of your render at the ray counts. This will give you an idea of the overall cost of a render.

I usually find the worst offenders are a lot of shadow rays per eye ray for a lot of soft shadows.

Also reflection ray explosions. (Lots of reflection rays per eye ray) Unified Sampling and more brute force methods mitigate this and make it faster. You can find a geometric explosion of ray casts with some shaders that are not well tuned (reflections of reflections of. . .each shooting rays). Future shaders will eliminate a lot of this problem.

Actual shader execution time is more of a debug mode and I don't think that's easily accessed inside Maya. But the hints above will tell you what effects are costing you the most time.

More details here: http://elementalray.wordpress.com/2...-do-i-fix-that/
__________________
My opinions are always my own...and maybe a friend's, but never my employer's.

Last edited by Bitter : 10 October 2012 at 12:36 PM.
 
  10 October 2012


RC   0.2  info : rendering statistics
RC   0.2  info :   type                           number   per eye ray
RC   0.2  info :   eye rays                      2387995          1.00
RC   0.2  info :   reflection rays              15738430          6.59
RC   0.2  info :   shadow rays                  44061335         18.45
RC   0.2  info :   environment rays             31317544         13.11
RC   0.2  info :   probe rays                   35415328         14.83
RC   0.2  info :   fg points interpolated       14186102          5.94
RC   0.2  info : on average 17.97 finalgather points used per interpolation
...
RC   0.2  info : wallclock  0:56:59.58 for rendering
RC   0.2  info : allocated 406 MB, max resident 568 MB
GAPM 0.2  info : triangle count (including retessellation) :     1103080
IMG  0.2  info : total for cached textures and framebuffers:
IMG  0.2  info :      444270697858 pixel accesses
IMG  0.2  info :          32862489 pages loaded/saved, 0.00739695% image cache failures
IMG  0.2  info : maximal texture cache size: 2288 pages, 34.379 MBytes
IMG  0.2  info : uncompressed cached texture I/O: 484545.965 MB
PHEN 0.2  info : Reflection rays skipped by threshold: 2133437


So, shadow rays most time consuming part of this remder(18.45 per eye ray), than probe and environment rays?
Shadow rays calculation, obvious, can be redused by reducing shadow samples, right?
What about environment and probe rays, what does thay mean, how to optimize render?
__________________
3D animation blog
 
  10 October 2012
Environment rays leave the scene, call the environment. Those are usually inexpensive.

Probe rays are usually Ambient Occlusion. Those can be expensive if:
1. There are a lot
2. You are using AO+Color bleed (runs shaders of struck objects)

Your image cache failures are good, you typically want those under .01% or smaller.

Other things that could be eating your render time are:

1. Aggressive Indirect Light settings. Your Final Gather phase, etc could be very long for no reason visually. Or your interpolation settings are high where the render phase has more calculation to do.
2. Texture I/O. Lots of large textures being read from a disk or across a network will be painful. Image caching here is helpful but more and larger files is just slower.

Unified Sampling:

Unified Sampling diagnostics (using the same diagnostics button) will give you a time (in seconds) per pixel in a layer of the diagnostic.exr. This will literally give you the pixels that are slowest to render. In many cases these are areas of contrast (object edges) and noise (soft shadows and glossiness)

Also, any non-physical shaped lights causing specular contribution (direct reflection) may cause noise when the light is large. For example: a large or dome area light where the object shader runs a highlight and not an actual reflection. This causes a lot of noise for the renderer to solve and draws more samples.

It might seem odd/old, but still-frame scenes and scenes where it can be reused may benefit from detail shadow maps where they are not recalculated each time.
__________________
My opinions are always my own...and maybe a friend's, but never my employer's.
 
  10 October 2012
Quote: Unified Sampling diagnostics (using the same diagnostics button) will give you a time (in seconds) per pixel in a layer of the diagnostic.exr. This will literally give you the pixels that are slowest to render. In many cases these are areas of contrast (object edges) and noise (soft shadows and glossiness)


Thanks! Its very nice visual way to catch time eaters in scene. A lot of info about reading diagnostic.exr i can find in your blog, so should be fine with this.


Well... i add cople of instanced glass bottles and rendertime rise from 56 min to almoust 11 hours.
I would not say i has extreme FG settings(they are default but secondary diffuse bounches=1) and 32 AO rays also not to high. Glass shaders is without glossy reflect/refract (mrGlobals reflections=2, refractions=6). 2 area lights with 12 high samples and 4 low samples, way to high for unified, but i render this images with adaptive sampling.




RC   0.2  info : rendering statistics
RC   0.2  info :   type                           number   per eye ray
RC   0.2  info :   eye rays                      2413566          1.00
RC   0.2  info :   reflection rays              71126167         29.47
RC   0.2  info :   refraction rays             269195483        111.53
RC   0.2  info :   shadow rays                  41147797         17.05
RC   0.2  info :   environment rays            277701614        115.06
RC   0.2  info :   probe rays                 7982004288       3307.14
RC   0.2  info :   fg points interpolated      162478825         67.32
RC   0.2  info : on average 18.62 finalgather points used per interpolation
...
RC   0.2  progr: rendering finished
RC   0.2  info : wallclock 10:45:55.47 for rendering
RC   0.2  info : allocated 414 MB, max resident 5920 MB
GAPM 0.2  info : triangle count (including retessellation) :     1109711
IMG  0.2  info : total for cached textures and framebuffers:
IMG  0.2  info :     1373119402434 pixel accesses
IMG  0.2  info :          37105740 pages loaded/saved, 0.0027023% image cache failures
IMG  0.2  info : maximal texture cache size: 2267 pages, 34.496 MBytes
IMG  0.2  info : uncompressed cached texture I/O: 546671.605 MB
PHEN 0.2  info : Reflection rays skipped by threshold: 12927119
PHEN 0.2  info : Refraction rays skipped by threshold: 81252317


I can understand, that render time will increase if i add refractive objects, but I think this is unexpected amount of rising. Or it should be so?
__________________
3D animation blog
 
  10 October 2012
Oh wow. Your probe rays are massive.

3000+ per eye ray. So almost 8 billion.

Are you running a super aggressive AO in render passes as well?
Does it make sense to have it on in the glass shaders? Remember, each bounce (reflection or refraction) will hit another shader and possibly call more AO rays. If you require it for primary rays, I might use a rayswitch with it off for reflections and refractions.

As a lighting effect, if necessary, leave it about 4 samples for Unified Sampling. Maybe 6 if still noisy.

Refraction seems a little high, glossy glass?
Reflection with brute force should be closer to 1 or 2 per eye ray.

Shadow is reasonable.

Default FG seems fine in most cases for a still frame.
__________________
My opinions are always my own...and maybe a friend's, but never my employer's.
 
  10 October 2012
Quote: Are you running a super aggressive AO in render passes as well?

What does it mean? AO settings in render globals are default(i use mentalcore), but max distance is rediqulas high (160 units, while my charactar height is 16 units only), will fix it for sure.
And i have AO enabled in all my shaders, and indeed i dont think its necessary in glass shaders, i will turn it off, rerender and check results. Definatley i dont need AO in reflect-refract, cos its even invisible, so rayswitch would help to optimize.
Never thought AO can be so expencive....

As for unified sampling. I start using this algoritm and i like the result much more than adaptive. Even with luck of quality image looks plesent and acceptable, not so ugly as with insufficient adaptive samples. Closer to rendermen i would say.
__________________
3D animation blog

Last edited by kiryha : 10 October 2012 at 09:17 AM.
 
  10 October 2012
Originally Posted by kiryha: What does it mean? AO settings in render globals are default(i use mentalcore), but max distance is rediqulas high (160 units, while my charactar height is 16 units only), will fix it for sure.
And i have AO enabled in all my shaders, and indeed i dont think its necessary in glass shaders, i will turn it off, rerender and check results. Definatley i dont need AO in reflect-refract, cos its even invisible, so rayswitch would help to optimize.
Never thought AO can be so expencive....

As for unified sampling. I start using this algoritm and i like the result much more than adaptive. Even with luck of quality image looks plesent and acceptable, not so ugly as with insufficient adaptive samples. Closer to rendermen i would say.


The massive amount of AO rays must be to do with the refracting objects, as david said, turn off AO on those objects and see what happens. Also, are you using AO transparency with MentalCore? That could potentially cause extra probe rays.

If you get stuck, post a scene if you can
__________________
www.core-cg.com
MentalCore - Shading and rendering pipeline for Maya/Mentalray
 
  10 October 2012
After turning of AO (i do not use transparancy with AO) in glass shaders i get some decreasing of probe rays, but render fail(i did it on the other mashine this time), so cant be sure about render time now. Will re render again to see.
Can we know the reason of crash from render log?

RC   0.2  info : rendering statistics
RC   0.2  info :   type                           number   per eye ray
RC   0.2  info :   eye rays                      2417754          1.00
RC   0.2  info :   reflection rays              74374236         30.76
RC   0.2  info :   refraction rays             308730070        127.69
RC   0.2  info :   shadow rays                  41456084         17.15
RC   0.2  info :   environment rays            312280139        129.16
RC   0.2  info :   probe rays                 3081748992       1274.63
RC   0.2  info :   fg points interpolated      175033621         72.40
RC   0.2  info : on average 18.72 finalgather points used per interpolation
DB   0.2  fatal  041061: invalid tag value 0xc0000000 requested
DB   0.2  fatal  041061: invalid tag value 0xc0000000 requested
DB   0.2  fatal  041061: invalid tag value 0xc0000000 requested
DB   0.2  fatal  041061: invalid tag value 0xc0000000 requested
// Maya exited with status 1
__________________
3D animation blog
 
Thread Closed share thread



Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off
CGSociety
Society of Digital Artists
www.cgsociety.org

Powered by vBulletin
Copyright 2000 - 2006,
Jelsoft Enterprises Ltd.
Minimize Ads
Forum Jump
Miscellaneous

All times are GMT. The time now is 04:01 AM.


Powered by vBulletin
Copyright ©2000 - 2017, Jelsoft Enterprises Ltd.