Unexpected error occurred in scheduled task (deleting stale searches)

[ca...@alis-sol.com.br]

Hi,

We keep getting this kind of error from time to time with HAPI 2.5 (Oracle database):

2017-10-06 11:08:56.349  INFO 4526 --- [ecutorService-2] c.u.f.j.s.StaleSearchDeletingSvcImpl     : Deleting search f7d9a3b0-d465-4523-b13d-fefcc23ccc2c - Created[2017-10-06 10:08:45.897] -- Last returned[2017-10-06 10:08:45.897]

2017-10-06 11:08:56.482 ERROR 4526 --- [ecutorService-2] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

java.lang.NullPointerException: null

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl$1.doInTransactionWithoutResult(StaleSearchDeletingSvcImpl.java:80) ~[hapi-fhir-jpaserver-base-2.5.jar:na]

at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:34) ~[spring-tx-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133) ~[spring-tx-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl.deleteSearch(StaleSearchDeletingSvcImpl.java:76) ~[hapi-fhir-jpaserver-base-2.5.jar:na]

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl.pollForStaleSearchesAndDeleteThem(StaleSearchDeletingSvcImpl.java:107) ~[hapi-fhir-jpaserver-base-2.5.jar:na]

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl.schedulePollForStaleSearches(StaleSearchDeletingSvcImpl.java:120) ~[hapi-fhir-jpaserver-base-2.5.jar:na]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_101]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_101]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_101]

at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_101]

at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) ~[spring-aop-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) ~[spring-aop-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) ~[spring-tx-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) ~[spring-aop-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at com.sun.proxy.$Proxy183.schedulePollForStaleSearches(Unknown Source) ~[na:na]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_101]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_101]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_101]

at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_101]

at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) ~[spring-context-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-4.3.7.RELEASE.jar:4.3.7.RELEASE]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_101]

at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_101]

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_101]

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_101]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_101]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_101]

at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]

Since findOne can return null it seems a simple enough bug to correct. However the cause may be more complex if the search should only be removed by that thread.

I hope in time I get more knowledge of the inner workings of HAPI and can start helping with small things like this.

Cheers,

Carlos