Super LOW performance on CPU rendering in complex scene #92601

New Issue

Juan Gea · 2021-10-29T11:27:04+02:00

Juan Gea commented

2021-10-29 11:27:04 +02:00

System Information
Operating system: Linux-5.13.0-7614-generic-x86_64-with-glibc2.33 64 Bits
Graphics card: NVIDIA GeForce GTX 1080/PCIe/SSE2 NVIDIA Corporation 4.5.0 NVIDIA 470.82.00

Blender Version
Broken: version: 3.0.0 Beta, branch: master, commit date: 2021-10-29 09:04, hash: f13826a572
Worked: 2.93.x

Short description of error

The CPU rendering performance on complex scenes is awful, making it not just way slower than in 2.93.x but making computers with 16 threads to work nearly at 50% or less of it's render capacity.

In a TR 2990WX the majority of the cores may be some times even at 0% in a more or less complex scene, but this happens too with a Ryzen 5950X as was checked by @leesonw

Example picture:

Exact steps for others to reproduce the error

@leesonw has an example scene that I shared with him privately since it has commercial assets on it.

Basically open the scene and render, check the CPU threads load.

**System Information** Operating system: Linux-5.13.0-7614-generic-x86_64-with-glibc2.33 64 Bits Graphics card: NVIDIA GeForce GTX 1080/PCIe/SSE2 NVIDIA Corporation 4.5.0 NVIDIA 470.82.00 **Blender Version** Broken: version: 3.0.0 Beta, branch: master, commit date: 2021-10-29 09:04, hash: `f13826a572` Worked: 2.93.x **Short description of error** The CPU rendering performance on complex scenes is awful, making it not just way slower than in 2.93.x but making computers with 16 threads to work nearly at 50% or less of it's render capacity. In a TR 2990WX the majority of the cores may be some times even at 0% in a more or less complex scene, but this happens too with a Ryzen 5950X as was checked by @leesonw Example picture: ![Captura de pantalla de 2021-10-28 11-37-35.png](https://archive.blender.org/developer/F11594045/Captura_de_pantalla_de_2021-10-28_11-37-35.png) **Exact steps for others to reproduce the error** @leesonw has an example scene that I shared with him privately since it has commercial assets on it. Basically open the scene and render, check the CPU threads load.

Juan Gea commented

2021-10-29 11:27:04 +02:00

Added subscribers: @leesonw, @juang3d

Steffen Dünner commented

2021-10-29 11:40:46 +02:00

Added subscriber: @SteffenD

Raimund Klink commented

2021-10-29 12:40:13 +02:00

Added subscriber: @Raimund58

Philipp Oeser commented

2021-10-29 15:29:28 +02:00

Added subscriber: @lichtwerk

Philipp Oeser commented

2021-10-29 15:29:28 +02:00

Changed status from 'Needs Triage' to: 'Confirmed'

Philipp Oeser commented

2021-10-29 15:29:28 +02:00

as was checked by @leesonw

Will read that as "Confirmed".

> as was checked by @leesonw Will read that as "Confirmed".

Juan Gea commented

2021-10-29 15:31:47 +02:00

Yep, I was checking this with him yesterday.

Jakub Jaszewski commented

2021-10-29 19:47:48 +02:00

Added subscriber: @silex

Jakub Jaszewski commented

2021-10-29 19:47:48 +02:00

I also tested this scene from @juang3d. With Threadripper 3970X the CPU sits around 35% with one thread maxed 100%. Didn't see any sudden dips to 0%.

With increased number of particles 20 times the rendering performance is much worse and there are visible memory fluctuations. Around 16GB of data is dumped and loaded again. Memgraph is on the left.

I also tested this scene from @juang3d. With Threadripper 3970X the CPU sits around 35% with one thread maxed 100%. Didn't see any sudden dips to 0%. ![2021-10-29_19-33.png](https://archive.blender.org/developer/F11602297/2021-10-29_19-33.png) With increased number of particles 20 times the rendering performance is much worse and there are visible memory fluctuations. Around 16GB of data is dumped and loaded again. Memgraph is on the left. ![2021-10-29_20-14.png](https://archive.blender.org/developer/F11604409/2021-10-29_20-14.png)

William Leeson commented

2021-11-08 10:37:12 +01:00

If I render from the command line using

../build_linux/bin/blender -b scene.blend -f 1

I no longer have the performance issues there are a few dips on 1 or 2 CPUs at the start but it settles down to 100% on all CPUs after a bit. @juang3d does this also happen for you? Is it only a case of when rendering with the UI? From this I am going to look at the image update and see if that is the culprit. I am not sure why this causes so much trouble but I am guessing that too many threads are trying to send data at the same time and something about this scene causes that.

If I render from the command line using ``` ../build_linux/bin/blender -b scene.blend -f 1 ``` I no longer have the performance issues there are a few dips on 1 or 2 CPUs at the start but it settles down to 100% on all CPUs after a bit. @juang3d does this also happen for you? Is it only a case of when rendering with the UI? From this I am going to look at the image update and see if that is the culprit. I am not sure why this causes so much trouble but I am guessing that too many threads are trying to send data at the same time and something about this scene causes that.

Juan Gea commented

2021-11-08 11:14:33 +01:00

I tested this, and while I still see a bit of inconsistency, the result is way better, check this picture:

You can see how it is not always at 100%, but goes sometimes to 70/90%, but not as often as with the UI, also you can see three big drowns in the graph, those corresponds when a new message with the Sample number appear (marked with arrows with the same color).

As the scene render progress this happens more often, as you can see in this picture:

But with the exception of those drowns, the load is more consistent.

I tested this, and while I still see a bit of inconsistency, the result is way better, check this picture: ![image.png](https://archive.blender.org/developer/F11766781/image.png) You can see how it is not always at 100%, but goes sometimes to 70/90%, but not as often as with the UI, also you can see three big drowns in the graph, those corresponds when a new message with the Sample number appear (marked with arrows with the same color). As the scene render progress this happens more often, as you can see in this picture: ![image.png](https://archive.blender.org/developer/F11766799/image.png) But with the exception of those drowns, the load is more consistent.

William Leeson self-assigned this 2021-11-09 11:43:46 +01:00

William Leeson commented

2021-11-09 11:43:46 +01:00

It seems the main render loop in session.cpp is causing these pauses as the render time for each tile is not even between all the CPU so some finish early. The loop is session makes them work in lock step on each update iteration so every n samples the render halts for all threads to catch up then reassigns new work items. Here is a screen grap of a perf session showing all the rendering threads

They all line up waiting for the next iteration.

It seems the main render loop in session.cpp is causing these pauses as the render time for each tile is not even between all the CPU so some finish early. The loop is session makes them work in lock step on each update iteration so every n samples the render halts for all threads to catch up then reassigns new work items. Here is a screen grap of a perf session showing all the rendering threads ![image.png](https://archive.blender.org/developer/F11774184/image.png) They all line up waiting for the next iteration.

Brecht Van Lommel commented

2021-11-09 12:35:45 +01:00

Added subscriber: @brecht

Brecht Van Lommel commented

2021-11-09 12:35:46 +01:00

If background rendering makes a big difference then indeed the image display is likely to be a problem. The next step would be to then figure out which parts of that are making other threads wait, it's not obvious to me where the issue could be, but it should be quite clear in a profiler.

For background rendering, I guess the thing to look into is the tbb::parallel_for loops in path_trace_work_cpu.cpp. From the image, it looks like the top part would be much faster to render than the bottom part, so you could imagine poor work distribution being the problem. As far as I know, tbb::parallel_for is supposed to use work stealing to do balancing. It may be that the grain size needs to be smaller. I'm not sure what that is by default. It would be interesting to set that to 1, 2, 4, 8, .. and see what happens. There may be other parameters in TBB than can be tweaked,

It may also be that some CPU cores get assigned to another thread/process in the middle of working on a pixel sample, and the operating system doesn't schedule another CPU core to finish this work quickly, which then ends up blocking everything else. I would expect it to render enough samples at a time that this doesn't have a big impact, but maybe.

If background rendering makes a big difference then indeed the image display is likely to be a problem. The next step would be to then figure out which parts of that are making other threads wait, it's not obvious to me where the issue could be, but it should be quite clear in a profiler. For background rendering, I guess the thing to look into is the `tbb::parallel_for` loops in `path_trace_work_cpu.cpp`. From the image, it looks like the top part would be much faster to render than the bottom part, so you could imagine poor work distribution being the problem. As far as I know, `tbb::parallel_for` is supposed to use work stealing to do balancing. It may be that the grain size needs to be smaller. I'm not sure what that is by default. It would be interesting to set that to 1, 2, 4, 8, .. and see what happens. There may be other parameters in TBB than can be tweaked, It may also be that some CPU cores get assigned to another thread/process in the middle of working on a pixel sample, and the operating system doesn't schedule another CPU core to finish this work quickly, which then ends up blocking everything else. I would expect it to render enough samples at a time that this doesn't have a big impact, but maybe.

Anton Raves commented

2021-11-09 14:00:16 +01:00

Added subscriber: @Memento

William Leeson commented

2021-11-11 11:32:26 +01:00

It seems this is caused by the starting and stopping of the profiling which was always on for the CPU. By disabling this the idling has been largely gone.

Background	UI

there could still be some work optimizing the threading as there is still a certain amount of lock stepping between sample cycles. This is particularly true when rendering from blender where updates are more frequent.

It seems this is caused by the starting and stopping of the profiling which was always on for the CPU. By disabling this the idling has been largely gone. | Background | UI | | -- | -- | |![image.png](https://archive.blender.org/developer/F11793378/image.png)|![image.png](https://archive.blender.org/developer/F11793392/image.png)| there could still be some work optimizing the threading as there is still a certain amount of lock stepping between sample cycles. This is particularly true when rendering from blender where updates are more frequent.

William Leeson commented

2021-11-11 14:25:35 +01:00

Some performance data on the three patches

patch	Juans Scene UI 256 samples	Juans Scene bg 256 samples	junkshop UI	junkshop bg
No patch	6:16.59	4:05.37	2:08.48	1:59.7
D13187	4:12.15	3:57.36	2:07.25	1:58.16
D13185	4.11.18	3:54.74	2:07.44	1:58.03
D13190	4:12.39	3:55.42	2:07.62	1:58.68

UI - means rendered from within Blender
bg - means rendered from the command line using ##blender -b scene.blend -f 1##

Some performance data on the three patches | patch | Juans Scene UI 256 samples | Juans Scene bg 256 samples | junkshop UI | junkshop bg | | -- | -- | -- | -- | -- | | No patch | 6:16.59 | 4:05.37 | 2:08.48 | 1:59.7 | | [D13187](https://archive.blender.org/developer/D13187) | 4:12.15 | 3:57.36 | 2:07.25 | 1:58.16 | | [D13185](https://archive.blender.org/developer/D13185) | 4.11.18 |3:54.74 | 2:07.44 | 1:58.03 | | [D13190](https://archive.blender.org/developer/D13190) | 4:12.39 | 3:55.42 | 2:07.62 | 1:58.68 | UI - means rendered from within Blender bg - means rendered from the command line using ##blender -b scene.blend -f 1##

Raimund Klink commented

2021-11-11 14:35:06 +01:00

@leesonw What do the first two columns mean? Just UI and Background... But what?

William Leeson commented

2021-11-11 14:46:17 +01:00

For the 1st column: I have 2 different patches so this column shows the results for which patch is applied or if no patch is applied.
Column 2: is rendering Juan's scene from within Blender
Column 3: is rendering Juan's scene from the command line blender - b etc...

For the 1st column: I have 2 different patches so this column shows the results for which patch is applied or if no patch is applied. Column 2: is rendering Juan's scene from within Blender Column 3: is rendering Juan's scene from the command line blender - b etc...

Raimund Klink commented

2021-11-11 15:10:40 +01:00

Okay, thank you for your explanation. I guess UI and bg was accidentally swapped for the first row?