Praktičan prikaz lociranja i optimizacije jednog curenja memorije — rešimo se zloglasnog OOM

Chenmo Wang Er1594 reči5 minuta

OutOfMemoryError, odnosno zloglasni OOM (curenje memorije), sigurno su mnogi kolege već iskusili; u poređenju sa uobičajenim poslovnim izuzecima, poput prekoračenja granica niza ili null pokazivača, problem OOM-a znatno je teže locirati i rešiti.

Ovaj tekst se oslanja na jedan raniji slučaj onlajn curenja memorije, prikazujući način lociranja i rešavanja problema; nadam se da će kolegama koje naiđu na sličan problem pružiti ideje i pomoć.

Problem analiziramo i rešavamo u četiri koraka: simptomi -> istraga -> lociranje -> rešavanje.

Curenje memorije i preliv memorije

U Javi postoje dve glavne vrste problema vezanih za memoriju: preliv memorije i curenje memorije.

Preliv memorije (Out Of Memory): kada se traži memorija, JVM nema dovoljno memorijskog prostora. Prosto rečeno — kad odeš u WC, a sva mesta su zauzeta.
Curenje memorije (Memory Leak): memorija je zatražena, ali nije oslobođena, čime memorijski prostor biva rasipan. Prosto rečeno — neko zauzme mesto u WC-u, a ne obavi posao.

Preliv memorije

U memorijskim oblastima JVM-a, osim brojača programa, u svim ostalim oblastima može doći do preliva memorije.

Svi znamo da se u Java heap-u čuvaju objekti, odnosno instance objekata; prema tome, ukoliko neprestano kreiramo objekte i pritom obezbeđujemo da između GC Roots i objekata postoji dostižan put, kako bismo izbegli da ih mehanizam sakupljanja smeća ukloni, nužno će nastupiti preliv memorije.

Na primer, pri pokretanju sledećeg koda:

public class OOM {
    public static void main(String[] args) {
        List<Object> list = new ArrayList<>();
        while (true) {
            list.add(new Object());
        }
    }
}

Pri pokretanju programa obavezno podesi VM parametre: -Xms20m -Xmx20m -XX:+HeapDumpOnOutOfMemoryError, kojima se veličina heap-a ograničava na 20 M, bez dozvole za širenje, i pri čemu se pri OOM-u radi dump trenutnog snimka memorije.

Rezultat pokretanja je:

O tome smo već govorili i pri obradi runtime podatkovnih oblasti.

Curenje memorije

Curenje memorije znači da dinamički alociranu memoriju u heap-u program iz nekog razloga ne oslobodi ili ne može da oslobodi, čime dolazi do rasipanja sistemske memorije i do ozbiljnih posledica poput usporavanja rada programa pa i rušenja sistema.

Jednostavno rečeno, objekti koji bi trebalo da budu sakupljeni kao smeće to ne budu, pa zauzimaju sve više memorije, što naposletku vodi prelivu memorije.

Na gornjoj slici: objekat X referencira objekat Y; životni vek X-a duži je od životnog veka Y-a; kada se životni vek Y-a završi, sakupljač smeća neće sakupiti objekat Y.

Pogledajmo primer:

public class MemoryLeak {
    public static void main(String[] args) {
      try{
          Connection conn =null;
          Class.forName("com.mysql.jdbc.Driver");
          conn =DriverManager.getConnection("url","","");
          Statement stmt =conn.createStatement();
          ResultSet rs =stmt.executeQuery("....");
      } catch(Exception e){// log izuzetka
      } finally {
        // 1. Zatvori skup rezultata Statement
        // 2. Zatvori deklarisane objekte ResultSet
        // 3. Zatvori konekciju Connection
    }
  }
}

Kada se konekcija koja je kreirana više ne koristi, potrebno je pozvati metod close da se zatvori; tek kada je konekcija zatvorena, GC će sakupiti odgovarajuće objekte (Connection, Statement, ResultSet, Session). Zaboravljanje zatvaranja ovih resursa vodi trajnom zauzeću memorije koju GC ne može da sakupi.

To vodi curenju memorije, a naposletku i prelivu memorije.

Drugim rečima, curenje memorije nije preliv memorije, ali ubrzava njegovo nastupanje.

Simptomi posle preliva memorije

Problem preliva memorije koji se ranije javio u produkcionom okruženju, sa porastom obima posla, javljao se sve češće.

Poslovna logika aplikacije vrlo je jednostavna: podaci se konzumiraju sa Kafke, a zatim se rade grupne operacije trajnog upisivanja.

Simptom OOM-a jeste što, što je više Kafka poruka, to se brže javlja izuzetak. Pošto sam tada imao i drugog posla, jedino što sam mogao je da tražim od održavanja da radi restart i da pažljivo prati heap memoriju i GC.

Moram priznati — restart zaista rešava mnoge probleme, ali nije dugoročno rešenje.

Istraga curenja memorije

Zato smo na osnovu memorijskih podataka i GC logova koje je prethodno prikupilo održavanje pokušali da ocenimo gde je nastupao problem.

Ispostavilo se da je zauzeće stare generacije memorije, čak i kada nastupi GC, uvek ostajalo visoko, a s vremenom sve više raslo.

Uz jstat logove primećeno je da, čak i kad se desi FGC, stara generacija ne uspeva da sakupi — memorija je već na vrhu.

Na nekim mašinama FGC je dostigao i po nekoliko stotina puta, a vreme je bilo zastrašujuće visoko.

To jasno pokazuje da upotreba memorije u aplikaciji sigurno ima problem — postoji mnogo „pakosnih“ objekata koji se nikako ne sakupljaju.

Lociranje curenja memorije

Pošto je dump fajl memorije u produkciji veoma velik — dostizao je desetine GB; delom i zbog velike memorije konfigurisane u produkcionom okruženju.

Zato je analiza pomoću MAT-a zahtevala mnogo vremena.

MAT je dodatak za Eclipse koji se može koristiti i samostalno; služi za analizu Java heap memorije i pronalaženje uzroka curenja memorije.

Onda smo pomislili — da li bismo problem mogli reprodukovati lokalno, čime bi ga bilo mnogo lakše locirati.

Da bismo problem reprodukovali što pre, maksimalnu veličinu heap memorije lokalne aplikacije postavio sam na 150 M. Zatim sam u delu gde se konzumira Kafka napravio Mock while petlju koja neprestano generiše podatke.

Istovremeno, po pokretanju aplikacije, pomoću VisualVM-a sam se povezao na aplikaciju i u realnom vremenu pratio zauzeće memorije i GC.

Posle desetak minuta rada, zauzeće memorije nije pokazivalo problem. Sa slike se vidi da pri svakom GC memorija uspešno biva oslobođena, pa se problem nije reprodukovao.

Ako se problem ne reprodukuje, teško je locirati. Zato smo se odlučili za drevni metod — review koda; otkrili smo da se logika u produkciji razlikuje od podataka koje smo Mock-ovali while petljom.

Zaista, review koda ne bez razloga jeste prva linija odbrane performansi programa. Kad napišete kod, neka ga tim ponovo pregleda.

Kasnije, u produkcionim logovima, videli smo da se iz Kafke svaki put vadi po nekoliko stotina zapisa, dok smo u Mock-u svaki put generisali samo jedan zapis.

Da bismo što vernije simulirali produkciju, na serveru smo pokrenuli program proizvođača koji je neprestano slao podatke u Kafku.

Nije prošlo više od jednog minuta, a memorija je popustila; sa slike se vidi da je učestalost GC-a vrlo visoka, ali je oslobađanje memorije prilično bedno.

Istovremeno je u pozadini počelo ispisivanje curenja memorije — tim smo problem uspešno reprodukovali.

Rešavanje curenja memorije

Iz dosadašnjih simptoma proizilazi da u memoriji postoji mnogo objekata koji su stalno u vezi snažnim referencama i zato se ne sakupljaju.

Hteo sam da vidim koji to objekti zauzimaju toliko memorije; pomoću HeapDump funkcije VisualVM-a može se odmah dobiti dump trenutnog stanja memorije aplikacije.

Ispostavilo se da objekti tipa com.lmax.disruptor.RingBuffer zauzimaju skoro 50% memorije.

Kad sam video ovaj paket, prirodno sam pomislio na Disruptor prstenasti red.

Disruptor jeste visoko-performantni asinhroni okvir, čija je osnovna ideja: postizanje visoko-performantnog konkurentnog procesiranja na bez-zaključavanja način; njegove performanse veće su od JDK-ovog BlockingQueue-a.

Ponovnim review-em koda otkriveno je: 700 zapisa izvučenih iz Kafke direktno se ubacuje u Disruptor.

Time se objašnjava zašto prva simulacija nije reprodukovala problem.

Tokom simulacije u red se stavljao po jedan objekat, dok se u produkciji u red stavljalo po 700 zapisa. Razlika u količini podataka bila je čak 700 puta.

A Disruptor, kao prstenasti red, dok god objekti nisu prebrisani, uvek postoji.

Napravio sam i jedan eksperiment koji to potvrđuje.

Postavio sam veličinu reda na 8 i u njega upisivao 10 zapisa, od 0 do 9; kad se upiše do 8, mesto gde je ranije bio 0 biva prebrisano, i tako dalje (slično lociranju po modulu kod HashMap-a).

Znači, u produkcionom okruženju, pretpostavimo li da je veličina reda 1024, sa radom sistema će naposletku svih 1024 pozicija biti pune objekata, i to po 700 na svakoj!

Zato sam proverio konfiguraciju Disruptor-ovog RingBuffer-a u produkciji — iznosila je 1024*1024.

Taj redosled veličine je zastrašujući.

Da bih proverio da li je upravo to problem, lokalno sam tu vrednost podesio na 2, najmanju moguću.

Sa istih 128 M memorije, i daljim neprestanim konzumiranjem podataka iz Kafke, pratnja je pokazala sledeće:

Posle dvadesetak minuta sistem je radio potpuno normalno; pri svakom GC oslobođena je većina memorije, čime se na kraju dobija obrazac testere.

Tako je problem pronađen; kolika tačno vrednost treba biti u produkciji mora se testirati prema poslovnoj situaciji, ali na staru vrednost 1024*1024 svakako ne smemo više ni misliti.

Kratak pregled

Iako sam se na kraju pomakao samo jednim redom koda (nisam ga ni promenio, već sam izmenio konfiguraciju), smatram da je ovaj proces istrage vrlo koristan.

Takođe će većini kolega za koje je JVM takva „crna kutija” u koju se teško dira dati intuitivan osećaj.

Takođe treba uzdahnuti — Disruptor je sjajna stvar, ali ne treba je koristiti nepromišljeno!

Povezani demo kod pogledajte ovde:

https://github.com/crossoverJie/JCSprout/tree/master/src/main/java/com/crossoverjie/disruptor

Referenca 1: Istraga curenja memorije
Referenca 2: Preliv memorije i curenje memorije