Java - Mi eszi a memóriát?

Java

Van egy szerverem. Java 11-re nemrég tértünk át, és az egyik szerver megbokrosodott.

Eddig beérte max. 5-6G memóriával, most hirtelenjében annyit eszik amennyit csak tud.

Ha készítek belőle memory dumpot, pl. egy 23G-ás RES memória foglalásról, akkor a profiler azt mondja, hogy az élő objektumok mérete 1G alatti. Mi a fene lehet a másik 22G?

Ötletek?

UPDATE:
A heap memórián az élő objektumok 900 mega körül vannak. Ezen kívül van még 22 (most már ~30) giga valami még.
Azaz mivel lehetne kideríteni, hogy mi az ami a heap-on kívül eszi a memóriát? 

  • 1404 megtekintés

( bAndie9100 | 2020. 06. 18., cs – 15:23 )

nem értek a JVM-hez de linux szintjén milyen memóriáról van szó? file cache, anon page?

( yoursoft | 2020. 06. 18., cs – 15:27 )

Linux szinten használt memóriáról van szó azaz resource memória, azaz a topban pl. itt látod: RES.

( XYBeR | 2020. 06. 18., cs – 15:29 )

hotspot vagy j9? a jvm-váltáson túl a kódhoz is hozzányúltatok? a dependenciák változtak?

Köszönöm, de ez elég hosszadalmas lenne. Hiszen át kellene nézni a WildFly változásokat, a dependency változásokat (melyik lehet hibás?), kódban is rengeteg volt, meg még a Java-nak is lehet gondja.

Nem a heap ami önmagában eszik, hanem valami a heapen kívül növekszik. Ha azt lehetne valahogy megállapítani, hogy mi a heap-en kívül a tartalma a memóriának, az sokat segíthetne.

Mekkora heap-et adtál amúgy a JVM-nek? Ha azon bőven túlterjeszkedik, akkor a JVM a probléma általában (és/vagy Unsafe interfészen át való off-heap memóriafoglalás), azt hiába nézed Java profiler-el, nem fogod látni a hibát.

Próbálj ezzel indítani: `-XX:NativeMemoryTracking=[summary | detail]`

https://iotguru.cloud

Köszönöm. Ezt kipróbáltam.

-Xmx16g van adva. Ennél jóval túllóg. Most olyan 32g a RES.

Úgy látom a class metadata környékén van gond:

-                     Class (reserved=1704851KB +6423KB, committed=738579KB +6679KB)
                            (classes #100205 +7)
                            (  instance classes #96335 +7, array classes #3870)

Bár még nem értem miért.

Ez most egy teszt szerver. Nem az éles. Ezen igyekszem valahogy kitalálni, hogy melyik alkalmazás okozza.

Itt még csak 5.1G a foglalás a RES-ből.

Native Memory Tracking:

Total: reserved=7118401KB, committed=5245917KB
-                 Java Heap (reserved=4194304KB, committed=3751936KB)
                            (mmap: reserved=4194304KB, committed=3751936KB) 
 
-                     Class (reserved=1742922KB, committed=777418KB)
                            (classes #101400)
                            (  instance classes #97503, array classes #3897)
                            (malloc=176202KB #921400) 
                            (mmap: reserved=1566720KB, committed=601216KB) 
                            (  Metadata:   )
                            (    reserved=526336KB, committed=526080KB)
                            (    used=509482KB)
                            (    free=16599KB)
                            (    waste=0KB =0,00%)
                            (  Class space:)
                            (    reserved=1040384KB, committed=75136KB)
                            (    used=67112KB)
                            (    free=8024KB)
                            (    waste=0KB =0,00%)
 
-                    Thread (reserved=371756KB, committed=41728KB)
                            (thread #359)
                            (stack: reserved=370040KB, committed=40012KB)
                            (malloc=1295KB #2156) 
                            (arena=421KB #716)
 
-                      Code (reserved=258469KB, committed=140301KB)
                            (malloc=10781KB #42209) 
                            (mmap: reserved=247688KB, committed=129520KB) 
 
-                        GC (reserved=282620KB, committed=266204KB)
                            (malloc=93656KB #530452) 
                            (mmap: reserved=188964KB, committed=172548KB) 
 
-                  Compiler (reserved=3034KB, committed=3034KB)
                            (malloc=2903KB #6458) 
                            (arena=131KB #5)
 
-                  Internal (reserved=7996KB, committed=7996KB)
                            (malloc=7964KB #8143) 
                            (mmap: reserved=32KB, committed=32KB) 
 
-                     Other (reserved=753KB, committed=753KB)
                            (malloc=753KB #94) 
 
-                    Symbol (reserved=72198KB, committed=72198KB)
                            (malloc=69441KB #963671) 
                            (arena=2757KB #1)
 
-    Native Memory Tracking (reserved=47650KB, committed=47650KB)
                            (malloc=856KB #12046) 
                            (tracking overhead=46794KB)
 
-               Arena Chunk (reserved=188KB, committed=188KB)
                            (malloc=188KB) 
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #189) 
 
-                 Arguments (reserved=19KB, committed=19KB)
                            (malloc=19KB #500) 
 
-                    Module (reserved=121607KB, committed=121607KB)
                            (malloc=121607KB #379968) 
 
-              Synchronizer (reserved=14871KB, committed=14871KB)
                            (malloc=14871KB #126731) 
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

Az élest csak holnap tudom intézni.

Most sikerült meghajtanom a teszt szervert és felment 5.5 gigára a mem használat.

Az újabb summary:
 

Native Memory Tracking:

Total: reserved=7455641KB, committed=5593845KB
-                 Java Heap (reserved=4194304KB, committed=3751936KB)
                            (mmap: reserved=4194304KB, committed=3751936KB) 
 
-                     Class (reserved=1912286KB, committed=948318KB)
                            (classes #103374)
                            (  instance classes #99410, array classes #3964)
                            (malloc=335326KB #1515989) 
                            (mmap: reserved=1576960KB, committed=612992KB) 
                            (  Metadata:   )
                            (    reserved=536576KB, committed=536320KB)
                            (    used=519398KB)
                            (    free=16922KB)
                            (    waste=0KB =0,00%)
                            (  Class space:)
                            (    reserved=1040384KB, committed=76672KB)
                            (    used=68336KB)
                            (    free=8336KB)
                            (    waste=0KB =0,00%)
 
-                    Thread (reserved=374855KB, committed=41979KB)
                            (thread #362)
                            (stack: reserved=373124KB, committed=40248KB)
                            (malloc=1306KB #2174) 
                            (arena=424KB #722)
 
-                      Code (reserved=259541KB, committed=153373KB)
                            (malloc=11853KB #46111) 
                            (mmap: reserved=247688KB, committed=141520KB) 
 
-                        GC (reserved=285002KB, committed=268586KB)
                            (malloc=96038KB #541380) 
                            (mmap: reserved=188964KB, committed=172548KB) 
 
-                  Compiler (reserved=3223KB, committed=3223KB)
                            (malloc=3092KB #6631) 
                            (arena=131KB #5)
 
-                  Internal (reserved=8033KB, committed=8033KB)
                            (malloc=8001KB #8165) 
                            (mmap: reserved=32KB, committed=32KB) 
 
-                     Other (reserved=774KB, committed=774KB)
                            (malloc=774KB #100) 
 
-                    Symbol (reserved=86037KB, committed=86037KB)
                            (malloc=83280KB #1085370) 
                            (arena=2757KB #1)
 
-    Native Memory Tracking (reserved=66408KB, committed=66408KB)
                            (malloc=887KB #12486) 
                            (tracking overhead=65521KB)
 
-               Arena Chunk (reserved=188KB, committed=188KB)
                            (malloc=188KB) 
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #189) 
 
-                 Arguments (reserved=19KB, committed=19KB)
                            (malloc=19KB #500) 
 
-                    Module (reserved=236399KB, committed=236399KB)
                            (malloc=236399KB #729867) 
 
-              Synchronizer (reserved=28561KB, committed=28561KB)
                            (malloc=28561KB #243556) 
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

DIFF:
 

Native Memory Tracking:

Total: reserved=7894970KB +766522KB, committed=6034938KB +777670KB

-                 Java Heap (reserved=4194304KB, committed=3751936KB)
                            (mmap: reserved=4194304KB, committed=3751936KB)
 
-                     Class (reserved=2130688KB +382221KB, committed=1165312KB +382093KB)
                            (classes #103424 +1981)
                            (  instance classes #99460 +1919, array classes #3964 +62)
                            (malloc=551680KB +369933KB #2313022 +1371050)
                            (mmap: reserved=1579008KB +12288KB, committed=613632KB +12160KB)
                            (  Metadata:   )
                            (    reserved=538624KB +12288KB, committed=536832KB +10496KB)
                            (    used=519919KB +10187KB)
                            (    free=16913KB +309KB)
                            (    waste=0KB =0,00%)
                            (  Class space:)
                            (    reserved=1040384KB, committed=76800KB +1664KB)
                            (    used=68363KB +1225KB)
                            (    free=8437KB +439KB)
                            (    waste=0KB =0,00%)
 
-                    Thread (reserved=373822KB +3098KB, committed=41994KB +314KB)
                            (thread #361 +3)
                            (stack: reserved=372096KB +3084KB, committed=40268KB +300KB)
                            (malloc=1303KB +11KB #2168 +18)
                            (arena=423KB +4 #720 +6)
 
-                      Code (reserved=259674KB +1184KB, committed=155630KB +15244KB)
                            (malloc=11986KB +1184KB #46427 +4173)
                            (mmap: reserved=247688KB, committed=143644KB +14060KB)
 
-                        GC (reserved=287665KB +4977KB, committed=271249KB +4977KB)
                            (malloc=98701KB +4977KB #546342 +15702)
                            (mmap: reserved=188964KB, committed=172548KB)
 
-                  Compiler (reserved=3281KB +247KB, committed=3281KB +247KB)
                            (malloc=3151KB +247KB #6654 +190)
                            (arena=131KB #5)
 
-                  Internal (reserved=8193KB +198KB, committed=8193KB +198KB)
                            (malloc=8161KB +198KB #8171 +30)
                            (mmap: reserved=32KB, committed=32KB)
 
-                     Other (reserved=784KB +24KB, committed=784KB +24KB)
                            (malloc=784KB +24KB #107 +10)
 
-                    Symbol (reserved=104687KB +31987KB, committed=104687KB +31987KB)
                            (malloc=101930KB +31987KB #1245244 +276918)
                            (arena=2757KB #1)
 
-    Native Memory Tracking (reserved=91402KB +43311KB, committed=91402KB +43311KB)
                            (malloc=898KB +217KB #12646 +3023)
                            (tracking overhead=90504KB +43094KB)
 
-               Arena Chunk (reserved=188KB, committed=188KB)
                            (malloc=188KB)
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #189)
 
-                 Arguments (reserved=19KB, committed=19KB)
                            (malloc=19KB #500)
 
-                    Module (reserved=393043KB +267414KB, committed=393043KB +267414KB)
                            (malloc=393043KB +267414KB #1207257 +815034)
 
-              Synchronizer (reserved=47209KB +31860KB, committed=47209KB +31860KB)
                            (malloc=47209KB +31860KB #402684 +271870)
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

De ebből még mindig nem derült ki számomra, hogy hol keressem az okot.
A class terület nőtt meg, a heap nem mozdult. Szinte mindenki nőtt valamennyit.

Köszönöm az eddigi segítségeteket.

2 további tapasztalat:

1. Ami viszont előjött, ha be van kapcsolva ez a -XX:NativeMemoryTracking akkor jobban eszi a memóriát. Így mos éppen az ellen-teszt megy. Azaz ennek a bekapcsolása nélkül igyekszem növelni a memórahasználatot. Egyelőre nem sikerült. :-(

2. Közben megnéztem az Eclipse mat-al és a YourKit-el is a memory dumpot. Az Mat-al az jött ki, hogy van 900m live object és van ~4.1G kitakarítandó objektum a heap-en.

- Ha csak a live memóriát nézem: 11 instances of "org.hibernate.internal.SessionFactoryImpl", loaded by "org.jboss.modules.ModuleClassLoader @ 0x7ef572f327d0" occupy 0,24 GB (27,56%) bytes.
- Ha a teljes heap-ot nézem, akkor a (azokat is figyelembe veszem, amiket a GC még nem takarított ki): 3 380 968 instances of "org.jboss.as.security.plugins.ModuleClassLoaderLocator$CombinedClassLoader", loaded by "org.jboss.modules.ModuleClassLoader @ 0x7ef571ea34c8" occupy 4,21 GB (56,06%) bytes.

Ez is elég furcsa viselkedés. Vagy nem G1-nél? Itt már nem tudom mekkora xmx volt megadva.

Esetleg érdemes lenne egy memória analizálást is csinálni, hátha a kódban is változott valami, vagy előjött egy olyan eset, amivel eddig nem foglalkoztatok.

Ha van heap dump (esetleg több is, az még jobb) akkor ezzel az ingyenes tool-lal meg tudjátok nézni, hogy mi is a helyzet:

 

https://www.eclipse.org/mat/

( KGer | 2020. 06. 18., cs – 15:34 )

hmap kilistázza milyen class-ból hány db van a memóriában és mennyit foglal

( _Franko_ v | 2020. 06. 18., cs – 16:59 )

Eszi is a memóriát vagy csak úgy gondolod, hogy eszi? Van ebből a fajta szerverből még és azok nem csinálják, vagy egyedi szerver és/vagy egyedi konfigurációval?

https://iotguru.cloud

Köszönöm.

Eszi. Amikor kezdte elérni a fizikai memória határát, egyre lassabb is lett. Annyira lassú, hogy kénytelenek voltunk újraindítani.

Van több szerverünk is. De ebből 2-ő van, mindkettő ugyanazt produkálja.
A többi más alkalmazásainkkal futó szerveren is látunk hasonlót, de ott jóval lassabban eszi a memóriát. Napi 300-400-600 mega fogy a többi szerveren. De még bőven kereten belül vannak.
Ez meg 1 nap alatt feleszik 20G-át. 

Az jo, akkor legalabb reprodukalhato.

java.nio kornyeken nezz korul, abban vannak bufferek, amik off-heap memoryt foglalnak. Valszleg valahol nem lesznek lezarva (vagy application code vagy wildfly code).

https://dzone.com/articles/troubleshooting-problems-with-native-off-hea…

https://dzone.com/articles/understanding-java-buffer-pool

Amugy lepjel vissza 1-2 wildfly verziot, ha lehetseges, hatha segit. Meg ugy altalaban is ajanlatos semmit nem hasznalni a wildfly-bol, ami nem public api module. Inkabb csomagold be a deploymentedbe a neked kello libet, es akkor nem fogsz szivni uj wildfly eseten.

( uid_18247 | 2020. 06. 18., cs – 22:25 )

a /proc alatt a megfelelő PID-nèl mi látható? érdemes lenne megmutatni a jól működőt is.

maps, numa_maps, smaps (vagy smaps_rollup), status -> lehet, hogy ezekkel egy lépéssel sem kerülsz közelebb. talán segítenek, talán nem. mondanám, hogy próbálj egy strace-t az érintett PID-re, de ugyanaz a gond, vagy fog segíteni, vagy nem (de inkább nem). coredumpod van?

Köszönöm. Egyedül a status fájlhoz volt jogom:

Ebből ami érdekes lehet:

VmLck:         0 kB
VmPin:         0 kB
VmHWM:  11907748 kB
VmRSS:  11897448 kB
RssAnon:        11873172 kB
RssFile:           24276 kB
RssShmem:              0 kB
VmData: 23113716 kB
VmStk:       132 kB
VmExe:         4 kB
VmLib:     26560 kB
VmPTE:     23872 kB
VmSwap:        0 kB
Threads:        171

( golgota | 2020. 06. 19., p – 08:55 )

Szerkesztve: 2020. 06. 19., p – 08:57

Ez a folyamatosan novekvo memoria hasznalat a JVM heap-en kivul eleg erost memoryleak-re utal. Az nem lenne baj, ha megenne az osszes memoriat, hiszen ez a dolga, csak kozben tisztitani is kellen (amennyiben a linux virtual memory-ban az adott page-ek felszabadithatoak lennenek, de ezek szerint nem lesznek azok).

Nem nagyon vagom a java-t en sem, de nalunk akkor szoktak belassulni a java alkalmazasok amikor a GC tul hosszu ideig, tul sokat kell takaritson. Mondjuk akkor a cpu usage is az egekben szokott lenni. De ha jol tudom a GC csak a jvm heap-et takaritja nem? Mondom nem ertek hozza.

En pmap-al is megneznem periodikusan a process virtual memory hasznalatat, hogy lassam hol novekszik a mi. Aztan ott a /proc/PID/smaps idonkenti leszedese es diffe-lgetese. Aztan vannak az inygenes tool-ok mtrace es tarsai. Tuti van valami a java-ra is.

na talaltam valamit: 

https://dzone.com/articles/finding-java-memory-leaks-from-a-heap-dump

( STP | 2020. 06. 19., p – 11:11 )

Egyáltalán milyen funkciója van az APP-nak?

( KGer | 2020. 06. 19., p – 12:33 )

nincs benne vhol jni ami elkezdett leak-lni?

+1

Ha A directmemory kimutatásokban nem szerepel, akkor JNI leakelhet. Az ilyet a legnehezebb megfogni, ha ez bárkit megnyugtat :-).

Ha Java DirectMemory leakel, akkor az a Heap Dumpban látható lehet: A DirectByteBuffer típusú objektumok szaporodnak. (Vagy valami nio osztály, ha esetleg azok is foglalnak ilyen memóriát.) Ezt meg lehet a Heap Dump alapján találni.

Ha a natívak leakelnek, azt már nehezebb megtalálni.

( talisker | 2020. 06. 19., p – 13:13 )

subscribe.

Talisker Single Malt Scotch Whisky aged 10 years - o.k. Yamazaki is playing as well :)

( KGer | 2020. 06. 20., szo – 15:47 )

ha kidumpolod a 22 giga memót és nyomsz rá egy strings parancsot, lehet hogy ezerszer ismétlődni fog vmi nyom, akár jdbc driver, akár bármi más

( gabrielakos v | 2020. 06. 22., h – 08:37 )

Nem nagyon hiszem hogy a 16g heap valid igény lenne, érdemes lenne sokkal kisebbel próbálkozni.

Akkor hamarabb elkezd aktívkodni a gc, kisebbek, kezelhetőbbek a dumpok.

Ha non-heap probléma van annak az arányai is jobban látszanak, hamarabb tolódik arra a memória igény.

zászló, zászló, szív

( yoursoft | 2020. 06. 26., p – 15:08 )

Egyelőre úgy tűnik JVM hibába futottunk. Egy új 11-es java telepítése ígéretesnek tűnik.

Köszi! Mi is utazunk Javában, és nem árt hallani ezekről. Jól értem, hogy az ilyen dinamikusan osztályokat generáló-betöltő-majd kidobó könyvtárakkal jön csak elő ez az issue?

Az is kiderült, hogy melyik könyvtár csinál ilyen nagytömegű osztálybetöltést, és mi célból?

( Nickname | 2020. 07. 07., k – 07:44 )

Odassatok! :)

 

JEP 387: Elastic Metaspace

 

Return unused HotSpot class-metadata (i.e., metaspace) memory to the operating system more promptly, reduce metaspace footprint, and simplify the metaspace code in order to reduce maintenance costs.

 

http://openjdk.java.net/jeps/387