sobota 7. února 2009

Leakující streamy

Nedávno jsem opravoval jednu svojí botu, která byla způsobena tím, že jsem předpokládal, že JDBC driver resp. PreparedStatement uzavírá po ukončení transakce předaný InputStream. Bohužel nic takového se neděje. Naše speciální implementace InputStream se chovala tak, že určitou část dat si držela v paměti a zbytek odswapovala do souboru v tmp adresáři. Tento soubor se měl smazat při zavření asociovaného streamu a pro strýčka příhodu měl ještě nastavený deleteOnExit příznak .

Díky tomu, že se nevolal close daného streamu, tak se v tmp adresáři rojily nové soubory jako houby po dešti. To vedlo k tomu, že za určitou dobu běhu serveru tmp adresář přetekl a došlo místo a nebo file descriptory (chyba lávky - nody clusteru se tak často nerestartuji. Takže deleteOnExit byl pro parádu). Celá situace našeho streamu, byla ještě komplikovaná faktem, že o jeho vyrábění se také staral Hibernate, protože tento stream se použil při mapování jako user type. To znamenalo, že selektovaná entita měla asociovaný stream aniž by si to člověk uvědomil. Naštěstí byla většina kódu izolována pouze v persistentní vrstvě.

Najít a odladit všechny nezavřené streamy ovšem nebylo tak jednoduché, protože tam byla indirikece přes Hibernate a user type. Nakonec někde v kódu persistentní vrstvy zůstával nějaký leak, který jsem nebyl z kódu sto přímo vyčíst. Nakonec jsem byl nucen vytvořit speciální debugovací kód, který v konstruktoru našeho streamu vypsal stacktrace označený identity hashcodem a zároveň přidal tento identity hashcod do vzniklého souboru v tmp adresáři. Projetím logu a párováním pozůstalých souborů s označenými stacktracy se mi nakonec podařilo odstranit zbývající leaky.

Samozřejmě, mě nemohlo toto ad hoc řešení uspokojit, protože mi přišlo málo systémové. Kdokoliv kdo použije daný user type (používáme jej obecně pro binární data v DB) může snadno zapomenout na onu zákeřnou indirekci a leak je na světě. Taky jsem si chtěl být jisty, že všechny vyšší vrstvy někde nezapomenou zavolat uzavření streamu a tedy uvolnění drženého souboru. Metodologie, kterou jsem použil pro odhalení zbývajících leaku se mi osvědčila a tak nebyl důvod dotáhnout její použití.

Celý trasovací kód jsem vyčlenil do aspectu, takže kdykoliv je teď potřeba, tak můžeme pro naše integrační testy či manuální testy zapnout tento aspect, který na exit JVM vypíše neuzavřené streamy resp. kód, který je otevřel. Výstup pak vypadá přibližně následovně.


-------------------------------------------------------

Unclosed stream allocated from: 



java.lang.Thread.getStackTrace(Thread.java:1436)

cz.sweb.pichlik.leakdetector.LeakDetector.ajc$afterReturning$cz_sweb_pichlik_leakdetector_LeakDetector$1$5f03d6db(LeakDetector.aj:29)

cz.sweb.pichlik.leakdetector.FooInputStream.(FooInputStream.java:12)

cz.sweb.pichlik.leakdetector.LeakDetectorTest.testSmoke(LeakDetectorTest.java:11)

...zbytek vynechán  

  

Ve výše uvedeném výpisu jsem pro účely článku vynechal plný stacktrace. Kód, který leak způsobil vypadá následovně.

public class LeakDetectorTest {
  @Test
  public void testSmoke() throws Exception{
    new FooInputStream(getClass().getResourceAsStream("LeakDetectorTest.class")).close();
    for(int i = 0; i < 5; i++) { 
      new FooInputStream(null);
    }
  }
}

Aspect vypadá následovně.

public aspect LeakDetector {
    
    private final Map<Integer, StackTraceElement[]> openStreams;  

    pointcut streamConstructor(): target(FooInputStream&& (execution(FooInputStream.new(..)));
    pointcut streamClose(): target(FooInputStream&& (execution(void close()));
    
    public LeakDetector(){
        openStreams = new ConcurrentHashMap<Integer, StackTraceElement[]>();
        Runtime.getRuntime().addShutdownHook(new LeakPrinter(openStreams));
    }
    
    /**
     * Puts a stream into watched area.
     */
    after() returning: streamConstructor() {
        StackTraceElement stacktrace[] = Thread.currentThread().getStackTrace()
        Integer streamId = getObjectIdentifier(thisJoinPoint);
        
        openStreams.put(streamId, stacktrace);   
    }
    
    /**
     * Removes a stream from watched area.
     */
    after() returning: streamClose() {      
        Integer streamId = getObjectIdentifier(thisJoinPoint);
        openStreams.remove(streamId);
    }
    
    private Integer getObjectIdentifier(JoinPoint jp) {
        return System.identityHashCode(jp.getTarget());
    }

}

Aspect obsahuje dva pointcut výrazy. Jeden pro zachycení vytvoření streamu a druhý pro jeho uzavření. Na tyto dva pointcut výrazy jsou navěšené dvě advice. První advice zajistí, že když je stream zkonstruován, udělá se snapshot aktuálního stacktrace a ten se spolu s identity hashcodem uloží do mapy. Druhá advice zajistí, že při volání close metody streamu, se na základě identity hashcode odstraní z mapy příslušný záznam. Aspect má ještě ve vlastním konstruktoru vlákno, které zaregistruje jako shutdownhook. Vlákno nedělá nic jiného, než že vypíše obsah mapy. Na konci běhu programu máme v mapě tedy pouze stacktracy určující místa kde vznikají neuzavřené streamy.

Pokud chci aspect použít, tak jako nejvhodnější se jeví load time weaving. Díky tomu neni potřeba žádná speciální kompilace, protože aspect se dostane do kódu při classloadingu. Pokud si chcete hráti, tak k dispozici je Maven project se zdrojovými kódy a nastavenym AspectJ compilerem.

Související články