Icefaces opening jsf and icefaces jar files hundreds of times

Question

I just had all the users of my system try to log in at the same time. My server came to its knees with this error:

SEVERE: Socket accept failed
Throwable occurred: java.net.SocketException: Too many open files
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:449)
    at java.net.ServerSocket.implAccept(ServerSocket.java:473)
    at java.net.ServerSocket.accept(ServerSocket.java:441)
    at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:59)
    at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:212)
    at java.lang.Thread.run(Thread.java:736)
May 9, 2012 10:04:11 AM org.apache.tomcat.util.net.JIoEndpoint$Acceptor run

i ran a lsof command to see what files the tomcat user has open and got a huge list of files. most looked normal, but then i came across about 700 entries of the same files, here is a snip of that output:

java    12285 tomcat  256r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  257r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  258r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  259r   REG                8,3   271669    1040879 /usr/share/tomcat7/shared/nmsc/icefaces-3.0.0.RC2.jar
java    12285 tomcat  260r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  261r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  262r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  263r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  264r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  265r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  266r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  267r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  268r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  269r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  270r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  271r   REG                8,3   271669    1040879 /usr/share/tomcat7/shared/nmsc/icefaces-3.0.0.RC2.jar
java    12285 tomcat  272r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  273r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  274r   REG                8,3   271669    1040879 /usr/share/tomcat7/shared/nmsc/icefaces-3.0.0.RC2.jar
java    12285 tomcat  275r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  276r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  277r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  278r   REG                8,3   271669    1040879 /usr/share/tomcat7/shared/nmsc/icefaces-3.0.0.RC2.jar
java    12285 tomcat  279r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  280r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  281r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar
java    12285 tomcat  282r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  283r   REG                8,3   271669    1040879 /usr/share/tomcat7/shared/nmsc/icefaces-3.0.0.RC2.jar
java    12285 tomcat  284r   REG                8,3  1470076    1040880 /usr/share/tomcat7/shared/nmsc/icefaces-ace-3.0.0.RC2.jar
java    12285 tomcat  285r   REG                8,3  1955103    1040820 /usr/share/tomcat7/shared/nmsc/jsf-impl-2.1.4.jar

i upped the number of allowed file handles for the tomcat user to get me thru the morning, but why in the world would tomcat be opening a new copy of icefaces and jsf for each HTTP request (which appears to be whats happening) instead of using the copy of the file that the classloader loads on boot? i don't know where to even begin troubleshooting this.

BTW, this happened with only 40 users trying to get in at the same time. — scphantm, May 09 '12 at 16:10
Off topic but IceFaces is a fork of PrimeFaces, in case you don't know. http://blog.primefaces.org/?p=1750 — Cagatay Civici, May 17 '12 at 11:10

score 0 · Answer 1 · answered May 09 '12 at 16:23

Personally, I'd start wth a profiler (I use YourKit since they give open source developers free copies), take a memory snapshot and then search for those file names. That should lead to File, URL or similar objects that hopefully provide some clues as to where the problem is. If not, you'll need to start tracking object allocation which is a lot more expensive but doable. Other profilers are available ;)

score 0 · Answer 2 · answered May 14 '12 at 16:43

I just ran our ACE showcase example and don't see the behaviour of the increasing file handles with each request. Are you perhaps using composite components in your application? There is a bug in versions of Mojarra that hasn't been fixed until recently (Mojarra 2.1.7) related to a core composite component class:

http://java.net/jira/browse/JAVASERVERFACES-2113

It documents InputStreams that are opened but not closed. On Windows, this locks the files and prevents them being redeployed. On other systems this might explain the behaviour your are seeing.

score 0 · Answer 3 · answered Mar 22 '13 at 15:18

Are you using the new G1 garbage collector? If so you might have uncovered a bug in one of your libraries or code. The new G1 garbage collector seems less inclined to close files than previous implementations.

There is well written example of this here: http://mark.koli.ch/2011/01/leaky-pipes-remember-to-close-your-streams-when-using-javas-runtimegetruntimeexec.html

Icefaces opening jsf and icefaces jar files hundreds of times

3 Answers3