Fop
  1. Fop
  2. FOP-2189

Apache FOP 1.0 Multithreading Problems - Too many open files err24

    Details

      Description

      We use Apache FOP to convert a whole lot of XML's to AFP's and PDF's. Our current load would be around 25k files per run on a HP-UX system. We have 12 threads in total that are used to initialize and trigger the FOP conversion in a producer-consumer fashion. Recently there have been multiple failures during conversion and when looked up, we've received generic FOP errors like:

      *ERROR,2460364,FOToPDF_Thread_11,FOP Exception, something.pdf,Failed to resolve font with embed-url './Fonts/arial.ttf'*

      or its an error failing to load the font metrics file although the files are intact with the right permissions. Many other PDF's are generated so this can't be the problem.

      We also wind up with:
      *java.io.FileNotFoundException: /PDF/20130111130002/something.pdf (Too many open files (errno:24))*

      judging by the logs and volume being processed, this looks like an FOP problem. I've read that FOP has had this issue in the past with the font files. There have been instances where Apache has opened each font file multiple times and not closed the handles resulting in a large number of open files. This was supposed to be fixed, but if it still persists, what would be a good and quick solution to this?

      1. tusc.log
        40 kB
        Joey Ezekiel
      2. Analyzer.log
        1 kB
        Joey Ezekiel

        Activity

        Joey Ezekiel created issue -
        Hide
        Alexios Giotis added a comment -

        Based on the description, this does not seem to be a multi-threading issue but a leak of file handles. In most Unix operating systems, you can use the "lsof" command line to list the files that are open by the java process. HP-UX might also have a more advanced tool similar to Dtrace.

        I doubt that the file leak is in FOP 1.0 code. I have been running FOP 1.0 plus patches for more than 2 years in much more than 10 production sites. Each site has a daily volume of 100-200K documents and 8-60 threads per process.

        I assume that you use FOP embedded in an application, so I suggest to look for file handle leaks in the code where the FOP output document is handled. I don't think there is much to do with this issue, unless there is some more specific information or some steps to reproduce it.

        Show
        Alexios Giotis added a comment - Based on the description, this does not seem to be a multi-threading issue but a leak of file handles. In most Unix operating systems, you can use the "lsof" command line to list the files that are open by the java process. HP-UX might also have a more advanced tool similar to Dtrace. I doubt that the file leak is in FOP 1.0 code. I have been running FOP 1.0 plus patches for more than 2 years in much more than 10 production sites. Each site has a daily volume of 100-200K documents and 8-60 threads per process. I assume that you use FOP embedded in an application, so I suggest to look for file handle leaks in the code where the FOP output document is handled. I don't think there is much to do with this issue, unless there is some more specific information or some steps to reproduce it.
        Hide
        Joey Ezekiel added a comment -

        Unfortunately we do not have lsof installed, but I'll try getting it. The thing that puzzles me is that the same threads with the same code are used to create the AFP files too. And it does - like a charm.

        Show
        Joey Ezekiel added a comment - Unfortunately we do not have lsof installed, but I'll try getting it. The thing that puzzles me is that the same threads with the same code are used to create the AFP files too. And it does - like a charm.
        Hide
        Joey Ezekiel added a comment -

        I've checked in the FOP source code. There is a class named FontFileReader that is used to read true type fonts.
        This class has two constructors as below:

        /**

        • Constructor
          *
        • @param fileName filename to read
        • @throws IOException In case of an I/O problem
          */

        public FontFileReader(String fileName) throws IOException {
        final File f = new File(fileName);
        InputStream in = new java.io.FileInputStream(f);
        try

        { init(in); }

        finally

        { in.close(); }

        }

        /**

        • Constructor
          *
        • @param in InputStream to read from
        • @throws IOException In case of an I/O problem
          */
          public FontFileReader(InputStream in) throws IOException { init(in); }

        As you can see in the second constructor above, the input stream is not closed., but in the constructor above that it is explicitly closed.

        There is another class called TTFFontLoader that loads the ttf fonts into memory, this class uses the second constructor (highlighted) to read the font files, so I think that is why the streams are remaining open and must be reaching the process wide limit of open file handles and is giving the “Too many open files” error.

        Can you please look into this?

        Show
        Joey Ezekiel added a comment - I've checked in the FOP source code. There is a class named FontFileReader that is used to read true type fonts. This class has two constructors as below: /** Constructor * @param fileName filename to read @throws IOException In case of an I/O problem */ public FontFileReader(String fileName) throws IOException { final File f = new File(fileName); InputStream in = new java.io.FileInputStream(f); try { init(in); } finally { in.close(); } } /** Constructor * @param in InputStream to read from @throws IOException In case of an I/O problem */ public FontFileReader(InputStream in) throws IOException { init(in); } As you can see in the second constructor above, the input stream is not closed., but in the constructor above that it is explicitly closed. There is another class called TTFFontLoader that loads the ttf fonts into memory, this class uses the second constructor (highlighted) to read the font files, so I think that is why the streams are remaining open and must be reaching the process wide limit of open file handles and is giving the “Too many open files” error. Can you please look into this?
        Hide
        Chris Bowditch added a comment - - edited

        The FontFileReader class has been refactored in trunk. Both the constructors listed above have been removed in favour of the init method thats been renamed into the constructor. That doesnt contain an explicit call to close, but the classes calling FontFileReader such as TTFFontLoader now call close in their finally block, e.g.

        InputStream in = resourceResolver.getResource(this.fontFileURI);
        try {
        TTFFile ttf = new TTFFile(useKerning, useAdvanced);
        FontFileReader reader = new FontFileReader(in);
        boolean supported = ttf.readFont(reader, ttcFontName);
        if (!supported)

        { throw new IOException("TrueType font is not supported: " + fontFileURI); }

        buildFont(ttf, ttcFontName);
        loaded = true;
        } finally

        { IOUtils.closeQuietly(in); }

        Therefore I believe this issue is resolved in trunk and this bug can be closed. You will need to upgrade to trunk to your resolve the problem in your environment.

        Show
        Chris Bowditch added a comment - - edited The FontFileReader class has been refactored in trunk. Both the constructors listed above have been removed in favour of the init method thats been renamed into the constructor. That doesnt contain an explicit call to close, but the classes calling FontFileReader such as TTFFontLoader now call close in their finally block, e.g. InputStream in = resourceResolver.getResource(this.fontFileURI); try { TTFFile ttf = new TTFFile(useKerning, useAdvanced); FontFileReader reader = new FontFileReader(in); boolean supported = ttf.readFont(reader, ttcFontName); if (!supported) { throw new IOException("TrueType font is not supported: " + fontFileURI); } buildFont(ttf, ttcFontName); loaded = true; } finally { IOUtils.closeQuietly(in); } Therefore I believe this issue is resolved in trunk and this bug can be closed. You will need to upgrade to trunk to your resolve the problem in your environment.
        Chris Bowditch made changes -
        Field Original Value New Value
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s trunk [ 12323672 ]
        Resolution Fixed [ 1 ]
        Hide
        Joey Ezekiel added a comment - - edited

        Ok, I've upgraded to trunk and I believe that there are other functions deprecated too. Is fopFactory.setUserConfig() no longer supported? and now FopFactory.newInstance(); needs a parameter?

        Show
        Joey Ezekiel added a comment - - edited Ok, I've upgraded to trunk and I believe that there are other functions deprecated too. Is fopFactory.setUserConfig() no longer supported? and now FopFactory.newInstance(); needs a parameter?
        Hide
        Alexios Giotis added a comment -

        I think this is not related to the issue and be better asked on the mailing list. Anyway, code like:

        FopFactory fopFactory = FopFactory.newInstance();
        fopFactory.setBaseURL(baseDir);
        fopFactory.setStrictValidation(strictValidation);
        fopFactory.setUserConfig(new File(fopConfigFile));

        needs to be replaced by code like:

        FopFactoryBuilder builder = new FopConfParser(new File(fopConfigFile)).getFopFactoryBuilder();
        builder.setBaseURI(new File(baseDir).getAbsoluteFile().toURI());
        builder.setStrictFOValidation(strictValidation);
        FopFactory fopFactory = builder.build();

        BTW, I was not able to identify any open file handle in FOP 1.0. The constructor of FontFileReader that takes an InputStream argument is indeed not closing it, but the caller (who created the stream) is closing it, see lines 94-106 of

        http://svn.apache.org/repos/asf/xmlgraphics/fop/tags/fop-1_0/src/java/org/apache/fop/fonts/truetype/TTFFontLoader.java

        Show
        Alexios Giotis added a comment - I think this is not related to the issue and be better asked on the mailing list. Anyway, code like: FopFactory fopFactory = FopFactory.newInstance(); fopFactory.setBaseURL(baseDir); fopFactory.setStrictValidation(strictValidation); fopFactory.setUserConfig(new File(fopConfigFile)); needs to be replaced by code like: FopFactoryBuilder builder = new FopConfParser(new File(fopConfigFile)).getFopFactoryBuilder(); builder.setBaseURI(new File(baseDir).getAbsoluteFile().toURI()); builder.setStrictFOValidation(strictValidation); FopFactory fopFactory = builder.build(); BTW, I was not able to identify any open file handle in FOP 1.0. The constructor of FontFileReader that takes an InputStream argument is indeed not closing it, but the caller (who created the stream) is closing it, see lines 94-106 of http://svn.apache.org/repos/asf/xmlgraphics/fop/tags/fop-1_0/src/java/org/apache/fop/fonts/truetype/TTFFontLoader.java
        Hide
        Joey Ezekiel added a comment -

        Picking up from my earlier issue, I have now used HP-UX's tusc utility (similar to lsof) to monitor the system calls (open/close file handles in specific) and I've noticed that certain image resources (.tif) files are left open. I've used the image cache listener to track the loading/pre-loading of images and the cache is working fine. The issue is that the last system file open call to any particular image (.tif in this case) is being left open and not being closed

        Show
        Joey Ezekiel added a comment - Picking up from my earlier issue, I have now used HP-UX's tusc utility (similar to lsof) to monitor the system calls (open/close file handles in specific) and I've noticed that certain image resources (.tif) files are left open. I've used the image cache listener to track the loading/pre-loading of images and the cache is working fine. The issue is that the last system file open call to any particular image (.tif in this case) is being left open and not being closed
        Joey Ezekiel made changes -
        Resolution Fixed [ 1 ]
        Status Resolved [ 5 ] Reopened [ 4 ]
        Joey Ezekiel made changes -
        Severity major [ 10591 ] blocker [ 10592 ]
        Joey Ezekiel made changes -
        Priority P2 [ 10595 ] P1 [ 10587 ]
        Hide
        Glenn Adams added a comment -

        Do you encounter the same issue under 1.1? Or under the current trunk?

        Show
        Glenn Adams added a comment - Do you encounter the same issue under 1.1? Or under the current trunk?
        Hide
        Joey Ezekiel added a comment -

        Yes - I've tried this with FOP 1.1 as well and it still has the same issue - not sure why the last call to the image resource is being left open and not closed.

        Show
        Joey Ezekiel added a comment - Yes - I've tried this with FOP 1.1 as well and it still has the same issue - not sure why the last call to the image resource is being left open and not closed.
        Hide
        Luis Bernardo added a comment -

        what about trunk? FOP-2226 seems to be a fix for the issue you describe.

        Show
        Luis Bernardo added a comment - what about trunk? FOP-2226 seems to be a fix for the issue you describe.
        Hide
        Joey Ezekiel added a comment -

        Thanks for that Luis, but I'm afraid it doesn't work with the FOP 1.1 trunk (nightly build - fop-20130606.jar) as well. I used the xmlgraphics trunk (xmlgraphics-commons-svn-trunk.jar) library as suggested but I still get the same results. I'm attaching the TUSC log from unix and a set of all the files open/closed so that it is evident that the files are not being closed. These image files are never opened manually anywhere in the code as there is no reason to.

        Going back to the original too many open files issue - there is another FOP process on the same unix box that runs simultaneously with this one but has nothing in common though - no font/image resources, not evoked from the same script, not a child script, no shared libraries - nothing. Could this be an issue causing the too many open files error? Both of them have substantial amount of images being used.

        Show
        Joey Ezekiel added a comment - Thanks for that Luis, but I'm afraid it doesn't work with the FOP 1.1 trunk (nightly build - fop-20130606.jar) as well. I used the xmlgraphics trunk (xmlgraphics-commons-svn-trunk.jar) library as suggested but I still get the same results. I'm attaching the TUSC log from unix and a set of all the files open/closed so that it is evident that the files are not being closed. These image files are never opened manually anywhere in the code as there is no reason to. Going back to the original too many open files issue - there is another FOP process on the same unix box that runs simultaneously with this one but has nothing in common though - no font/image resources, not evoked from the same script, not a child script, no shared libraries - nothing. Could this be an issue causing the too many open files error? Both of them have substantial amount of images being used.
        Joey Ezekiel made changes -
        Attachment tusc.log [ 12586735 ]
        Attachment Analyzer.log [ 12586736 ]
        Joey Ezekiel made changes -
        Comment [ tusc.log contains the open/close commands monitored on the unix bos. Analyzer.log gives which files are being left open. The jar files/system commands can be ignored - the calls to the image files are the concern. ]
        Hide
        Luis Bernardo added a comment -

        how many files (images, fonts, etc) do you expect your applications to open concurrently assuming that there are no leaks of file handles? what is the limit of file descriptors in your system (usually in unix/linux the default limit is 1024 but your system may be different)?

        this could be a coincidence, but the first google hit for "Too many open files (errno:24)" is a HP forum. maybe the issue is particular to your system. can you test in a non HP system?

        Show
        Luis Bernardo added a comment - how many files (images, fonts, etc) do you expect your applications to open concurrently assuming that there are no leaks of file handles? what is the limit of file descriptors in your system (usually in unix/linux the default limit is 1024 but your system may be different)? this could be a coincidence, but the first google hit for "Too many open files (errno:24)" is a HP forum. maybe the issue is particular to your system. can you test in a non HP system?
        Hide
        Joey Ezekiel added a comment -

        The limit is currently 4096 which is the process limit and in normal circumstances I do not think that the no of files opened concurrently should exceed that limit. I will try and replicate this on a windows environment.

        Show
        Joey Ezekiel added a comment - The limit is currently 4096 which is the process limit and in normal circumstances I do not think that the no of files opened concurrently should exceed that limit. I will try and replicate this on a windows environment.
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open Resolved Resolved
        1d 6h 35m 1 Chris Bowditch 18/Jan/13 15:08
        Resolved Resolved Reopened Reopened
        76d 16h 43m 1 Joey Ezekiel 05/Apr/13 08:52

          People

          • Assignee:
            Unassigned
            Reporter:
            Joey Ezekiel
          • Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

            • Created:
              Updated:

              Development