theotherp
commented
5 years ago I suggest you restore your database from an older backup file.
On Sat, 20 Apr 2019, 18:00 jalmansor, notifications@github.com wrote:
Running linuxserver.io's latest (2.5.5) image on a bare-metal Ubuntu 16.04 x86_64 host.
I've been seeing the following errors when the Old Search Results task runs every hour. Looking back at my logs it started after I updated from 2.3.19 to 2.3.21. I tried generating a bug report but got an error there, too. Please let me know what I can do to help troubleshoot this further.
The update looks like it didn't have any issues:
2019-03-31 14:32:17.716 INFO --- [ Thread-4] org.nzbhydra.NzbHydra : Shutting down 2019-03-31 14:32:17.733 INFO --- [ Thread-4] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated... 2019-03-31 14:32:17.737 INFO --- [ Thread-4] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed. 2019-03-31 14:32:32.359 INFO --- [ main] org.nzbhydra.NzbHydra : Starting NzbHydra on c5f7193b116b with PID 290 (/app/hydra2/lib/core-2.3.21-exec.jar started by abc in /app/hydra2) 2019-03-31 14:32:32.371 DEBUG --- [ main] org.nzbhydra.NzbHydra : Running with Spring Boot v2.1.2.RELEASE, Spring v5.1.4.RELEASE 2019-03-31 14:32:32.371 INFO --- [ main] org.nzbhydra.NzbHydra : The following profiles are active: default 2019-03-31 14:32:35.109 INFO --- [ main] org.nzbhydra.config.BaseConfig : Using data folder /config 2019-03-31 14:32:35.173 DEBUG --- [ main] org.nzbhydra.config.ConfigReaderWriter : CONFIG_READ_WRITE: Using temporary file /config/nzbhydra.yml.bak 2019-03-31 14:32:35.186 DEBUG --- [ main] org.nzbhydra.config.ConfigReaderWriter : CONFIG_READ_WRITE: Copying temporary file to /config/nzbhydra.yml 2019-03-31 14:32:35.208 INFO --- [ main] a.HydraGlobalMethodSecurityConfiguration : Enabling auth type FORM 2019-03-31 14:32:36.119 DEBUG --- [ main] o.n.a.HydraAnonymousAuthenticationFilter : Filter 'hydraAnonymousAuthenticationFilter' configured for use 2019-03-31 14:32:36.294 INFO --- [ main] o.f.c.internal.license.VersionPrinter : Flyway Community Edition 5.2.4 by Boxfuse 2019-03-31 14:32:36.298 INFO --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2019-03-31 14:32:37.609 INFO --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2019-03-31 14:32:37.615 INFO --- [ main] o.f.c.internal.database.DatabaseFactory : Database: jdbc:h2:file:/config/database/nzbhydra (H2 1.4) 2019-03-31 14:32:37.656 WARN --- [ main] o.f.c.internal.database.base.Database : Flyway upgrade recommended: H2 1.4.199 is newer than this version of Flyway and support has not been tested. 2019-03-31 14:32:37.808 INFO --- [ main] o.f.core.internal.command.DbValidate : Successfully validated 17 migrations (execution time 00:00.081s) 2019-03-31 14:32:37.830 INFO --- [ main] o.f.core.internal.command.DbMigrate : Current version of schema "PUBLIC": 1.18 2019-03-31 14:32:37.831 INFO --- [ main] o.f.core.internal.command.DbMigrate : Schema "PUBLIC" is up to date. No migration necessary. 2019-03-31 14:32:41.308 WARN --- [ main] org.nzbhydra.NzbHydra : Overwritten settings will be displayed with their original value in the config section of the GUI 2019-03-31 14:32:42.805 DEBUG --- [ main] org.nzbhydra.auth.SecurityConfig : Using packaged cacerts file 2019-03-31 14:32:43.155 INFO --- [ main] o.n.d.downloaders.DownloaderProvider : Loading downloaders 2019-03-31 14:32:43.156 INFO --- [ main] o.n.d.downloaders.DownloaderProvider : Initializing downloader NZBGet 2019-03-31 14:32:43.192 INFO --- [ main] o.n.d.downloaders.DownloaderProvider : Finished initializing active downloaders 2019-03-31 14:32:43.228 INFO --- [ main] o.n.searching.SearchModuleProvider : Loading indexers 2019-03-31 14:32:43.238 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer Binsearch 2019-03-31 14:32:43.281 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer NZBGeek 2019-03-31 14:32:43.313 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer NZBIndex 2019-03-31 14:32:43.314 DEBUG --- [ main] org.nzbhydra.indexers.NzbsOrg : Will limit queries to nzbs.org to 255 characters 2019-03-31 14:32:43.319 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer NZBs.org 2019-03-31 14:32:43.322 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer anizb 2019-03-31 14:32:43.327 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer nzb.su 2019-03-31 14:32:43.329 INFO --- [ main] o.n.searching.SearchModuleProvider : Initializing indexer omgwtfnzbs 2019-03-31 14:32:43.331 INFO --- [ main] o.n.searching.SearchModuleProvider : Finished initializing active indexers 2019-03-31 14:32:43.356 DEBUG --- [ main] o.n.downloading.DownloadStatusUpdater : DOWNLOAD_STATUS_UPDATE: Will not check for download statuses if last download was more than 360 minutes ago 2019-03-31 14:32:43.883 INFO --- [ main] org.nzbhydra.web.WebConfiguration : Found folder /static. Will load UI resources from there 2019-03-31 14:32:44.635 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Check for and install updates" to be run every 1 hour 2019-03-31 14:32:44.639 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Delete short term storage results" to be run every 12 hours 2019-03-31 14:32:44.640 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Delete old history entries" to be run every 1 hour 2019-03-31 14:32:44.641 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Download queue check" to be run every 10 seconds 2019-03-31 14:32:44.641 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Backup" to be run every 1 hour 2019-03-31 14:32:44.643 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Clean up indexer statuses" to be run every 1 minute 2019-03-31 14:32:44.644 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Download history check" to be run every 10 minutes 2019-03-31 14:32:44.645 INFO --- [ main] org.nzbhydra.tasks.HydraTaskScheduler : Scheduling task "Delete old search results" to be run every 1 hour 2019-03-31 14:32:44.719 INFO --- [ main] org.nzbhydra.NzbHydra : Started NzbHydra in 13.298 seconds (JVM running for 15.004) 2019-03-31 14:32:44.774 INFO --- [ main] org.nzbhydra.NzbHydra : You seem to be running NZBHydra 2 in docker. You can access Hydra using your local address and the IP you provided
but then whenever that one task runs:
2019-03-31 15:32:46.833 WARN --- [ HydraTask5] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 50200, SQLState: HYT00 2019-03-31 15:32:46.834 ERROR --- [ HydraTask5] o.h.engine.jdbc.spi.SqlExceptionHelper : Timeout trying to lock table {0}; SQL statement: delete from SEARCHRESULT where FIRST_FOUND < DATEADD('SECOND', ?, DATE '1970-01-01') AND ID not in (select SEARCH_RESULT_ID from INDEXERNZBDOWNLOAD where SEARCH_RESULT_ID is not null) [50200-199] 2019-03-31 15:32:46.844 ERROR --- [ HydraTask5] o.s.s.s.TaskUtils$LoggingErrorHandler : Unexpected error occurred in scheduled task.
javax.persistence.PessimisticLockException: could not execute statement at org.hibernate.internal.ExceptionConverterImpl.wrapLockException(ExceptionConverterImpl.java:273) at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:108) at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181) at org.hibernate.query.internal.AbstractProducedQuery.executeUpdate(AbstractProducedQuery.java:1604) at org.nzbhydra.searching.cleanup.OldResultsCleanup.deleteOldResults(OldResultsCleanup.java:56) at org.nzbhydra.searching.cleanup.OldResultsCleanup$$FastClassBySpringCGLIB$$cad1559f.invoke(
) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) at org.nzbhydra.searching.cleanup.OldResultsCleanup$$EnhancerBySpringCGLIB$$abe3a18f.deleteOldResults( ) 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:564) at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:93) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:844) Caused by: org.hibernate.PessimisticLockException: could not execute statement at org.hibernate.dialect.H2Dialect$3.convert(H2Dialect.java:353) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178) at org.hibernate.engine.query.spi.NativeSQLQueryPlan.performExecuteUpdate(NativeSQLQueryPlan.java:107) at org.hibernate.internal.SessionImpl.executeNativeUpdate(SessionImpl.java:1593) at org.hibernate.query.internal.NativeQueryImpl.doExecuteUpdate(NativeQueryImpl.java:292) at org.hibernate.query.internal.AbstractProducedQuery.executeUpdate(AbstractProducedQuery.java:1594) ... 23 common frames omitted Caused by: org.h2.jdbc.JdbcSQLTimeoutException: Timeout trying to lock table {0}; SQL statement: delete from SEARCHRESULT where FIRST_FOUND < DATEADD('SECOND', ?, DATE '1970-01-01') AND ID not in (select SEARCH_RESULT_ID from INDEXERNZBDOWNLOAD where SEARCH_RESULT_ID is not null) [50200-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:508) at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) at org.h2.message.DbException.get(DbException.java:194) at org.h2.command.Command.filterConcurrentUpdate(Command.java:333) at org.h2.command.Command.executeUpdate(Command.java:274) at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:200) at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:154) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175) ... 27 common frames omitted Caused by: org.h2.message.DbException: Row "-9222941034096215761" not found in primary index "PUBLIC.SEARCHRESULT_DATA" [90143-199] at org.h2.message.DbException.get(DbException.java:205) at org.h2.mvstore.db.MVPrimaryIndex.getRow(MVPrimaryIndex.java:274) at org.h2.mvstore.db.MVTable.getRow(MVTable.java:338) at org.h2.mvstore.db.MVSecondaryIndex$MVStoreCursor.get(MVSecondaryIndex.java:455) at org.h2.index.IndexCursor.get(IndexCursor.java:274) at org.h2.table.TableFilter.getValue(TableFilter.java:1092) at org.h2.expression.ExpressionColumn.getValue(ExpressionColumn.java:215) at org.h2.expression.condition.Comparison.getValue(Comparison.java:271) at org.h2.expression.condition.ConditionAndOr.getValue(ConditionAndOr.java:89) at org.h2.expression.Expression.getBooleanValue(Expression.java:259) at org.h2.command.dml.Delete.update(Delete.java:91) at org.h2.command.CommandContainer.update(CommandContainer.java:133) at org.h2.command.Command.executeUpdate(Command.java:267) ... 32 common frames omitted Caused by: org.h2.jdbc.JdbcSQLTransientException: Row "-9222941034096215761" not found in primary index "PUBLIC.SEARCHRESULT_DATA" [90143-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:621) at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) ... 45 common frames omitted — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/theotherp/nzbhydra2/issues/367, or mute the thread https://github.com/notifications/unsubscribe-auth/ADNUA6OZ33742D7H2ENK3ELPRM42LANCNFSM4HHJ5VSA .
emopinata
Running linuxserver.io's
latest(2.5.5) image on a bare-metal Ubuntu 16.04 x86_64 host.I've been seeing the following errors when the
Old Search Resultstask runs every hour. Looking back at my logs it started after I updated from2.3.19to2.3.21. I tried generating a bug report but got an error there, too. Please let me know what I can do to help troubleshoot this further.The update looks like it didn't have any issues:
but then whenever that one task runs: