java.io.IOException: Stale file handle issue with multiple XNAT servers on a shared file system

1,654 views

Skip to first unread message

Haofei FENG

unread,

Nov 14, 2017, 5:16:50 PM11/14/17

to xnat_discussion

Hi,

We recently experienced issues with multiple XNAT application server sharing the PostgreSQL databases + Shared File systems on AWS.

Architecture:

-- Application Load Balancer + Auto Scaling Group

-- 2 x XNAT Application Servers

-- 1 x PostgreSQL database on AWS (RDS)

-- 1 x shared file system on AWS (EFS)

We recently experienced issues with "Stale File Handle Issue". It seemed to occur when we tried to change the DICOM RECEIVER SCP setting on one server (Server A), when the changes took effect, on the Server B, after logging on, it will show blank plage

1st. logon with admin and password

2nd. showing blank page after logging on

The application log showed below errors

2017-11-14 22:05:32,294 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#79 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:05:40,448 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_63_, preference0_.created as created2_63_, preference0_.disabled as disabled3_63_, preference0_.enabled as enabled4_63_, preference0_.timestamp as timestam5_63_, preference0_.entity_id as entity_i6_63_, preference0_.name as name7_63_, preference0_.scope as scope8_63_, preference0_.tool as tool10_63_, preference0_.value as value9_63_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=security.user.guestName}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:05:40,914 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#86 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:06:40,832 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#58 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:07:32,324 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#83 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:07:32,399 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#79 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-14 22:07:40,871 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#99 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

Security Log shows below errors.

at org.nrg.xnat.security.XnatProviderManager.authenticate(XnatProviderManager.java:147)

at org.nrg.xnat.security.XnatAuthenticationFilter.attemptAuthentication(XnatAuthenticationFilter.java:122)

at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:212)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64)

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:155)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.nrg.xnat.security.XnatExpiredPasswordFilter.doFilter(XnatExpiredPasswordFilter.java:158)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:157)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)

at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214)

at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:218)

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)

at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)

at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)

at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1087)

at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)

at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

at java.lang.Thread.run(Thread.java:748)

Caused by: net.sf.ehcache.CacheException: java.io.IOException: Stale file handle

at net.sf.ehcache.store.disk.DiskStorageFactory.retrieve(DiskStorageFactory.java:888)

at net.sf.ehcache.store.disk.Segment.decode(Segment.java:172)

at net.sf.ehcache.store.disk.Segment.put(Segment.java:449)

at net.sf.ehcache.store.disk.DiskStore.put(DiskStore.java:438)

at net.sf.ehcache.store.FrontEndCacheTier.put(FrontEndCacheTier.java:267)

at net.sf.ehcache.Cache.putInternal(Cache.java:1455)

at net.sf.ehcache.Cache.put(Cache.java:1383)

at net.sf.ehcache.Cache.put(Cache.java:1348)

at org.hibernate.cache.ehcache.internal.regions.EhcacheTransactionalDataRegion.put(EhcacheTransactionalDataRegion.java:143)

... 71 more

Caused by: java.io.IOException: Stale file handle

at java.io.RandomAccessFile.readBytes(Native Method)

at java.io.RandomAccessFile.read(RandomAccessFile.java:377)

at java.io.RandomAccessFile.readFully(RandomAccessFile.java:436)

at java.io.RandomAccessFile.readFully(RandomAccessFile.java:416)

at net.sf.ehcache.store.disk.DiskStorageFactory.read(DiskStorageFactory.java:364)

at net.sf.ehcache.store.disk.DiskStorageFactory.retrieve(DiskStorageFactory.java:886)

... 79 more

Usually it will solved the problem after we restart the tomcat services/reboot on the problematic server. But the next time we make some changes, we might need to reboot again.

The reason we want to have multiple servers accessing the same file system is to distribute the load.

Haofei FENG

unread,

Nov 14, 2017, 5:36:00 PM11/14/17

to xnat_discussion

Recent update.

We find out that if we restart the services on the problematic server, say server b, then server B works.

But server A will have the same issues. Then we reboot /restart services on Server A, server A fixes, but server B has same issues.

Let me try to shut them all down and start to see whether there are issues.

Haofei FENG

unread,

Nov 14, 2017, 5:46:10 PM11/14/17

to xnat_discussion

After I stop/start the tomcat service on both servers, it work again.

No further output for application.log.

Now i am trying to change the DICOM Receiver Port from one node, and see how it goes.

Haofei FENG

unread,

Nov 14, 2017, 5:48:54 PM11/14/17

to xnat_discussion

It worked after I change the DICOM receiver port on one node.

Haofei FENG

unread,

Nov 14, 2017, 5:51:39 PM11/14/17

to xnat_discussion

Conclusion:

I had issues with the "Stale File handle", my action

- Restart tomcat service on problematic server A, server A issues fix, the non-problematic server B fails

- Repeat the action on Server B, Server B issues fix, the non-problematic server A fails

- Stop tomcat services on both servers, start services on server A and B, problem fixed.

Haofei FENG

unread,

Nov 22, 2017, 11:09:10 PM11/22/17

to xnat_discussion

Issues reoccured again. This time had some cache release locks issues

2017-11-23 03:58:47,419 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=imageSessionDisplayNamePlural}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 03:59:00,014 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select this_.id as id1_40_0_, this_.created as created2_40_0_, this_.disabled as disabled3_40_0_, this_.enabled as enabled4_40_0_, this_.timestamp as timestam5_40_0_, this_.host_name as host_nam6_40_0_, this_.is_active as is_activ7_40_0_, this_.last_check_in as last_che8_40_0_, this_.last_initialized as last_ini9_40_0_, this_.last_ip_address as last_ip10_40_0_, this_.node_id as node_id11_40_0_ from xhbm_xnat_node_info this_ where this_.enabled=?; parameters: true, ; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:00:00,007 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=aliasTokenTimeout}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:00:33,055 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Tool#1 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:00:47,489 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=imageSessionDisplayNamePlural}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:01:33,092 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#53 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:02:17,514 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=sessionTimeout}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:02:33,117 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Tool#1 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:02:47,581 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=imageSessionDisplayNamePlural}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:03:33,134 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#53 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:04:17,614 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=sessionTimeout}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:04:47,692 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=imageSessionDisplayNamePlural}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:04:47,711 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=uiShowLeftBarFavorites}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:05:33,168 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.prefs.entities.Preference#53 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:05:45,273 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=emailVerification}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:05:45,275 [http-bio-8080-exec-100] ERROR org.hibernate.engine.spi.ActionQueue - HHH000353: Could not release a cache lock : org.hibernate.cache.CacheException: net.sf.ehcache.CacheException: java.io.IOException: Stale file handle

2017-11-23 04:06:05,583 [nrg.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of org.nrg.xdat.entities.XdatUserAuth#1 failed:

java.io.IOException: Stale file handle

at java.io.RandomAccessFile.writeBytes(Native Method)

at java.io.RandomAccessFile.write(RandomAccessFile.java:525)

at net.sf.ehcache.store.disk.DiskStorageFactory.write(DiskStorageFactory.java:392)

at net.sf.ehcache.store.disk.DiskStorageFactory$DiskWriteTask.call(DiskStorageFactory.java:485)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1088)

at net.sf.ehcache.store.disk.DiskStorageFactory$PersistentDiskWriteTask.call(DiskStorageFactory.java:1072)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

2017-11-23 04:06:17,752 [org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data] ERROR net.sf.ehcache.store.disk.DiskStorageFactory - Disk Write of sql: select preference0_.id as id1_22_, preference0_.created as created2_22_, preference0_.disabled as disabled3_22_, preference0_.enabled as enabled4_22_, preference0_.timestamp as timestam5_22_, preference0_.entity_id as entity_i6_22_, preference0_.name as name7_22_, preference0_.scope as scope8_22_, preference0_.tool as tool10_22_, preference0_.value as value9_22_ from xhbm_preference preference0_ left outer join xhbm_tool tool1_ on preference0_.tool=tool1_.id where tool1_.tool_id=? and preference0_.name=? and preference0_.scope=?; parameters: ; named parameters: {toolId=siteConfig, scope=0, name=siteDescriptionType}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2 failed:

Tim

unread,

Jul 11, 2018, 11:43:26 PM7/11/18

to xnat_discussion

It looks like ehcache is writing to disk space that is shared across 2 different servers. And both are trying to right to it to at the same time. This particular ehcache usage is coming from hibernate and is related to the Preferences API. I know there were some issues with that in early versions of 1.7, where the caching wasn't quite working right. I think you were on 1.7.4.1 here.

Rick, do you know if there could have been caching issues on the preference stuff in 1.7.4.1. If so, is that fixed in 1.7.5? Want to rule that out before we start delving further.

Tim

...

Herrick, Rick

unread,

Jul 12, 2018, 11:02:56 AM7/12/18

to xnat_di...@googlegroups.com

No issues with caching there that I’m aware of. The caching configuration for that is pretty straightforward. The portion relevant to Hibernate (and thus the preferences library) is this:

<defaultCache

maxElementsInMemory="10000"

eternal="false"

timeToIdleSeconds="120"

timeToLiveSeconds="120"

maxElementsOnDisk="10000000"

diskExpiryThreadIntervalSeconds="120"

memoryStoreEvictionPolicy="LRU">

</defaultCache>

Really the important thing is the disk-store path. With the default paths for XNAT, that ends up being /data/xnat/home/work/cache. Looking in there, I have these files:

./hbm/nrg.data

./hbm/org%002ehibernate%002ecache%002einternal%002e%0053tandard%0051uery%0043ache.data

./hbm/.ehcache-diskstore.lock

./hbm/org%002ehibernate%002ecache%002espi%002e%0055pdate%0054imestamps%0043ache.data

./xnat/.ehcache-diskstore.lock

./xnat/%0044efault%0043atalog%0053ervice%0043ache.data

The only file that contains any data is that hbm/nrg.data, which is the cache for all Hibernate entities in XNAT, which are annotated with:

@Cache(usage = CacheConcurrencyStrategy.READ_WRITE, region = "nrg")

The nrg region here is what prescribes the nrg.data file. The other caches XNAT uses are all in-memory due to issues with serializing XFT objects.

I could see where having separate processes accessing the same shared file could cause problems. I’m not sure if that’s the cause of this particular problem, but certainly can’t rule it out. Overall that work folder should probably be set up on a per-server basis. And, depending on how you have multiple servers configured, the same goes for the configuration folder. You can define separate node properties in config, but of course if the config folder is shared there’s only a single copy of that.

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

Phone: +1 (314) 273-1645

Tim

2nd. showing blank page after logging on

...

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to xnat_discussi...@googlegroups.com.
To post to this group, send email to xnat_di...@googlegroups.com.
Visit this group at https://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.

The materials in this message are private and may contain Protected Healthcare Information or other information of a sensitive nature. If you are not the intended recipient, be advised that any unauthorized use, disclosure, copying or the taking of any action in reliance on the contents of this information is strictly prohibited. If you have received this email in error, please immediately notify the sender via telephone or return mail.

Herrick, Rick

unread,

Jul 12, 2018, 11:43:12 AM7/12/18

to xnat_di...@googlegroups.com

One note I meant to add on this: the best way to share a single cache between multiple servers would be a distributed ehcache, but that’s only offered as a commercial product (BigMemory). FOSS ehcache only supports per-instance caching. I’ve spent a little time looking into other 2LC providers for Hibernate and haven’t found any FOSS application that’s stable and robust enough at this point. Memcached used to have a connector but that hasn’t worked since Hibernate 3. Infinispan actually looks pretty promising, but configuration is non-trivial so we haven’t had a chance to look into it and try it out.

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

Phone: +1 (314) 273-1645

Timothy Olsen

unread,

Jul 13, 2018, 10:13:35 AM7/13/18

to xnat_di...@googlegroups.com

Haofei,

Are you guys putting the entire xnat home directory on the shared space? Seems like that might be the issue here. We don’t usually put that directory on a network mount. The only directories we put on a network mount are the archive, build, cache, prearchive folders that are configured in XNAT. I believe we populate the xnat home directory via a script at server startup which pulls the content from S3 (and also pulls the xnat war from there). But it resides on the tomcat server’s local storage. I suspect doing that might resolve this issue.

Tim

--
You received this message because you are subscribed to a topic in the Google Groups "xnat_discussion" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/xnat_discussion/2iFtcdxqRlU/unsubscribe.
To unsubscribe from this group and all its topics, send an email to xnat_discussi...@googlegroups.com.

Alastair Ferguson

unread,

Feb 21, 2019, 10:53:25 PM2/21/19

to xnat_discussion

Also, for cost savings Goofys mount of S3 for /xnat/data/cache + archive + prearchive directories and the rest locally (home and pipeline) FTW.

10X cheaper than EFS...

...

Reply all

Reply to author

Forward

0 new messages