theotherp / nzbhydra2

Usenet meta search
Other
1.25k stars 75 forks source link

NullPointerException when downloading file through nzbhydra #457

Closed fbjerggaard closed 4 years ago

fbjerggaard commented 4 years ago

I get the following error when downloading an NZB through NZBHydra2. The indexer is a custom-made one that works fine when used directly in Sonarr, so the output from it should conform to the standards.

I am running NZBHydra2 version 2.8.0

2019-11-11 14:22:14.067  INFO --- [0.0-5076-exec-1] org.nzbhydra.downloading.FileHandler     : [Search: <redacted>, Host: <redacted>] NZB download request for "<redacted>" from indexer <redacted>
2019-11-11 14:22:14.071 ERROR --- [0.0-5076-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : [Search: <redacted>, Host: <redacted>] Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.NullPointerException] with root cause

java.lang.NullPointerException: null
    at java.base/java.time.Duration.between(Duration.java:488)
    at org.nzbhydra.downloading.FileDownloadEntity.<init>(FileDownloadEntity.java:55)
    at org.nzbhydra.downloading.FileHandler.handleRedirect(FileHandler.java:119)
    at org.nzbhydra.downloading.FileHandler.getFileByGuid(FileHandler.java:73)
    at org.nzbhydra.downloading.nzbs.NzbHandlingWeb.downloadNzbForUsers(NzbHandlingWeb.java:130)
    at org.nzbhydra.downloading.nzbs.NzbHandlingWeb$$FastClassBySpringCGLIB$$fbb32e1e.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:769)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747)
    at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:69)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at org.nzbhydra.downloading.nzbs.NzbHandlingWeb$$EnhancerBySpringCGLIB$$3abb3a7f.downloadNzbForUsers(<generated>)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.nzbhydra.auth.HydraAnonymousAuthenticationFilter.doFilter(HydraAnonymousAuthenticationFilter.java:98)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:320)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:126)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:118)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:158)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:158)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:117)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:92)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:77)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526)
    at org.nzbhydra.auth.HydraEmbeddedServletContainer$1.invoke(HydraEmbeddedServletContainer.java:89)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:747)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1579)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:834)
theotherp commented 4 years ago

Please always attach the debug infos zip (as mentioned in the issues template).

theotherp commented 4 years ago

I assume the result that's being downloaded doesn't have a pubdate.

fbjerggaard commented 4 years ago

@theotherp The debug zip contains sensitive information I do not feel comfortable posted publicly on Github.

The file download fails with a HTTP 500 error. The age is shown correctly when doing a search against the affected indexer, so everything except downloading is working fine.

theotherp commented 4 years ago

You can upload the file to https://ufile.io/ and send me the link.

You're the first to report his problem and write that you use a custom-made indexer, so please understand that I'm a bit suspicious here...

Error 500 is a direct result of the NPE which is caused by either the pubdate or the age of the search result being empty. So if you say that the age is being shown correctly the pubdate must be empty. I'll take a closer look where that value should come from and how the age is calculated originally, but I still think the root cause lies in an unexpected indexer output. To determine that I'd need to see the XML output from the indexer that delivered that result. Then I can parse that and see if all values are filled correctly.

fbjerggaard commented 4 years ago

Hi,

Here is an example of an output from the indexer:

        <item>
            <newznab:attr name="language" value="English" />
            <newznab:attr name="category" value="5000" />
            <newznab:attr name="usenetdate" value="Sun, 27 Oct 2019 12:02:48 +00:00" />
            <newznab:attr name="guid" value="ashdhnsfdgjj77" />
            <newznab:attr name="size" value="11260142" />
            <category>HD / Series</category>
            <enclosure length="11260142" type="application/x-nzb" url="https://a.direct.link.to.nzb" />
            <guid isPermaLink="true">https://a.direct.link.to.nzb</guid>
            <link>https://a.direct.link.to.nzb</link>
            <pubDate>Sun, 27 Oct 2019 12:02:48 +00:00</pubDate>
            <title>nzb.title</title>
        </item>

That should conform to the basics of the newznab specification where pubDate isn't actually mentioned at all.

Searching for the same item in the interface reveals this result where the date is parsed correctly: image

I do understand your suspiciousness :) I'll see if I can get to upload the debug file from a clean test-install of nzbhydra later today so the logs won't be full of other stuff to make debugging harder.

theotherp commented 4 years ago

Please execute this SQL query in the debug section of NZBHydra: select title, pub_date, first_found from searchresult x where x.pub_date is null or x.first_found is null. This will log any search result of which a download will cause an error. Check with your indexer if the pubdate is not set for that result.

You linked the predefined newznab attributes but pubDate is mentioned in the "Important fields of the returned data (RSS)" section. That's where Hydra reads it from.

fbjerggaard commented 4 years ago

Thanks for the query. The problem was that nzbhydra2 had cached the results - which in itself is perfectly fine - before I had fixed the date to show in the correct format. A quick DELETE from searchresult x where x.pub_date is null or x.first_found is null fixed the issue and now the query returns 0 records instead of 10k+ :)

Closing here since it is irrelevant and the problem was on my side in the end.