Too many open files issue

canus · September 10, 2018, 2:38pm

Hi, there,

Recently we’ve got follow error (Too many open files issue) while attaching barcode image to PDF file.

OS: Linux redhat 6
Aspose Java PDF - Version: 17.12
Aspose Java Barcode - Version: 17.6

#Stacktrace log

com.aspose.pdf.internal.ms.System.IO.FileNotFoundException: File not found File: /s21_nas/eip_report/eipprod_cups/NWC/20180906/4030030878_20180907001122029.pdf
File name: ‘/s21_nas/eip_report/eipprod_cups/NWC/20180906/4030030878_20180907001122029.pdf’ —> /s21_nas/eip_report/eipprod_cups/NWC/20180906/4030030878_20180907001122029.pdf (Too many open files)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
com.aspose.pdf.internal.p115.z17.m2(Unknown Source)
com.aspose.pdf.internal.p115.z17.(Unknown Source)
com.aspose.pdf.internal.p84.z2.m5(Unknown Source)
com.aspose.pdf.internal.p115.z16.(Unknown Source)
com.aspose.pdf.internal.p84.z2.m8(Unknown Source)
com.aspose.pdf.internal.p22.z13.m1(Unknown Source)
com.aspose.pdf.internal.p22.z13.(Unknown Source)
com.aspose.pdf.ADocument.m1(Unknown Source)
com.aspose.pdf.ADocument.(Unknown Source)
com.aspose.pdf.Document.(Unknown Source)
com.canon.cusa.s21.framework.ZYP.aspose.pdf.S21PDFDocument.(S21PDFDocument.java:33)
com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.addBarcodeImageToPdf(NWCB011001.java:779)
com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.doProcess(NWCB011001.java:421)
com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.mainRoutine(NWCB011001.java:198)
com.canon.cusa.s21.framework.batch.S21BatchMain.executeBatch(S21BatchMain.java:281)
com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.main(NWCB011001.java:124)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
at com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
at com.aspose.pdf.internal.p115.z17.m2(Unknown Source)
at com.aspose.pdf.internal.p115.z17.(Unknown Source)
at com.aspose.pdf.internal.p84.z2.m5(Unknown Source)
at com.aspose.pdf.internal.p115.z16.(Unknown Source)
at com.aspose.pdf.internal.p84.z2.m8(Unknown Source)
at com.aspose.pdf.internal.p22.z13.m1(Unknown Source)
at com.aspose.pdf.internal.p22.z13.(Unknown Source)
at com.aspose.pdf.ADocument.m1(Unknown Source)
at com.aspose.pdf.ADocument.(Unknown Source)
at com.aspose.pdf.Document.(Unknown Source)
at com.canon.cusa.s21.framework.ZYP.aspose.pdf.S21PDFDocument.(S21PDFDocument.java:33)
at com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.addBarcodeImageToPdf(NWCB011001.java:779)
at com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.doProcess(NWCB011001.java:421)
at com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.mainRoutine(NWCB011001.java:198)
at com.canon.cusa.s21.framework.batch.S21BatchMain.executeBatch(S21BatchMain.java:281)
at com.canon.cusa.s21.batch.NWC.NWCB011001.NWCB011001.main(NWCB011001.java:124)
Caused by: java.io.FileNotFoundException: /s21_nas/eip_report/eipprod_cups/NWC/20180906/4030030878_20180907001122029.pdf (Too many open files)
at java.io.RandomAccessFile.open(Native Method)
at java.io.RandomAccessFile.(RandomAccessFile.java:233)
at java.io.RandomAccessFile.(RandomAccessFile.java:118)
… 21 more

However, when I confirmed current process’s open file number,it shows couple of few hundreds files. (Max: 65536) And it always failed over 3,xxx files processed.

$ ulimit -a
open files (-n) 65536

$ lsof -p 30245 | wc -l
3700

Anybody who knows what is the cause of this issue?

FYI, I found this functions from Aspose PDF API to release resources, however it doesn’t work.

pdfDocument.freeMemory();
pdfDocument.dispose();
pdfDocument.close();
com.aspose.pdf.MemoryCleaner.clear();

asad.ali · September 10, 2018, 10:18pm

@canus

Thanks for contacting support.

In case you are dealing with multiple and large number of files simultaneously in a muti-threaded environment, it is recommended to grant maximum available memory to the IDE. You can increase allotted memory by changing the values of Xms and Xmx parameters. However, please share complete sample code snippet if increasing memory does not help. We will test the scenario in our environment and address it accordingly.

canus · September 11, 2018, 2:42pm

@asad.ali

Thanks for quick reply.

However, our run time environment is not local IDE, it is linux redhat 6 server environment which has enough resources (cpu, memory). Also, I’ve confirmed that there is enough Xms and Xmx (512, 1024) and it used less than 400mb on JVM while running. Our scenario is opening PDF file then attaching 2D Barcode iamge one by one, total files will be about 20K. But, now it fails on processing over 3,000 files due to ‘Too many file open’. But, when I checked current open files by ‘lsof’ command while our program running (not Multi Threads, it’s standalone java batch program), it seems opening PDF file one by one. Do I have to use any function on below once save edited PDF?

pdfDocument.freeMemory();
pdfDocument.dispose();
pdfDocument.close();
com.aspose.pdf.MemoryCleaner.clear();

asad.ali · September 11, 2018, 8:05pm

@canus

Document.Save() method is itself more like to these methods as it closes each resource being used during document generation or modification. However, during PDF document generation and editing scenarios, there are some font files involved which remain open after conversion is completed. They have been opened by JDK inside java.awt.* classes to init internal static instances.

Would you please try using latest version of the API i.e. Aspose.PDF for Java 18.8 as it contains more fixes and improvements in terms of memory consumption. In case you still face any issue, please share complete sample code snippet which is able to reflect the routine you are performing along with screenshot of error you are facing. We will log an investigation ticket to investigate the issue and share the ticket ID with you.

canus · September 12, 2018, 2:33pm

@asad.ali

Thank you for quick answer, Today, I reproduced the issue!

It looks like something wrong in Document.Save() method, because it was always OK if I can specify filepath like Document.Save(‘failepath’); which worked fine even if 20K PDF file editing. However, When I did not specify filepath as input parameter, it caused ‘too many file open’ error easily. I attach my test code which I used test. Also, let me try latest version of 18.8. ThanksPdfDuplexPageUsingFolder.zip (2.9 KB)

[q02638@varhdv242 ~]$ ksh /home/q02638/dvlp/02shell/ZZT/TEST_2DBarcode2.ksh /s21_nas/eip_report/eipdev_cups/ZZT/20180907/ &
[1] 2540
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
427
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
426
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
427
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
625
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
626
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
^[[A626
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
626
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
485
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
485
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
488
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
488
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
488
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
488
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
488
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
491
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof -u q02638 | wc -l
527
[q02638@varhdv242 ~]$ lsof | wc -l
1794
[q02638@varhdv242 ~]$ lsof | wc -l
1401
[1]+ Done ksh /home/q02638/dvlp/02shell/ZZT/TEST_2DBarcode2.ksh /s21_nas/eip_report/eipdev_cups/ZZT/20180907/
[q02638@varhdv242 ~]$ lsof | wc -l
1401

#Error log (got error after 43 pdf processing)

com.aspose.pdf.internal.ms.System.IO.FileNotFoundException: File not found File: /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014376_20180907023028384.pdf
File name: ‘/s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014376_20180907023028384.pdf’ —> /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014376_20180907023028384.pdf (Too many open files)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.p965.z3.(Unknown Source)
com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
com.aspose.pdf.internal.p115.z17.m2(Unknown Source)
com.aspose.pdf.internal.p115.z17.(Unknown Source)
com.aspose.pdf.internal.p84.z2.m5(Unknown Source)
com.aspose.pdf.internal.p115.z16.(Unknown Source)
com.aspose.pdf.internal.p84.z2.m8(Unknown Source)
com.aspose.pdf.internal.p22.z13.m1(Unknown Source)
com.aspose.pdf.internal.p22.z13.(Unknown Source)
com.aspose.pdf.ADocument.m1(Unknown Source)
com.aspose.pdf.ADocument.(Unknown Source)
com.aspose.pdf.Document.(Unknown Source)
com.canon.cusa.s21.framework.ZYP.aspose.pdf.S21PDFDocument.(S21PDFDocument.java:33)
test.datamatrix.PdfDuplexPageUsingFolder.addBarcodeImageToPdfS21PDFFramework(PdfDuplexPageUsingFolder.java:213)
test.datamatrix.PdfDuplexPageUsingFolder.main(PdfDuplexPageUsingFolder.java:60)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.p965.z3.(Unknown Source)
at com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
at com.aspose.pdf.internal.ms.System.IO.z28.(Unknown Source)
at com.aspose.pdf.internal.p115.z17.m2(Unknown Source)
at com.aspose.pdf.internal.p115.z17.(Unknown Source)
at com.aspose.pdf.internal.p84.z2.m5(Unknown Source)
at com.aspose.pdf.internal.p115.z16.(Unknown Source)
at com.aspose.pdf.internal.p84.z2.m8(Unknown Source)
at com.aspose.pdf.internal.p22.z13.m1(Unknown Source)
at com.aspose.pdf.internal.p22.z13.(Unknown Source)
at com.aspose.pdf.ADocument.m1(Unknown Source)
at com.aspose.pdf.ADocument.(Unknown Source)
at com.aspose.pdf.Document.(Unknown Source)
at com.canon.cusa.s21.framework.ZYP.aspose.pdf.S21PDFDocument.(S21PDFDocument.java:33)
at test.datamatrix.PdfDuplexPageUsingFolder.addBarcodeImageToPdfS21PDFFramework(PdfDuplexPageUsingFolder.java:213)
at test.datamatrix.PdfDuplexPageUsingFolder.main(PdfDuplexPageUsingFolder.java:60)
Caused by: java.io.FileNotFoundException: /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014376_20180907023028384.pdf (Too many open files)
at java.io.RandomAccessFile.open(Native Method)
at java.io.RandomAccessFile.(RandomAccessFile.java:233)
at java.io.RandomAccessFile.(RandomAccessFile.java:118)
… 18 more
— Total Processing Time of 43PDF: 6633(msec)
— Average Processing Time of 1PDF: 154(msec)

Memory Usage : 177257760
Memory Commited : 536870912

asad.ali · September 12, 2018, 7:39pm

@canus

Thanks for sharing sample code snippet.

We tried to use the code file with latest version of APIs (i.e. Aspose.PDF for Java 18.8 and Aspose.Barcode for Java 18.8) and noticed that the code contains some undefined and missing assembly references. We request you to please share a sample console application along with sample input files which is able to replicate the issue in any environment. We will again test the scenario in our environment and address it accordingly.

canus · September 13, 2018, 1:25pm

@asad.ali

Hi,

I reproduced the ‘Document.save()’ method cause ‘Too many open files’ issue unless call ‘Document.dispose()’ method after save() in follow our environment. Also confirmed ‘Document.save(‘file-path’)’ method Does not cause this issue even if doesn’t call ‘Document.dispose()’ method.
Could you please verify if this is correct? For now we changed the code to use ‘Document.save(‘file-path’)’ without ‘Document.dispose()’ method and confirmed it worked fine with over 20K pdf file processing.

#Test Aspose versions and environment

OS: Linux redhat 6
Aspose Java PDF - Version: 17.12
Aspose Java Barcode - Version: 17.6

#Sample Code

public static void main(String[] args) {
for (int i=1; i<=10; i++) {
execLsof("[" + i + “] before new”);
com.aspose.pdf.Document pdf = new com.aspose.pdf.Document(inpuFileName);
execLsof("[" + i + “] before save”);
pdf.save();
execLsof("[" + i + “] end save”);
// pdf.dispose();
// execLsof("[" + i + “] end dispose”);
}
}

private static void execLsof(String memo){
String[] Command1 = { “sh”, “-c”, “echo " + memo + " >> ./lsof_aspose.txt”};
String[] Command2 = { “sh”, “-c”, “lsof -p " + myPid + " | wc -l >> ./lsof_aspose.txt”};
// String[] Command2 = { “sh”, “-c”, “lsof -p " + myPid + " >> ./lsof_aspose.txt”};
Runtime runtime = Runtime.getRuntime();
try {
runtime.exec(Command1);
runtime.exec(Command2);
} catch (IOException e) {
e.printStackTrace();
}
    try {
        Thread.sleep(1000);
    }
    catch (InterruptedException e) {
        e.printStackTrace();
    }
}

Test Result (You can see 'Document.save() method doesn’t close the edited pdf file and it cause ‘too many open files’ issue finally.

[q02638@varhdv242 ~]$ lsof java 21201 q02638 62r REG java 21201 q02638 254u REG java 21201 q02638 258u REG java 21201 q02638 259u REG java 21201 q02638 260u REG java 21201 q02638 261w REG java 21201 q02638 262w REG java 21201 q02638 263r REG java 21201 q02638 264r REG java 21201 q02638 265r REG java 21201 q02638 266r REG java 21201 q02638 267r REG java 21201 q02638 268r REG java 21201 q02638 269r REG java 21201 q02638 270r REG java 21201 q02638 271r REG java 21201 q02638 272r REG java 21201 q02638 273w REG java 21201 q02638 274r REG java 21201 q02638 275r REG java 21201 q02638 276r REG java 21201 q02638 277r REG -p 21201 | grep .pdf
253,6 44376232 6557420 /home/q02638/dvlp/99ezf/lib/aspose-pdf.jar
0,21 186261 4022796954 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/AuditTrail_41_20180907013906466.pdf
0,21 95545 4162075773 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/AuditTrail_42_20180907013920242.pdf
0,21 166973 49013384 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/AuditTrail_43_20180907013925696.pdf
0,21 1278243 3034044282 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/AuditTrail_44_20180907013947026.pdf
0,21 204403 2885393678 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014335_20180907023027699.pdf
0,21 204402 3489410944 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014341_20180907023027806.pdf
0,21 204136 2976270772 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014334_20180907023027611.pdf
0,21 204387 2390383412 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014340_20180907023027788.pdf
0,21 204402 401303270 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014347_20180907023027927.pdf
0,21 204410 3319501940 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014353_20180907023028036.pdf
0,21 204392 2094576230 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014336_20180907023027719.pdf
0,21 204393 3365240361 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014346_20180907023027907.pdf
0,21 204397 1239620370 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014342_20180907023027824.pdf
0,21 204378 3027604558 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014359_20180907023028127.pdf
0,21 204401 3107683859 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014352_20180907023028025.pdf
0,21 204389 1290847976 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014348_20180907023027946.pdf
0,21 204375 2250730643 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014358_20180907023028111.pdf
0,21 204392 3692545 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014365_20180907023028208.pdf
0,21 204374 270562427 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014364_20180907023028198.pdf
0,21 204391 86738427 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014344_20180907023027865.pdf
0,21 204396 1262212213 /s21_nas/eip_report/eipdev_cups/ZZT/20180907/4030014356_20180907023028088.pdf

asad.ali · September 13, 2018, 9:15pm

@canus

Thanks for sharing narrowed down code snippet.

We executed your code snippet in Linux environment using latest versions of the APIs and were unable to replicate the said error. Would you please try using latest versions and let us know about your feedback.

canus · September 17, 2018, 6:48pm

@asad.ali

Sorry, I couldn’t test with latest version of PDF jar v.18.8, because it requires our code change on editing PDF contents and that’s the reason why we are keep using current ver.17.6 for a while. For now, we decided to code Save() + Dispose() or Save('filepath) way with going PDF v.17.6.

Thanks for your help

asad.ali · September 17, 2018, 7:02pm

@canus

Thanks for your feedback.

You may please keep using your current API Version as long as it fulfills your needs. You can surely upgrade to latest version when it suites you and in case you experience any issue, please feel free to let us know.