Intensive CPU/GPU usage when displaying animated content in the editor scene

itsjavi commented 4 years ago

Bugsquad note: This issue has been confirmed several times already. No need to confirm it further.

Godot version:

3.2.1.stable.official
3.2.2.rc3

OS/device including version:

OS: macOS Catalina 10.15.5
Hardware:
- macbook Pro 13' 2015 + Intel Iris Graphics 6100 + 8 GB RAM + i5 Dual Core
- macbook Pro 13' 2018 + Intel Iris Plus Graphics 655 + 16 GB RAM + i5 Quad Core

Issue description: When using AnimatedTexture(s) the editor seems to put a lot of load in the CPU, whose fans start to work intensively (they can become very loud in both macs). As you can see in the following GIF, the CPU usage is around 20% and GPU ~35% even if the IDE is idle:

Jun-22-2020 19-00-46

I don't know if this is a CPU or GPU issue. You can also see that the Idle Wake-ups are higher than normal (I don't know if that's some indicator for this issue). Only when the node having the animations is hidden, the hardware load starts to normalize.

This is maybe related to https://github.com/godotengine/godot/issues/30115 , but I am not sure, that's why I created this ticket.

Steps to reproduce:

Create a new project (2D, GLES3)
Create a new AnimatedTexture with some frames, assigning images to them.
Use it in a new TileSet resource (not sure if this is related or not), as single tile.
Draw some tiles in a new TileMap node, using the animated tile you created.
Wait some minutes with the IDE playing the animations of your animated tiles // or continue working with the IDE and the scene having the animations.

This issue only affects the IDE. The game itself doesn't seem to have this problem when running.

Minimal reproduction project:

godot-issue-39758.zip

PS: Would be nice and convenient to be able to stop playing animated textures (or animations in general) in the IDE. A button or a checkbox in the menu or in the IDE settings.

lawnjelly commented 4 years ago

PS: Would be nice and convenient to be able to stop playing animated textures in the IDE. A button or a checkbox in the menu.

Agree with this (may have mentioned it before in another issue in fact). And not just animated textures, all the features that request frame updates (shaders using time, bones animations etc). Would be very helpful on lower power machines. As it is, I have to manually close tabs in order to prevent this runaway CPU usage.

Calinou commented 4 years ago

@lawnjelly This was implemented in https://github.com/godotengine/godot/pull/31070, but it needs to be redone for the current master branch as it wasn't merged.

itsjavi commented 4 years ago

@Calinou cool, I think this option would be enough for now, since this only affects the IDE. It seems not a problem for the compiled game itself.

itsjavi commented 4 years ago

Issue still present in 3.2.3 RC3

Multitasking becomes difficult when the IDE has a +35% CPU usage because of this.

CPU fans are running at full speed all the time until the Animated sprites are hidden.

Tried on a macbook PRO 2018 (Intel graphics)

ghost commented 4 years ago

Hi,

Can you please post detailed instructions on creating the "AnimatedTexture", I do not see it when adding new nodes. Would love to test to see if I can reproduce this bug on v3.22.

Thanks.

Calinou commented 4 years ago

@knadoor An AnimatedTexture is a resource, not a node. You can create one by choosing New AnimatedTexture after clicking on the dropdown arrow next to a Sprite's Texture property.

ghost commented 4 years ago

Untitled I tried to replicate this but could not - I did notice an uptick in my laptops fans but CPU utilization is not bad. Perhaps if you create a video that would help.

lawnjelly commented 4 years ago

Just to clarify, is this issue caused by only animated texture, or does anything that causes editor updates cause it? If you place e.g. an animated model in the 3d window of the IDE?

itsjavi commented 4 years ago

In the description there is a minimal project zip file to reproduce it. Also, pls check the screenshot in the issue description (it's a GIF). GPU goes up to 35% with that project.

@lawnjelly I don't know if there are other use cases or features causing this problem, but I suspect that it has to do with anything related to previewing animated content.

@knadoor I see that you are using Windows and that's maybe why you cannot reproduce it. The issue I reported is for macOS using Intel integrated graphics cards. So I guess this happens in less-capable GPUs.

lawnjelly commented 4 years ago

@lawnjelly I don't know if there are other use cases or features causing this problem, but I suspect that it has to do with anything related to previewing animated content.

In that case it is possible it could be a duplicate of #17584. This has been an ongoing issue on some Macs with slow rendering. None of the rendering guys tend to use Macs or have hardware that exhibits the problem, so it's been a bit difficult to investigate.

itsjavi commented 4 years ago

I see @lawnjelly should I close this issue then?

anyway I could help testing. I keep doing it in every RC release. I have a MBP 2015 (Intel Graphics), MBP 2018 (Intel Graphics) and an iMac 2019 with a Radeon 5700 XT, where I don't have this issue, so it seems related to Intel graphics.

lawnjelly commented 4 years ago

I see @lawnjelly should I close this issue then?

anyway I could help testing. I have a MBP 2015 (Intel Graphics), MBP 2018 (Intel Graphics) and an iMac 2019 with a Radeon 5700 XT, where I don't have this issue, so it seems related to Intel graphics.

You may well be right about it being Intel related. :+1:

If you are able to confirm that it is anything animated (try a shader using time, or an animated character maybe) that causes IDE updates which triggers slowness for you then we could close this one, as it would seem likely to be the same (and even the closed issue will be visible and linked now so that will help us with hardware specs). If other animations don't cause the same problem then it will suggest it is a different issue and it should remain separate.

ViktorEvil commented 4 years ago

can confirm this is a problem with animated sprites and in one small project I get the same screaming fans and 40% CPU usage in a scene with a few Particle2D nodes. I came here to see if anybody else was affected by this issue of if my MacBook Air 2015 was getting too old to be used with Godot

using Godot 3.2.2 macOS 10.15.6

Calinou commented 4 years ago

This was confirmed by someone on Windows. Apparently, disabling V-Sync and setting the FPS cap in the Project Settings to 60 decreases the CPU usage a lot.

Can someone try to run a debug build in a profiler to know where most of the CPU usage is coming from?

vaner-org commented 4 years ago

Unfortunately not Intel related, and not limited to AnimatedTexture(s) either.

On my MBP 2015 with the discrete Radeon R9 M370X, Godot's update spinner spinning means 100 (that's right) percent GPU processor load. This can be caused by anything that updates the editor continuously, and most egregiously: An idle animation on my 3D character. Which means if I have my animation tree enabled, I have godot using 100% of my GPU. If I use a ClippedCamera, 100%.

About a minute of GPU load with constant spinning (with the Animation Tree on), versus a minute without:

This is not tied to anything specific. It is simply how Godot updates on my machine, unfortunately. If I enable "Update continuously" in the Editor settings, I see the same behaviour, 100%.

I fear that this may be indicative of a larger issue on the Mac side than just what is found in this thread. Should I create a new issue for this?

I really would like to help fix this, in whichever way I can, since Godot is basically unusable for me otherwise. While my programming is nowhere enough, I can build and test any branch that needs it.

Calinou commented 4 years ago

@molevision Rendering the editor at an hiDPI scale is much more demanding than at a loDPI scale. That said, you can enable Half Resolution in the Perspective/Orthogonal menu at the top-left corner of the 3D viewport to decrease the GPU load. (GPU load will still be higher than on an actual loDPI display due to 2D elements being rendered at a higher resolution and all that.)

On top of that, you can also increase Low Processor Mode Sleep Usec in the Project Settings to make the editor redraw less often. 100000 is the highest you can go (effectively 10 FPS), but a value like 33333 (30 FPS) is probably more reasonable. Note that this value applies only if Update Continuously is not enabled.

The only way I see to fix this is to add a button that pauses various simulations in the editor: https://github.com/godotengine/godot-proposals/issues/942

There's a pull request that attempted to add this, but it needs to be salvaged: https://github.com/godotengine/godot/pull/31070

vaner-org commented 4 years ago

@Calinou Thank you for the help, I tried the steps you mentioned (LoDPI and 33333 low processor mode sleep usec) but even then I get about 80% constant load, if the editor updates continuously. Even with my game running with low processor mode disabled I get less load on the GPU, about 30-40%.

Could I be assured this is expected behaviour with Godot's update system? Surely, a new project with only an empty Particles node shouldn't be completely maxing out the GPU load?

Regardless, the pause button seems like a really good solution for the time being. Maybe calling it something else (like "freeze") would help prevent confusion with the pause scene button right above it.

Calinou commented 4 years ago

Could I be assured this is expected behaviour with Godot's update system? Surely, a new project with only an empty Particles node shouldn't be completely maxing out the GPU load?

If anything causes the editor to redraw continuously, then the entire editor must draw 60 times a second (or more on high refresh rate monitors). There is no notion of partial redraws in most game engines, since most games will always cause the whole screen to update in one way or another during gameplay.

vaner-org commented 4 years ago

I did a little more digging and ran Godot with the same settings I had earlier, at HiDPI, except forcing it to use my integrated Intel (Iris Pro) card, and performance was dramatically better, only ~40% GPU used with both the game and the editor running, and focus on the continuously updating editor. The editor's framerate was a little slower but the game's was identical. So unlike everyone else on the thread, the load on the Intel chipset on my 2015 MBP is half than that on my discrete AMD card. I'll run tests with a Vulkan build to see if anything has changed with Metal.

Regardless, until we can reconcile this, salvaging #31070 would be a lifesaver.

naithar commented 4 years ago

CPU usage of MRP in Instruments app. Hopefully it'll help.

Animated tiles enabled (tested for 5 seconds):

Trace:

  23  8077.0  godot (9615) :0
  22 libdyld.dylib 8077.0  0x7fff70cc5cc8
  21 godot 8077.0  main src/platform/osx/godot_main_osx.mm:71
  20 godot 8077.0  OS_OSX::run() src/platform/osx/os_osx.mm:3153
  19 godot 7920.0  Main::iteration() src/main/main.cpp:2118
  18 godot 7622.0  VisualServerWrapMT::draw(bool, double) src/servers/visual/visual_server_wrap_mt.cpp:102
  17 godot 7621.0  VisualServerRaster::draw(bool, double) /Users/naithar/Projects/godot_xcode/src/servers/visual/visual_server_raster.cpp:108
  16 godot 6897.0  VisualServerViewport::draw_viewports() src/servers/visual/visual_server_viewport.cpp:344
  15 godot 6826.0  VisualServerViewport::_draw_viewport(VisualServerViewport::Viewport*, ARVRInterface::Eyes) src/servers/visual/visual_server_viewport.cpp:241
  14 godot 6801.0  VisualServerCanvas::render_canvas(VisualServerCanvas::Canvas*, Transform2D const&, RasterizerCanvas::Light*, RasterizerCanvas::Light*, Rect2 const&, int) src/servers/visual/visual_server_canvas.cpp:270
  13 godot 6223.0  RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) src/drivers/gles3/rasterizer_canvas_gles3.cpp:1708
  12 godot 5939.0  RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) src/drivers/gles3/rasterizer_canvas_gles3.cpp:871
  11 godot 1174.0  RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) src/drivers/gles3/rasterizer_canvas_gles3.cpp:607

Animated tiles disabled (tested for 10 seconds):

lawnjelly commented 4 years ago

@naithar that is interesting to look at. Can the profiler display how many times each function is called too?

One possibility is that the whole render is being done far more times than expected (e.g. if the scene was being rendered 400 times per second or something), so it would be nice to discount that.

I'm assuming the figures given are time within function and children, percentage of time within function and children, and time within function excluding children. In which case none of the functions shown seem to be hogging the time on the CPU, so on first impressions it seems to be bottlenecked by the GPU or driver.

naithar commented 4 years ago

Found some ugly way to count the amount of times function got called via breakpoint list (which almost killed my mac 😆 ). Both test was running for 2 minutes. Not sure if they are anywhere correct, but that's what I got.

Running with animation disabled:

Summary: 1.1 Main::iteration - max hit count = 5293 2.1 VisualServerViewport::draw_viewports() - max hit count = 13 3.1 VisualServerCanvas::render_canvas - max hit count = 26 4.1 RasterizerCanvasGLES3::canvas_render_items - max hit count = 26 5.1 RasterizerCanvasGLES3::_draw_gui_primitive - max hit count = 1756 6.1 RasterizerCanvasGLES3::_canvas_item_render_commands - max hit count = 959

Long log

``` 1: file = 'src/main/main.cpp', line = 2031, exact_match = 0, locations = 1, resolved = 1, hit count = 5293 1.1: where = godot`Main::iteration() + 25 at main.cpp:2036:11, address = 0x0000000100054ef9, resolved, hit count = 5293 2: file = 'src/servers/visual/visual_server_viewport.cpp', line = 267, exact_match = 0, locations = 1, resolved = 1, hit count = 13 2.1: where = godot`VisualServerViewport::draw_viewports() + 44 at visual_server_viewport.cpp:270:21, address = 0x0000000102fc295c, resolved, hit count = 13 3: file = 'src/servers/visual/visual_server_canvas.cpp', line = 227, exact_match = 0, locations = 1, resolved = 1, hit count = 25 3.1: where = godot`VisualServerCanvas::render_canvas(VisualServerCanvas::Canvas*, Transform2D const&, RasterizerCanvas::Light*, RasterizerCanvas::Light*, Rect2 const&, int) + 87 at visual_server_canvas.cpp:229:2, address = 0x0000000102f73957, resolved, hit count = 25 4: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 1417, exact_match = 0, locations = 1, resolved = 1, hit count = 25 4.1: where = godot`RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) + 45 at rasterizer_canvas_gles3.cpp:1419:8, address = 0x0000000100f66e8d, resolved, hit count = 25 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 3: file = 'src/servers/visual/visual_server_canvas.cpp', line = 227, exact_match = 0, locations = 1, resolved = 1, hit count = 26 3.1: where = godot`VisualServerCanvas::render_canvas(VisualServerCanvas::Canvas*, Transform2D const&, RasterizerCanvas::Light*, RasterizerCanvas::Light*, Rect2 const&, int) + 87 at visual_server_canvas.cpp:229:2, address = 0x0000000102f73957, resolved, hit count = 26 4: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 1417, exact_match = 0, locations = 1, resolved = 1, hit count = 26 4.1: where = godot`RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) + 45 at rasterizer_canvas_gles3.cpp:1419:8, address = 0x0000000100f66e8d, resolved, hit count = 26 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1752 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1752 6: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 700, exact_match = 0, locations = 1, resolved = 1, hit count = 959 6.1: where = godot`RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) + 60 at rasterizer_canvas_gles3.cpp:702:11, address = 0x0000000100f6973c, resolved, hit count = 959 6: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 700, exact_match = 0, locations = 1, resolved = 1, hit count = 959 6.1: where = godot`RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) + 60 at rasterizer_canvas_gles3.cpp:702:11, address = 0x0000000100f6973c, resolved, hit count = 959 6: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 700, exact_match = 0, locations = 1, resolved = 1, hit count = 959 6.1: where = godot`RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) + 60 at rasterizer_canvas_gles3.cpp:702:11, address = 0x0000000100f6973c, resolved, hit count = 959 6: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 700, exact_match = 0, locations = 1, resolved = 1, hit count = 959 6.1: where = godot`RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) + 60 at rasterizer_canvas_gles3.cpp:702:11, address = 0x0000000100f6973c, resolved, hit count = 959 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1756 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1756 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 1756 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 1756 ```

Running with animation enabled:

Summary: 1.1 Main::iteration - max hit count = 33 2.1 VisualServerViewport::draw_viewports() - max hit count = 33 3.1 VisualServerCanvas::render_canvas - max hit count = 66 4.1 RasterizerCanvasGLES3::canvas_render_items - max hit count = 99 5.1 RasterizerCanvasGLES3::_draw_gui_primitive - max hit count = 4672 6.1 RasterizerCanvasGLES3::_canvas_item_render_commands - max hit count = 2506

Long log

``` 6: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 700, exact_match = 0, locations = 1, resolved = 1, hit count = 2506 6.1: where = godot`RasterizerCanvasGLES3::_canvas_item_render_commands(RasterizerCanvas::Item*, RasterizerCanvas::Item*, bool&) + 60 at rasterizer_canvas_gles3.cpp:702:11, address = 0x0000000100f6973c, resolved, hit count = 2506 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 1: file = 'src/main/main.cpp', line = 2031, exact_match = 0, locations = 1, resolved = 1, hit count = 33 1.1: where = godot`Main::iteration() + 25 at main.cpp:2036:11, address = 0x0000000100054ef9, resolved, hit count = 33 2: file = 'src/servers/visual/visual_server_viewport.cpp', line = 267, exact_match = 0, locations = 1, resolved = 1, hit count = 33 2.1: where = godot`VisualServerViewport::draw_viewports() + 44 at visual_server_viewport.cpp:270:21, address = 0x0000000102fc295c, resolved, hit count = 33 3: file = 'src/servers/visual/visual_server_canvas.cpp', line = 227, exact_match = 0, locations = 1, resolved = 1, hit count = 65 3.1: where = godot`VisualServerCanvas::render_canvas(VisualServerCanvas::Canvas*, Transform2D const&, RasterizerCanvas::Light*, RasterizerCanvas::Light*, Rect2 const&, int) + 87 at visual_server_canvas.cpp:229:2, address = 0x0000000102f73957, resolved, hit count = 65 4: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 1417, exact_match = 0, locations = 1, resolved = 1, hit count = 97 4.1: where = godot`RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) + 45 at rasterizer_canvas_gles3.cpp:1419:8, address = 0x0000000100f66e8d, resolved, hit count = 97 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 4: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 1417, exact_match = 0, locations = 1, resolved = 1, hit count = 98 4.1: where = godot`RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) + 45 at rasterizer_canvas_gles3.cpp:1419:8, address = 0x0000000100f66e8d, resolved, hit count = 98 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 3: file = 'src/servers/visual/visual_server_canvas.cpp', line = 227, exact_match = 0, locations = 1, resolved = 1, hit count = 66 3.1: where = godot`VisualServerCanvas::render_canvas(VisualServerCanvas::Canvas*, Transform2D const&, RasterizerCanvas::Light*, RasterizerCanvas::Light*, Rect2 const&, int) + 87 at visual_server_canvas.cpp:229:2, address = 0x0000000102f73957, resolved, hit count = 66 4: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 1417, exact_match = 0, locations = 1, resolved = 1, hit count = 99 4.1: where = godot`RasterizerCanvasGLES3::canvas_render_items(RasterizerCanvas::Item*, int, Color const&, RasterizerCanvas::Light*, Transform2D const&) + 45 at rasterizer_canvas_gles3.cpp:1419:8, address = 0x0000000100f66e8d, resolved, hit count = 99 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 5: file = 'src/drivers/gles3/rasterizer_canvas_gles3.cpp', line = 551, exact_match = 0, locations = 1, resolved = 1, hit count = 4672 5.1: where = godot`RasterizerCanvasGLES3::_draw_gui_primitive(int, Vector2 const*, Color const*, Vector2 const*) + 66 at rasterizer_canvas_gles3.cpp:557:6, address = 0x0000000100f66a52, resolved, hit count = 4672 ```

lawnjelly commented 4 years ago

I'm used to profilers giving a call count as part of the data, maybe the method the mac profiler uses is making this difficult.

Those types of numbers should be no problem, it should be doing e.g. those types of numbers no problem in a second, rather than 2 mins! The profiler can slow things down, so this could be anomalous results given that it seems the bottleneck seems not to be in Godot CPU code. So we may not be getting a true picture of the ratio of calls without the slowdown from the profiler.

Having said all that I can't see anything immediately obvious as being problematic godot CPU side, so it does look this is something we are doing that either the driver or GPU doesn't like.

Have you guys tried all this in GLES2 with batching? Do you get the same slowdown?

As I have mentioned in the other thread, the way I would probably investigate this is as follows:

1) Start with an empty project 2) Gradually add features (sprites, animated textures etc) one by one until you find a particular thing that is causing a dramatic slowdown

If it is animated textures particularly, it could be doing something like reading the texture back from the GPU, however no one has been able to provide information as to whether it is a particular thing that is causing it (or if it doesn't occur with only using certain features), so there is not much to go on. Of course it could be just using reference rasterizer in which case everything would be slow and the CPU would be maxed out in the driver I guess.

Also noteworthy is that the driver isn't appearing in the profile at all. It would be nice to know whether it appears (maybe off the screen towards the bottom) and that will confirm it's not bottlenecked by CPU driver stuff (although it could still be e.g. waiting for info back from GPU).

It could also be some high level thing in terms of the frame buffers that this platform doesn't like. Which would be incredibly difficult to debug remotely.

naithar commented 4 years ago

Well, I have the same slowdown with CPUParticle with both GLES3 and GLES2 (but I'm not sure about batching) on macOS, but device (iOS) runs just fine. So I guess it's not animated texture only issue.

I'll make more test and profiling once I'm able, hopefully it'll give more useful info.

setanarut commented 3 years ago

on macbook pro 2016 15" with AMD Radeon Pro 455

GPU goes to 100% when dragged with Space(hand tool) while ruler or grid view is on in 2D viewport. When launch Godot on with the option "Open in Low Resolution" the GPU usage becomes less. If it is not selected, Retina display and Editor window animations in large resolutions cause excessive GPU usage.(scrolling large text, animation player etc.)

When I use the online editor on this site macOS switches to Integrated Intel HD Graphics 530 and GPU usage is low and normal (hidpi retina).

Test with gfxCardStatus

Godot.app ;

Intel HD Graphics 530 ->low FPS + normal GPU usage
AMD Radeon Pro 455 -> normal FPS+ high GPU usage

https://godotengine.org/online/godot.tools.html ;
Intel HD Graphics 530 -> normal FPS + normal GPU usage
AMD Radeon Pro 455 -> normal FPS + normal GPU usage

lawnjelly commented 3 years ago

Does the performance get dramatically better when you resize the editor window to very small? If so it would indicate a fill rate type issue rather than something to do with drawcalls.

A lot of the problems seem to be associated with this high DPI stuff and the use of a 2nd GPU. I know there have been a lot of problems in general with there being 2 GPUs available on other platforms, maybe this is causing a problem on Mac too. This would be to do with the OS specific and setup code rather than the renderer backends.

setanarut commented 3 years ago

Does the performance get dramatically better when you resize the editor window to very small? @lawnjelly

No, window size and resolution make little difference. The problem is not window resolution.

My observation. GPU is 100% only in the following cases.

2D ruler lines, grid lines. (when dragging with hand tool)
2D Animations within the editor (I haven't tried 3D animation)
Scrolling through the big help pages
The animated "Visible Collision Shapes" during the 2D game

vaner-org commented 3 years ago

My observation. GPU is 100% only in the following cases.

2D ruler lines, grid lines. (when dragging with hand tool)

2D Animations within the editor (I haven't tried 3D animation)

Scrolling through the big help pages

The animated "Visible Collision Shapes" during the 2D game

@hazarek Do you experience the same performance penalty if you start an empty project with GLES3, and enable in Preferences > General > Interface > Editor > "Update editor continuously"?

Does the performance get dramatically better when you resize the editor window to very small? If so it would indicate a fill rate type issue rather than something to do with drawcalls.

Doing this doesn't improve performance for me either, unfortunately.

After what Calinou said I've grown to understand that GPU at 100% for hiDPI 60fps is somewhat expected, since Blender would do the same at with an animation running, however, in Godot, setting Low Resolution mode in the editor viewport doesn't lower the GPU load for the discrete card (still at 100%) and the CPU temperature is always climbing. The GPU stays at an even 65º with an animation playing (which makes me think I had misattributed the problem initially), but the the CPU heat will steadily climb for a few minutes, up to 80 or 90 sometimes (if focus stays on Godot), until the system throttles.

setanarut commented 3 years ago

@hazarek Do you experience the same performance penalty if you start an empty project with GLES3, and enable in Preferences > General > Interface > Editor > "Update editor continuously"? @molevision

yes GPU always 100% if "Update editor continuously" is on.(GLES3, GLES2 doesn't matter.) Same problem after Blender 2.8.

edit; I installed windows 10 on Macbook Pro 2016 with bootcamp, the GPU usage is very low and there is an incredible difference. Smooth even at high window sizes. The jitter and stutter problems has also disappeared.

chryswoods commented 3 years ago

Maybe related, but after upgrading to Catalina I also found that the editor and my game on my MacBook started stuttering a lot and juddered. Frame rate went down from a comfortable 60fps to juddering between 10-30 fps. And using the editor was difficult (the text editor couldn't even keep up with my typing). After playing with the various project options I found that I could restore expected behaviour by disabling the "Use Nvidia Rect Flicker Workaround". I disabled this, restarted the editor, and then everything returned to 60fps and the editor was smooth again. I verified this was the cause of the problem by re-enabling the workaround, restarting Godot, and then seeing that the low fps and juddering returned. (note that I needed to close and restart Godot to have this change in option take effect)

So, at least for me, having "Use Nvidia Rect Flicker Workaround" enabled causes the editor to lag, fps to drop to 10-30fps and everything judders.

Godot version:

3.2.3.stable.official

OS/device including version:

OS: macOS Catalina 10.15.7 Hardware: Macbook 2016 1.2 GHz + Intel HD Graphics 515 1536 MB + 8 GB RAM

lawnjelly commented 3 years ago

Is this in GLES2 or GLES3? This might point to vertex buffer orphaning being a problem in the driver, one of the suspects.

Calinou commented 3 years ago

For the record, the NVIDIA rect flicker workaround is known to have a significant performance cost. Only enable it if you actually need it.

lawnjelly commented 3 years ago

For the record, the NVIDIA rect flicker workaround is known to have a significant performance cost. Only enable it if you actually need it.

On the other hand, reusing vertex buffers per frame is used throughout Godot backends, so we have to make sure the method plays nice with the driver. It is used in basically all non-rect primitives, and in the batching. Which might explain why people were seeing slowdowns when the ruler showed, giving a lot of separate orphaning drawcalls.

It could be almost as simple as not setting GLES_OVER_GL on Mac. But without having Macs we can't test the various permutations easily.

I'll see if I can figure out how to make a Mac build with github actions. I could add a temporary project setting to vary the orphaning technique used and see if we can find a solution, if orphaning is the problem.

chryswoods commented 3 years ago

Both, but much worse using GLES3. I'm new to godot and enabled it by mistake when exploring the various options (although surprised that a workaround for nvidia issues would not be automatically disabled on intel gpus). I'm working on game logic, not graphics now, so all that is being rendered are a few Polygon2Ds, hence why the slow frame rate was a surprise. Also saw this problem on a new 2020 MacBook Air, and double checked CPU usage etc on both machines and saw it was <10%. Saw occasional 100% peaks in gpu usage, although not correlated with the judders.

Happy to run some tests on my Mac if there's anything you want to send over. I suspect that you're right.

lawnjelly commented 3 years ago

Ok I have no idea whether this build for mac will work, new territory for me, but I copied most of the github action from the main godot repository to make this.

I would appreciate it if someone with the problem can try this out. At the moment this applies to GLES3 only, so make sure you test it using GLES3.

You should also set project_settings->rendering->quality->use_nvidia_rect_flicker_workaround to true as this appears to cause the slowness problem to appear. You should do this irrespective of whether your gpu is nvidia: it is used to select a different drawing method.

See this comment for an explanation of why you should use the nvidia_workaround: https://github.com/godotengine/godot/issues/39758#issuecomment-706562398

The setting is in: project_settings->rendering->quality->2d->orphan_method

The available options are:

Default
None
Fresh_Buffer

Let me know the relative performance of each method. You will need to restart after changing (for it to take effect in the editor). If will also affect projects you run from the editor, but not exported projects (that requires a template).

https://github.com/lawnjelly/Misc/releases/tag/orph_v0.10

(out of interest the branch for the source code is here: https://github.com/lawnjelly/godot/tree/mac_orphan)

setanarut commented 3 years ago

I would appreciate it if someone with the problem can try this out. At the moment this applies to GLES3 only, so make sure you test it using GLES3. You should also set 'project_settings->rendering->quality->use_nvidia_rect_flicker_workaround' to true as this appears to cause the slowness problem to appear. @lawnjelly

There is confusion about this. Some people say it has slowdown problem, Some say high CPU, Some say high GPU.

My status; I don't have an Nvidia card, no slowdown issue. There is 100% AMD GPU usage. CPU usage is normal values. GLES2 GLES3 does not matter.

Should I try what lawnjelly shared?

lawnjelly commented 3 years ago

There is confusion about this. Some people say it has slowdown problem, Some say high CPU, Some say high GPU.

My status; I don't have an Nvidia card, no slowdown issue. There is 100% AMD GPU usage. CPU usage is normal values. GLES2 GLES3 does not matter.

Should I try what lawnjelly shared?

Ignore nvidia in the name, that is irrelevant. If you are using a mac, and you have slow performance in the editor, then yes try it out, and let me know the results - even if there is no change between settings this is useful info. Be sure to follow the instructions.

chryswoods commented 3 years ago

Thanks - here's the results

use_nvidia_rect_flicker_workaround	orphan_method	editor feel	speed (fps)
yes	None	very laggy	10-15 fps, crash with "opcode 38, report please"
yes	Fresh_buffer	smooth	60 fps, crash with "opcode 38..."
yes	Default	smooth	60 fps, crash with "opcode 38..."
no	None	smooth, but slightly slower	60 fps, crash with "opcode 38..."
no	Fresh_buffer	smooth	60 fps, crash with "opcode 38..."
no	Default	smooth	60 fps, crash with "opcode 38..."

Using Godot 3.2.3.stable.official with use_nvidia_rect_flicker_workaround "no" I get 60fps and no crash, but the editor feels slightly slower (almost same as "No", "None" in the above table). The editor with "yes", "Fresh_buffer" or "yes", "default" feels very smooth - scrolling is silky compared to a bit janky for 3.2.3.stable.official. Your fix definitely works, except for the "opcode 38" crash I now see... (which could be poor programming on my part).

chryswoods commented 3 years ago

Ok - I've fixed the crashes, although this has pointed to a new issue in Godot. The error was in the lines (pseudo-code)

func set_parameters(params):
    _params = params as BaseParamsClass

and it was crashing when I passed params as a DerivedParamsClass. Changing to;

func set_parameters(params):
    _params = params

removed the error and things worked again. I checked with the debugger and prints(params.get_class()) that an object of DerivedParamsClass was indeed passed. The Godot error was;

E 0:00:01.637   call: Condition ' !base_type ' is true. Breaking..:
  <C++ Source>  modules/gdscript/gdscript_function.cpp:938 @ call()

So, your fix works - the editor is silky smooth, rendering is quick and I need to double check or remove some of my type hinting ;-)

chryswoods commented 3 years ago

Here's what I mean by a janky scrolling editor - https://youtu.be/CwZHryv9Cm0 And here is the very smooth scrolling for lawnjelly's fixed version - much better - https://youtu.be/rAxV5pWmZmY

setanarut commented 3 years ago

@lawnjelly Animations do not use 100% GPU, much better than before.

godot_orphan_test_010_mac64

use_nvidia_rect_flicker_workaround : I could not see the difference. Default- Approximately between 15-35% AMD GPU usage with animated content None - Always 100% AMD GPU Fresh_Buffer - Approximately between 15-35% AMD GPU usage with animated content

GPU always 100% if "Update editor continuously" is on. The settings above do not matter.

Edit: Some Animations not all

lawnjelly commented 3 years ago

Fantastic. :partying_face: :grinning:

I didn't say in advance, because I didn't want to bias the results, but none is the current state in the Mac build I believe (because GLES_OVER_GL is defined). I'll either integrate this in unified batching or a separate PR, we should be able to get this in for 3.2.4. :+1:

akien-mga commented 3 years ago

Fixed by #42734.

setanarut commented 3 years ago

@akien-mga This issue has little improved, but in most cases there is still 100% usage. the issue should not be closed.

vaner-org commented 3 years ago

Unfortunately I agree with @hazarek, can't see a difference on my machine when I build from source.

setanarut commented 3 years ago

Unfortunately I agree with @hazarek, can't see a difference on my machine when I build from source.

@molevision Can you share the binary file or App? I will test it. I found a workaround for AMD macbook.

for godot_orphan_test_010_mac64

Godot.app > Get info > "Open in low Resolution" = ON
Godot Project and Editor settings;

display/window/vsync/use_vsync = true
quality/2d/use_nvidia_rect_flicker_workaround=true
project_settings->rendering->quality->2d->orphan_method = default
settings/fps/force_fps=60

result with animated content;

vaner-org commented 3 years ago

@hazarek Sorry for the time I took to respond, but I haven't compiled a single one that shows me the orphan_method setting in Godot, not even when using lawnjelly's build.

Everything seems largely unchanged for me running the newer builds, still at 100% GPU with a steadily heating CPU (that's under more load than it would be in Blender) under reasonable operating conditions. I also agree with all the findings in #42849, and am grateful for the progress lawnjelly continues to make.

If I may, really: @Chaosus's #31070 should be salvaged ASAP, even if its visibility is optional (like the update spinner). There's no telling how long it could take to completely squish this bug and a lot of our editor workflows are broken by animated content. The pause button in 3.2.4 would (at least) be a stopgap and allow me to resume working regularly in Godot.

Calinou commented 3 years ago

@molevision Done here: https://github.com/godotengine/godot/pull/43011

johnfn commented 3 years ago

Just investigated a similar issue in my project, and found some interesting things. Same issue - super high CPU/GPU usage when Godot was entirely idle. At first I thought like you guys did that the AnimatedSprite was the issue. However, what I eventually tracked it down to was a shader, updating every tick, that we were applying across a huge number (100+) of our sprites. Turned off the shader in the editor only and BOOM, CPU usage back down to single digits!!

The super strange thing here is that running the game does not eat CPU at all. Running the game with an equivalent amount of sprites visible in the viewport with the shader turned on only eats about 10% CPU. It's only in the editor that the CPU spikes to 100% and sits there. This leads me to suspect that this is a genuine bug in the Godot editor rather than some sort of pathologic 60FPS rendering issue.

Let me know if I should report this as a separate issue or something. It looks pretty ugly to see Godot run so slowly (especially since it's generally just a snappy editor) but I'm really happy that the solution ended up being trivial, if obscure.

lawnjelly commented 3 years ago

Let me know if I should report this as a separate issue or something.

Separate issue I think, with full details of platform, OS, the shader etc.

godotengine / godot