Isotropix Forums

Render Time Issue on CNode Renderfarm

General Discussion about Isotropix and CG related topics

Render Time Issue on CNode Renderfarm

Unread postby nareineru » Fri Sep 27, 2019 11:30 am

Hello.
We are currently using CNode on our renderfarm and recently we have encountered an issue regarding the render time.
We have tested rendering a project file which has almost zero camera movement and every frame rendered out fine with no quality difference or errors. However certain frames took five times longer than others.

Here is part of logs from a couple of frames which had noticeable differences.


The first log is the one that rendered out faster than others.

CNODE Preferences
-----------------
* General:
- Enable file logging: no
- Log file policy: 1
- Log file path:
* Evaluation:
- Max core count: 40
* Animation:
- Frames per second: 24
* Rendering:
- Motion blur sample count: 3
- Motion blur direction: 0
- Motion blur length: 50%
- Texture cache: 131072 MB
00:04:54 1464/1503MB
Image to be rendered:
00:04:54 1464/1503MB project://scene/RenderLayer/GAE_0020.GAE_0310
00:04:54 1464/1503MB
00:04:54 1464/1503MB CNode licensing up and running.
00:04:58 1599/1599MB Current Image: project://scene/RenderLayer/GAE_0020 Frame: 1002
00:04:58 1602/1602MB Rendering 3D layer 'GAE_0310'
00:04:58 1602/1602MB Scanning for cache {'/show/BANDO/seq/GAE/GAE_0020/lit/wip/images/bando_GAE_litSet_test2/GAE_0310/bando_GAE_litSet_test2GAE_0310.1002'}
00:04:58 1602/1602MB Reading cache file '/show/BANDO/seq/GAE/GAE_0020/lit/wip/images/bando_GAE_litSet_test2/GAE_0310/bando_GAE_litSet_test2GAE_0310.1002.ix.00.dat'
00:04:58 1602/1602MB Progress for 'project://scene/RenderLayer/GAE_0020' : 0%
00:04:58 1602/1602MB Subprogress 'project://scene/RenderLayer/GAE_0020.GAE_0310' : 0%
00:04:59 1602/1602MB History : Wed Sep 25 06:46:11 : Render started [rdf467] : progress 0.00%
00:04:59 1602/1602MB History : 00:06:30 : progress 0.04%
00:04:59 1602/1602MB History : 00:07:01 : progress 1.04%
00:04:59 1602/1602MB History : 00:07:17 : progress 1.09%
00:04:59 1602/1602MB History : 00:07:48 : progress 1.61%
00:04:59 1602/1602MB History : 00:07:51 : progress 1.65%
00:04:59 1602/1602MB History : 00:08:22 : progress 2.30%
00:04:59 1602/1602MB History : 00:08:37 : progress 2.39%
00:04:59 1602/1602MB History : 00:08:57 : progress 2.43%
00:04:59 1602/1602MB History : 00:09:34 : progress 2.56%
00:04:59 1602/1602MB History : 00:09:48 : progress 2.69%
00:04:59 1602/1602MB History : 00:10:36 : progress 2.73%
00:04:59 1602/1602MB History : 00:11:09 : progress 3.30%
00:04:59 1602/1602MB History : 00:12:21 : progress 4.08%
00:04:59 1602/1602MB History : 00:13:04 : progress 4.17%
00:04:59 1602/1602MB History : 00:13:58 : progress 4.30%
00:04:59 1602/1602MB History : 00:14:35 : progress 4.34%
00:04:59 1602/1602MB History : 00:17:21 : progress 4.38%
00:04:59 1602/1602MB History : 00:18:19 : progress 4.43%
00:04:59 1602/1602MB History : 00:18:50 : progress 4.69%





The second one is the one that took longer than other frames.



CNODE Preferences
-----------------
* General:
- Enable file logging: no
- Log file policy: 1
- Log file path:
* Evaluation:
- Max core count: 56
* Animation:
- Frames per second: 24
* Rendering:
- Motion blur sample count: 3
- Motion blur direction: 0
- Motion blur length: 50%
- Texture cache: 131072 MB
00:03:44 1490/1529MB
Image to be rendered:
00:03:44 1490/1529MB project://scene/RenderLayer/GAE_0020.GAE_0310
00:03:44 1490/1529MB
00:03:45 1490/1529MB CNode licensing up and running.
00:03:49 1626/1626MB Current Image: project://scene/RenderLayer/GAE_0020 Frame: 1003
00:03:49 1629/1629MB Rendering 3D layer 'GAE_0310'
00:03:49 1629/1629MB Scanning for cache {'/show/BANDO/seq/GAE/GAE_0020/lit/wip/images/bando_GAE_litSet_test2/GAE_0310/bando_GAE_litSet_test2GAE_0310.1003'}
00:03:49 1629/1629MB No cache files found.
00:03:49 1629/1629MB Opening image cache file for writing '/show/BANDO/seq/GAE/GAE_0020/lit/wip/images/bando_GAE_litSet_test2/GAE_0310/bando_GAE_litSet_test2GAE_0310.1003.ix.00.dat'
00:03:49 1679/1679MB WARNING: PolyMesh: the triangulation has detected 2 degenerated triangles
00:03:49 1680/1680MB WARNING: PolyMesh: the triangulation has detected 5 degenerated triangles
00:03:49 1683/1684MB WARNING: PolyMesh: the triangulation has detected 8 degenerated triangles
00:03:49 1784/1784MB WARNING: PolyMesh: the triangulation has detected 8 degenerated triangles
00:03:49 2105/2107MB WARNING: PolyMesh: the triangulation has detected 2 degenerated triangles
00:03:49 2168/2170MB WARNING: PolyMesh: the triangulation has detected 1 degenerated triangles
00:03:49 2200/2202MB WARNING: PolyMesh: the triangulation has detected 5 degenerated triangles
00:03:49 2282/2285MB WARNING: PolyMesh: the triangulation has detected 12 degenerated triangles
00:03:49 2415/2417MB WARNING: PolyMesh: the triangulation has detected 5 degenerated triangles
00:03:49 2532/2536MB WARNING: PolyMesh: the triangulation has detected 2 degenerated triangles
00:03:49 2755/2757MB WARNING: PolyMesh: the triangulation has detected 4 degenerated triangles


The slower one says that there's "no cache files found".
And the slower one also is missing "render started" message for some reason.

We also suspected the problem might be happening to certain render machine, but it turns out the one which rendered out slow also rendered out fine for other frame and vice versa.
And there's no noticeable pattern in render start time.

Any suggestion or hint would be greatly appreciated.

Thanks.
nareineru
 
Posts: 22
Joined: Tue Feb 06, 2018 10:48 am

Re: Render Time Issue on CNode Renderfarm

Unread postby dboude » Fri Sep 27, 2019 2:03 pm

Hi,

Did you render the frame 1002 (partially) before logging this ?

You render with render cache option activated. So it seems that the frame 1002 was partially rendered (render was killed, by user login or the job was killed...). Cnode found a render cache and continued to render from that cache. For the frame 1003, a cache was not found so the render started from de beginning.

The thing what we could improve is to calculate how many tiles of the image were rendered and start the progress from that percentage instead starting from 0% like in your log for the frame 1002.

Does it make sense or do you still feel that there is a weird thing going on your farm?

Cheers ;)
Démian
Isotropix
Technical Artist - Clarisse Specialist
User avatar
dboude
 
Posts: 1251
Joined: Mon Jul 03, 2017 10:51 am


Return to General Discussion