Bug 111288

Created attachment 144935 [details]
glxinfo

Hi Greg, could you please re-upload apitrace somewhere instead of BZ? Looks like it is too big and can't be opened. (google drive or any other file-sharing system will be ok I think).

Ok, here it is https://drive.google.com/file/d/1D3GNUW-DTaxI7hFEZmoEnucRQOrzNBAR/view?usp=sharing
That's fresh trace (i've lost old one), way smaller this time. Apitrace leaks doesn't find much, yet by the end of trace there were 115 `/dev/dri/renderD128` regions in process memory.

Created attachment 144957 [details]
terminal output of `apitrace replay mine.trace`

Also not sure if it's important, but when replaying this trace I get lots of messages in log (from driver I guess).

Mentioned memory regions can also be seen when replaying the trace, accumulating up to 116.

Thanks for the trace and explanations. I installed minecraft (demo version). First observation - is that the app versions available for me 1.14.4 and 1.14

I ran it thru the valgrind. Result below:

==9226== LEAK SUMMARY:
==9226==    definitely lost: 672 bytes in 6 blocks
==9226==    indirectly lost: 9,878,823 bytes in 1,984 blocks
==9226==      possibly lost: 6,480,869 bytes in 26,861 blocks
==9226==    still reachable: 7,899,321 bytes in 62,276 blocks
==9226==                       of which reachable via heuristic:
==9226==                         length64           : 1,384 bytes in 28 blocks
==9226==                         newarray           : 1,808 bytes in 33 blocks
==9226==                         multipleinheritance: 1,960 bytes in 10 blocks
==9226==         suppressed: 0 bytes in 0 blocks


According to it, during my game session there were lost about 10 MB of memory.

I made tests on:
Manjaro OS
kernel 5.1.16-1-MANJARO
mesa 19.1.2 (system)
gpu - Intel HD620

Also I am not sure how memory allocation should work during app launching (I mean, possibly that could be find that app requested memory in renderD128 and freed it only after app closing...). It would be useful for me to know, why did you decide that those records relate to memory leaks (my observation - after normal game launching there were about 30 records for "renderD128" were created. And they were not increased then)

upd - as I found out, these memleaks are for the Launcher, not the exact game. Trying to connect to java process with valgrind now

>why did you decide that those records relate to memory leaks
I've decided that there's memory leak since memory used by minecraft grows indefinitely and it's surely not how it should be (I played minecraft on other PCs and there were no such problems), and absurdly high amount of these records in process memory map seemed to be quite rational explanation of where that memory leak is.
As mentioned, short timespan captured on trace was enough to accumulate >100 of these records (and as I said these records don't get deleted until program termination (exiting to main menu doesn't help), so amount of these can easily grow until there's no memory left).

>First observation - is that the app versions available for me 1.14.4 and 1.14

I use older version (to play with specific mods), but issue also persists on newest (1.14.4) and oldest versions (1.0 release) available to me

>and absurdly high amount of these records in process memory map seemed to be quite rational explanation of where that memory leak is.
Got you, thanks.

>so amount of these can easily grow until there's no memory left

ok, I see your point. I ran the game for a all night, and in the morning observed memory usage - and it still used 2.3 GB of RAM memory (it is for about 20 hours in pause)
According to '/dev/dri/renderD128' records - they were increased up to 90. About memory allocated for them - most of them used 4-16 kb, not 1 MB. Only few of them used 400 Kb (1 or 2 records).

And the last thing - I tried to run java process using valgrind, it created some logs (useless as they don't have information about possible leaks now) but game still didn't start :( Possibly it should take more time... (it used 1.2 GB of RAM memory now, as the original game uses 2.3 GB)

>it is for about 20 hours in pause
As I said, it pauses leaking when you stay still; it only seems to leak when you move (supposedly when new chunks (map is split into 16x16x256 (256 in vertical dimension) areas (chunks), only those near the player are loaded (are rendered and processed). When player moves, some chunks get loaded and some get unloaded to keep only area close to player loaded) are loaded). Reliable way to trigger leak is moving in one direction for some time.

Can you please check trace I provided (replay it and monitor amount of `renderD128` records) (if leaks are 'replayed', then the problem is somewhere in jvm (i've noticed appearance of sigsegv signals that don't terminate program when I traced with ltrace), if not, then probably it's driver issue or something, and at least it'll be easier (than delving in decompiled minecraft) to locate troublesome chunk)

If you replace the trace with "valgrind --leak-check=full", valgrind's output should contain information about where how much memory is (possibly) leaked.

P.S. If the trace was compressed with e.g. xz, it might be small enough to be attached here.

>"valgrind --leak-check=full"
Valgrind doesn't do well with java. It detects over 10000194 errors in jvm *before minecraft even starts*, and makes it very slow, as Denis mentioned.

Replaying the trace doesn't involve Java.

(In reply to Michel Dänzer from comment #13)
> Replaying the trace doesn't involve Java.

There seems no leaks on program exit when replaying the trace. Maybe the issue here is that for some reason memory usage keeps increasing all the time, even though finally it all gets released (?)

--- 8< ---
Rendered 896 frames in 15.3518 secs, average of 58.3646 fps
==19330== 
==19330== HEAP SUMMARY:
==19330==     in use at exit: 0 bytes in 0 blocks
==19330==   total heap usage: 5,065 allocs, 5,065 frees, 2,423,144 bytes allocated
==19330== 
==19330== All heap blocks were freed -- no leaks are possible

>If you replace the trace with "valgrind --leak-check=full", valgrind's output should contain information about where how much memory is (possibly) leaked.

That's how I launched minecraft for tracing (it is HUGE command, I took it from the "real" process launched. Without valgrind it launches second instance with a game, without launching "minecraft launcher"). As I wrote, waited 20 hours without result.

valgrind --leak-check=full \
         --show-leak-kinds=all \
         --track-origins=yes \
         --verbose \
         --log-file=valgrind-out.txt \
         --suppressions=/home/den/Downloads/invalid_access.supp \
         /usr/lib/jvm/java-8-openjdk/jre/bin/java -Xss1M -Djava.library.path=/tmp/3024-a622-fa75-1bb1 -Dminecraft.launcher.brand=minecraft-launcher -Dminecraft.launcher.version=2.1.5965 -cp /home/den/.minecraft/libraries/com/mojang/patchy/1.1/patchy-1.1.jar:/home/den/.minecraft/libraries/oshi-project/oshi-core/1.1/oshi-core-1.1.jar:/home/den/.minecraft/libraries/net/java/dev/jna/jna/4.4.0/jna-4.4.0.jar:/home/den/.minecraft/libraries/net/java/dev/jna/platform/3.4.0/platform-3.4.0.jar:/home/den/.minecraft/libraries/com/ibm/icu/icu4j-core-mojang/51.2/icu4j-core-mojang-51.2.jar:/home/den/.minecraft/libraries/com/mojang/javabridge/1.0.22/javabridge-1.0.22.jar:/home/den/.minecraft/libraries/net/sf/jopt-simple/jopt-simple/5.0.3/jopt-simple-5.0.3.jar:/home/den/.minecraft/libraries/io/netty/netty-all/4.1.25.Final/netty-all-4.1.25.Final.jar:/home/den/.minecraft/libraries/com/google/guava/guava/21.0/guava-21.0.jar:/home/den/.minecraft/libraries/org/apache/commons/commons-lang3/3.5/commons-lang3-3.5.jar:/home/den/.minecraft/libraries/commons-io/commons-io/2.5/commons-io-2.5.jar:/home/den/.minecraft/libraries/commons-codec/commons-codec/1.10/commons-codec-1.10.jar:/home/den/.minecraft/libraries/net/java/jinput/jinput/2.0.5/jinput-2.0.5.jar:/home/den/.minecraft/libraries/net/java/jutils/jutils/1.0.0/jutils-1.0.0.jar:/home/den/.minecraft/libraries/com/mojang/brigadier/1.0.17/brigadier-1.0.17.jar:/home/den/.minecraft/libraries/com/mojang/datafixerupper/2.0.24/datafixerupper-2.0.24.jar:/home/den/.minecraft/libraries/com/google/code/gson/gson/2.8.0/gson-2.8.0.jar:/home/den/.minecraft/libraries/com/mojang/authlib/1.5.25/authlib-1.5.25.jar:/home/den/.minecraft/libraries/org/apache/commons/commons-compress/1.8.1/commons-compress-1.8.1.jar:/home/den/.minecraft/libraries/org/apache/httpcomponents/httpclient/4.3.3/httpclient-4.3.3.jar:/home/den/.minecraft/libraries/commons-logging/commons-logging/1.1.3/commons-logging-1.1.3.jar:/home/den/.minecraft/libraries/org/apache/httpcomponents/httpcore/4.3.2/httpcore-4.3.2.jar:/home/den/.minecraft/libraries/it/unimi/dsi/fastutil/8.2.1/fastutil-8.2.1.jar:/home/den/.minecraft/libraries/org/apache/logging/log4j/log4j-api/2.8.1/log4j-api-2.8.1.jar:/home/den/.minecraft/libraries/org/apache/logging/log4j/log4j-core/2.8.1/log4j-core-2.8.1.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl/3.2.2/lwjgl-3.2.2.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl-jemalloc/3.2.2/lwjgl-jemalloc-3.2.2.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl-openal/3.2.2/lwjgl-openal-3.2.2.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl-opengl/3.2.2/lwjgl-opengl-3.2.2.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl-glfw/3.2.2/lwjgl-glfw-3.2.2.jar:/home/den/.minecraft/libraries/org/lwjgl/lwjgl-stb/3.2.2/lwjgl-stb-3.2.2.jar:/home/den/.minecraft/libraries/com/mojang/text2speech/1.11.3/text2speech-1.11.3.jar:/home/den/.minecraft/versions/1.14.4/1.14.4.jar -Xmx2G -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -XX:G1NewSizePercent=20 -XX:G1ReservePercent=20 -XX:MaxGCPauseMillis=50 -XX:G1HeapRegionSize=32M -Dlog4j.configurationFile=/home/den/.minecraft/assets/log_configs/client-1.12.xml net.minecraft.client.main.Main --username Player --version 1.14.4 --gameDir /home/den/.minecraft --assetsDir /home/den/.minecraft/assets --assetIndex 1.14 --uuid 265e330a88c60b9ad41d57788ec45778 --accessToken fbaaa18c2da14c20b1211a28e69137c3 --userType legacy --versionType release --demo


>Valgrind doesn't do well with java. It detects over 10000194 errors in jvm *before minecraft even starts*, and makes it very slow, as Denis mentioned.

Confirming, I used to suppress some errors, because without this step it simply said "valgrind stopped. Fix your buggy program" :)

>Can you please check trace I provided (replay it and monitor amount of `renderD128` records) (if leaks are 'replayed', then the problem is somewhere in jvm (i've noticed appearance of sigsegv signals that don't terminate program when I traced with ltrace), if not, then probably it's driver issue or something, and at least it'll be easier (than delving in decompiled minecraft) to locate troublesome chunk)

Interesting. Yesterday, when I replayed trace, I saw about 15 records for '/dev/dri/renderD128' at .../maps

Today - no any records related to this device. Replayed trace about 5 times.

Mesa is migrating to gitlab for issue tracking:

https://gitlab.freedesktop.org/mesa/mesa/issues

Unfortunately the migration script chokes on this bug, apparently because the attachments are too large for it to handle. Please file this issue in gitlab if you're still seeing it.