Re: [Exist-open] Unable to delete: webapp/WEB-INF/data/fs.journal/txn.41518

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

There is a leak of binary file chunks in 3.0.RC1, that could cause the
"Too many open files" error that you are seeing. I would suggest
updating to 3.1.1 and seeing how you go.

On 2 April 2017 at 15:24, Nick Sincaglia <nsi...@nu...> wrote:
> eXist-db Version: eXist-db 3.0 RC1 Stable
> OS: AWS Linux
>
> I have an eXist-db 3.0 RC1 instance running that has the Quartz scheduler
> running once every minute. The quartz schedule basically queries a
> collection to see if any documents have a particular XML tag set to a
> particular value. It is very simple and works fine generally. What i have
> noticed in recent weeks is that if I have my server running for about a
> week, it eventually becomes unresponsive. In particular, if I try to
> navigate to the dashboard, I get the following error.
>
> <exception>
> <path>/db/apps/dashboard/modules/view.xql</path>
> <message>exerr:ERROR An IO exception occurred: Could not load cache for
> class: org.exist.util.io.FileFilterInputStreamCache [at line 36, column
> 17]</message>
> </exception>
>
> I did a little looking around the log files and I found that my system was
> operating fine for a while but eventually, I will get the following error:
>
> 2017-04-01 18:22:02,047 [DefaultQuartzScheduler_Worker-4] INFO
> (Journal.java [lambda$clearBackupFiles$7]:375) - Checkpoint deleting:
> /mnt/data/exist-3.0-RC/tools/wrapper/bin/../../../webapp/WEB-INF/data/fs.journal/txn.41518
> 2017-04-01 18:22:02,048 [DefaultQuartzScheduler_Worker-4] ERROR
> (FileUtils.java [deleteQuietly]:89) - Unable to delete:
> /mnt/data/exist-3.0-RC/tools/wrapper/bin/../../../webapp/WEB-INF/data/fs.journal/txn.41518
> java.nio.file.FileSystemException:
> /mnt/data/exist-3.0-RC/tools/wrapper/bin/../../../webapp/WEB-INF/data/fs.journal/txn.41518/oper.1ae6eb75-4681-46e7-8f0e-fce7ea37ff7b/db/tmp/20170401182100001/012886102921:
> Too many open files
> at sun.nio.fs.UnixException.translateToIOException(UnixException.java:91)
> ~[?:1.8.0_65]
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
> ~[?:1.8.0_65]
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
> ~[?:1.8.0_65]
> at
> sun.nio.fs.UnixFileSystemProvider.newDirectoryStream(UnixFileSystemProvider.java:427)
> ~[?:1.8.0_65]
> at java.nio.file.Files.newDirectoryStream(Files.java:457) ~[?:1.8.0_65]
> at java.nio.file.FileTreeWalker.visit(FileTreeWalker.java:300) ~[?:1.8.0_65]
> at java.nio.file.FileTreeWalker.next(FileTreeWalker.java:372) ~[?:1.8.0_65]
> at java.nio.file.Files.walkFileTree(Files.java:2706) ~[?:1.8.0_65]
> at java.nio.file.Files.walkFileTree(Files.java:2742) ~[?:1.8.0_65]
> at org.exist.util.FileUtils.deleteQuietly(FileUtils.java:85) ~[exist.jar:?]
> at
> org.exist.storage.journal.Journal.lambda$clearBackupFiles$7(Journal.java:376)
> ~[exist.jar:?]
> at java.util.Iterator.forEachRemaining(Iterator.java:116) [?:1.8.0_65]
> at
> java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
> [?:1.8.0_65]
> at
> java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:580)
> [?:1.8.0_65]
> at org.exist.storage.journal.Journal.clearBackupFiles(Journal.java:374)
> [exist.jar:?]
> at org.exist.storage.journal.Journal.checkpoint(Journal.java:357)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.checkpoint(TransactionManager.java:296)
> [exist.jar:?]
> at org.exist.storage.BrokerPool.sync(BrokerPool.java:1816) [exist.jar:?]
> at org.exist.storage.sync.SyncTask.execute(SyncTask.java:91) [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.runSystemTask(SystemTaskManager.java:87)
> [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.processTasks(SystemTaskManager.java:69)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$5.execute(TransactionManager.java:366)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$RunWithLock.run(TransactionManager.java:395)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.processSystemTasks(TransactionManager.java:369)
> [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.triggerSystemTask(SystemTaskManager.java:48)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$4.execute(TransactionManager.java:356)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$RunWithLock.run(TransactionManager.java:395)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.triggerSystemTask(TransactionManager.java:359)
> [exist.jar:?]
> at org.exist.storage.BrokerPool.triggerSystemTask(BrokerPool.java:1893)
> [exist.jar:?]
> at
> org.exist.scheduler.impl.SystemTaskJobImpl.execute(SystemTaskJobImpl.java:113)
> [exist.jar:?]
> at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> [quartz-2.2.1.jar:?]
> at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
> [quartz-2.2.1.jar:?]
>
> When I navigate over to $EXIST_HOME/webapp/WEB-INF/data/fs.journal I see the
> following:
> [ec2-user@ip-10-31-66-185 fs.journal]$ ls -la
> total 28
> drwxr-xr-x 5 root     root     12288 Apr  1 18:22 .
> drwxrwxr-x 9 ec2-user ec2-user  4096 Mar 30 19:35 ..
> drwxr-xr-x 3 root     root      4096 Apr  1 18:22 txn.41452
> drwxr-xr-x 5 root     root      4096 Apr  1 18:21 txn.41518
> drwxr-xr-x 5 root     root      4096 Apr  1 18:22 txn.41585
>
> Looking at the logs, I can see the system is complaining at different times
> that it can’t delete these various txn.XXXXX files.
>
> Things generally get worse from here. Looking further down in the logs, it
> appears that the database goes into read-only mode and all that is in the
> logs is this:
>
> 2017-04-02 09:38:02,454 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:04,536 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:07,037 [DefaultQuartzScheduler_Worker-2] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:09,535 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:12,036 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:12,554 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:14,536 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:17,037 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:19,536 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:22,036 [DefaultQuartzScheduler_Worker-2] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:22,654 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:24,536 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:27,036 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:29,536 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:32,037 [DefaultQuartzScheduler_Worker-2] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:32,754 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:34,535 [DefaultQuartzScheduler_Worker-2] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:37,036 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:37,036 [DefaultQuartzScheduler_Worker-4] FATAL
> (Journal.java [clearBackupFiles]:381) - Could not clear journal backup files
> java.nio.file.FileSystemException:
> /mnt/data/exist-3.0-RC/tools/wrapper/bin/../../../webapp/WEB-INF/data/fs.journal:
> Too many open files
> at sun.nio.fs.UnixException.translateToIOException(UnixException.java:91)
> ~[?:1.8.0_65]
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
> ~[?:1.8.0_65]
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
> ~[?:1.8.0_65]
> at
> sun.nio.fs.UnixFileSystemProvider.newDirectoryStream(UnixFileSystemProvider.java:427)
> ~[?:1.8.0_65]
> at java.nio.file.Files.newDirectoryStream(Files.java:457) ~[?:1.8.0_65]
> at java.nio.file.Files.list(Files.java:3451) ~[?:1.8.0_65]
> at org.exist.storage.journal.Journal.clearBackupFiles(Journal.java:373)
> [exist.jar:?]
> at org.exist.storage.journal.Journal.checkpoint(Journal.java:357)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.checkpoint(TransactionManager.java:296)
> [exist.jar:?]
> at org.exist.storage.BrokerPool.sync(BrokerPool.java:1816) [exist.jar:?]
> at org.exist.storage.sync.SyncTask.execute(SyncTask.java:91) [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.runSystemTask(SystemTaskManager.java:87)
> [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.processTasks(SystemTaskManager.java:69)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$5.execute(TransactionManager.java:366)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$RunWithLock.run(TransactionManager.java:395)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.processSystemTasks(TransactionManager.java:369)
> [exist.jar:?]
> at
> org.exist.storage.SystemTaskManager.triggerSystemTask(SystemTaskManager.java:48)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$4.execute(TransactionManager.java:356)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager$RunWithLock.run(TransactionManager.java:395)
> [exist.jar:?]
> at
> org.exist.storage.txn.TransactionManager.triggerSystemTask(TransactionManager.java:359)
> [exist.jar:?]
> at org.exist.storage.BrokerPool.triggerSystemTask(BrokerPool.java:1893)
> [exist.jar:?]
> at
> org.exist.scheduler.impl.SystemTaskJobImpl.execute(SystemTaskJobImpl.java:113)
> [exist.jar:?]
> at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> [quartz-2.2.1.jar:?]
> at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
> [quartz-2.2.1.jar:?]
> 2017-04-02 09:38:39,536 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:42,036 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:42,854 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:44,537 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:47,035 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:49,536 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:52,036 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:52,955 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:38:54,537 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:57,035 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:38:59,536 [DefaultQuartzScheduler_Worker-2] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:39:02,036 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:39:03,055 [Scanner-1] WARN  (Scanner.java [scanFile]:587) -
> Error listing files in directory /mnt/data/exist-3.0-RC/tools/jetty/webapps
> 2017-04-02 09:39:04,538 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:39:07,036 [DefaultQuartzScheduler_Worker-4] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:39:09,537 [DefaultQuartzScheduler_Worker-1] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
> 2017-04-02 09:39:12,036 [DefaultQuartzScheduler_Worker-3] INFO
> (BrokerPool.java [setReadOnly]:1333) - Switching to read-only mode!!!
>
> Does anyone have have any idea what is causing this issue? I found this post
> on the internet that sounds like it might be related.
> https://github.com/eXist-db/exist/pull/816
>
> Does anyone have any suggestions on how to identify this issue? Is there any
> other information I can provide?
>
> Nick
>
>
> ------------------------------------------------------------------------------
> Check out the vibrant tech community on one of the world's most
> engaging tech sites, Slashdot.org! http://sdm.link/slashdot
> _______________________________________________
> Exist-open mailing list
> Exi...@li...
> https://lists.sourceforge.net/lists/listinfo/exist-open
>

-- 
Adam Retter

eXist Developer
{ United Kingdom }
ad...@ex...
irc://irc.freenode.net/existdb

Re: [Exist-open] Unable to delete: webapp/WEB-INF/data/fs.journal/txn.41518

eXist-db is a feature rich Open Source native XML database

Re: [Exist-open] Unable to delete: webapp/WEB-INF/data/fs.journal/txn.41518