Grizzly pipe leak - co robię źle?

Question

Pisałem następujący kod testowy:

@Test 
public void testLeakWithGrizzly() throws Throwable { 
    ExecutorService executor = Executors.newFixedThreadPool(N_THREADS); 
    Set<Future<Void>> futures = new HashSet<>(); 
    InetSocketAddress inetSocketAddress = new InetSocketAddress(localhostAddress, 111); 
    for (int i = 0; i < N_THREADS; i++) { 
     Future<Void> future = executor.submit(new GrizzlyConnectTask(inetSocketAddress, requests, bindFailures, successfulOpens, failedOpens, successfulCloses, failedCloses)); 
     futures.add(future); 
    } 
    for (Future<Void> future : futures) { 
     future.get(); //block 
    } 
    Thread.sleep(1000); //let everything calm down 
    reporter.report(); 
    throw causeOfDeath; 
}  
private static class GrizzlyConnectTask implements Callable<Void> { 
    private final InetSocketAddress address; 
    private final Meter requests; 
    private final Meter bindFailures; 
    private final Counter successfulOpens; 
    private final Counter failedOpens; 
    private final Counter successfulCloses; 
    private final Counter failedCloses; 

    public GrizzlyConnectTask(InetSocketAddress address, Meter requests, Meter bindFailures, Counter successfulOpens, Counter failedOpens, Counter successfulCloses, Counter failedCloses) { 
     this.address = address; 
     this.requests = requests; 
     this.bindFailures = bindFailures; 
     this.successfulOpens = successfulOpens; 
     this.failedOpens = failedOpens; 
     this.successfulCloses = successfulCloses; 
     this.failedCloses = failedCloses; 
    } 

    @Override 
    public Void call() throws Exception { 
     while (!die) { 
      TCPNIOTransport transport = null; 
      boolean opened = false; 
      try { 
       transport = TCPNIOTransportBuilder.newInstance().build(); 
       transport.start(); 
       transport.connect(address).get(); //block 
       opened = true; 
       successfulOpens.inc(); //successful open 
       requests.mark(); 
      } catch (Throwable t) { 
       //noinspection ThrowableResultOfMethodCallIgnored 
       Throwable root = getRootCause(t); 
       if (root instanceof BindException) { 
        bindFailures.mark(); //ephemeral port exhaustion. 
        continue; 
       } 
       causeOfDeath = t; 
       die = true; 
      } finally { 
       if (!opened) { 
        failedOpens.inc(); 
       } 
       if (transport != null) { 
        try { 
         transport.shutdown().get(); //block 
         successfulCloses.inc(); //successful close 
        } catch (Throwable t) { 
         failedCloses.inc(); 
         System.err.println("while trying to close transport"); 
         t.printStackTrace(); 
        } 
       } else { 
        //no transport == successful close 
        successfulCloses.inc(); 
       } 
      } 
     } 
     return null; 
    } 
} 

na moim laptopie linux, to rozbija w ~ 5 minut z następującym wyjątkiem:

java.io.IOException: Too many open files 
    at sun.nio.ch.EPollArrayWrapper.epollCreate(Native Method) 
    at sun.nio.ch.EPollArrayWrapper.<init>(EPollArrayWrapper.java:130) 
    at sun.nio.ch.EPollSelectorImpl.<init>(EPollSelectorImpl.java:68) 
    at sun.nio.ch.EPollSelectorProvider.openSelector(EPollSelectorProvider.java:36) 
    at org.glassfish.grizzly.nio.Selectors.newSelector(Selectors.java:62) 
    at org.glassfish.grizzly.nio.SelectorRunner.create(SelectorRunner.java:109) 
    at org.glassfish.grizzly.nio.NIOTransport.startSelectorRunners(NIOTransport.java:256) 
    at org.glassfish.grizzly.nio.NIOTransport.start(NIOTransport.java:475) 
    at net.radai.LeakTest$GrizzlyConnectTask.call(LeakTest.java:137) 
    at net.radai.LeakTest$GrizzlyConnectTask.call(LeakTest.java:111) 
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 
    at java.lang.Thread.run(Thread.java:745) 

sukces/fail liczniki wyglądać następująco:

-- Counters -------------------------------------------------------------------- 
failedCloses 
      count = 0 
failedOpens 
      count = 40999 
successfulCloses 
      count = 177177 
successfulOpens 
      count = 136178 

-- Meters ---------------------------------------------------------------------- 
bindFailures 
      count = 40998 
     mean rate = 153.10 events/second 
    1-minute rate = 144.61 events/second 
    5-minute rate = 91.12 events/second 
    15-minute rate = 39.56 events/second 
requests 
      count = 136178 
     mean rate = 508.54 events/second 
    1-minute rate = 547.38 events/second 
    5-minute rate = 442.76 events/second 
    15-minute rate = 391.53 events/second 

który mówi mi, że:

• nie było bliskie porażki
• wszystkie połączenia albo nie udało się utworzyć lub zostały pomyślnie zamknięte (136178 + 40999 = 177177)
• wszystkie awarie otwarcia były efemeryczne wyczerpanie portu z wyjątkiem ostatniego (40999 = 40998 + 1)

kompletny kod jest maksymalnie na github tutaj - https://github.com/radai-rosenblatt/oncrpc4j-playground/blob/master/src/test/java/net/radai/LeakTest.java

tak, mam jakoś niewłaściwie grizzly API, czy jest to prawdziwy przeciek? (uwaga -. Im przy grizzly 2.3.12, co wiem, nie jest najnowsza modernizacja wymagałaby przekonujących ludzi, dlatego chcę być dodatnia to nie jest błąd użytkownika na moim końcu)

EDIT - ta rzecz wycieka, nawet gdy nic nie jest rzucane. cofnięcie się do pojedynczego wątku i pozostawienie tam 2ms nadal przecieka 800 rur w ciągu 50 minut.

Answer 1

Znalazłem problem głęboko w grizzly. Jest to kwestia wewnętrznego wielowątkowości (stan wyścigu). Deskryptory plików są nieszczelne w klasie sun.nio.ch.EPollSelectorImpl. Każda instancja zawiera 3 deskryptory plików (2 dla każdej rury i 1 dla epoll_create syscall). Grizzly wysyła blisko/wyłączanie w klasie SelectorRunner:

public synchronized void stop() { 
     stateHolder.set(State.STOPPING); 
     wakeupSelector(); 

     // we prefer Selector thread shutdown selector 
     // but if it's not running - do that ourselves. 
     if (runnerThreadActivityCounter.compareAndSet(0, -1)) { 
      // The thread is not running 
      shutdownSelector(); 
     } 
    } 

Zazwyczaj wszystko jest w porządku, ale czasami selektor nie obudzi. Metoda Wakeup wysyła przerwanie metodą natywną sun.nio.ch.EPollArrayWrapper#interrupt(int). Ma prostą implementację:

JNIEXPORT void JNICALL 
Java_sun_nio_ch_EPollArrayWrapper_interrupt(JNIEnv *env, jobject this, int fd) 
{ 
    int fakebuf[1]; 
    fakebuf[0] = 1; 
    if (write(fd, fakebuf, 1) < 0) { 
     JNU_ThrowIOExceptionWithLastError(env,"write to interrupt fd failed"); 
    } 
} 

Po prostu wysyła jeden bajt, aby obudzić selektor oczekiwania. Ale zamykasz transport natychmiast po stworzeniu. Rzadko zdarza się to w rzeczywistości, ale zdarza się to regularnie w twoim przypadku testowym. Czasami grizzly wywołuje NIOConnection.enableIOEvent po zamknięciu i przebudzeniu/przerwie. Myślę, że w tym przypadku selektorzy nigdy się nie budzą i nigdy nie mają wolnych deskryptorów plików.

Obecnie mogę tylko zasugerować poprawki do tej sytuacji: użyj zadania czasomierza do bezpośredniego połączenia selector.close po pewnym timeout:

//hotfix code bellow 
private static final Timer timer = new Timer(); 
//hotfix code above 
protected synchronized void stopSelectorRunners() { 
    if (selectorRunners == null) { 
     return; 
    } 

    for (int i = 0; i < selectorRunners.length; i++) { 
     SelectorRunner runner = selectorRunners[i]; 
     if (runner != null) { 
      runner.stop(); 
      //hotfix code below 
      final Selector selector = runner.getSelector(); 
      if(selector !=null) { 
       timer.schedule(new TimerTask() { 
        @Override 
        public void run() { 
         try { 
          selector.close(); 
         } catch (IOException e) { 
         } 
        } 
       }, 100); 
      } 
      //hotfix code above 
      selectorRunners[i] = null; 
     } 
    } 

    selectorRunners = null; 
} 

mogę zapobiec przeciekom po dodaniu to org.glassfish.grizzly.nio.NIOTransport#stopSelectorRunners

Answer 2

Znaleźliśmy rzeczywista bazowego problem w Grizzly i naprawili go.

Głównym źródłem problemu jest, w oparciu o przypadek testowy, Transport.stop() był wywoływany w punkcie wystarczająco wcześnie w wykonaniu SelectorRunner.run(), który spowodowałby wcześniejsze zakończenie metody run (z powodu stanu StateHolder będącego w stanie zatrzymania w tym momencie).

Dodatkowo, ponieważ SelectorRunner.run() CAS zmienia stan aktywności selektora na początku metody run(), wątek wywołujący Transport.stop() widzi selektor jako aktywny. Z powodu tych dwóch warunków SelectorRunner.shutdownSelector() nigdy nie jest wywoływany i dlatego wybieramy selektory.

Poprawka będzie dostępna w wieczornej nocnej kompilacji.