Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Backup cause Internal Server Error - java.io.IOException: This archives contains unclosed entries. #964

Open
tatsuo98se opened this issue Nov 21, 2017 · 8 comments

Comments

@tatsuo98se
Copy link

tatsuo98se commented Nov 21, 2017

データベースのバックアップが失敗します。

ちなみに
knowledge_db.mv.dbは、14.27 GB
投稿数は140と、投稿数の割にデータ量が大きい感があります

動作環境は
OS X Yosemite (10.10.5)
Memory: 16GB
空き: 98.14GB

--- stack trace ---
javax.servlet.ServletException: javax.servlet.ServletException: org.support.project.common.exception.SystemException: 
	at org.support.project.web.filter.AuthenticationFilter.doFilter(AuthenticationFilter.java:300)
	at org.support.project.knowledge.listener.CloseAbleAuthenticationFilter.doFilter(CloseAbleAuthenticationFilter.java:98)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.knowledge.filter.ApiFilter.doFilter(ApiFilter.java:71)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.web.filter.LoggingFilter.doFilter(LoggingFilter.java:62)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.web.filter.SeqFilter.doFilter(SeqFilter.java:31)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.web.filter.EncodingFilter.doFilter(EncodingFilter.java:36)
	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:198)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
	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:1455)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)
Caused by: javax.servlet.ServletException: org.support.project.common.exception.SystemException: 
	at org.support.project.web.filter.ControlManagerFilter.doFilter(ControlManagerFilter.java:216)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.web.filter.MultipartFilter.doFilter(MultipartFilter.java:63)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.support.project.web.filter.AuthenticationFilter.doFilter(AuthenticationFilter.java:293)
	... 31 more
Caused by: org.support.project.common.exception.SystemException: 
	at org.support.project.common.util.ObjectUtils.invoke(ObjectUtils.java:136)
	at org.support.project.web.common.InvokeTarget.invoke(InvokeTarget.java:106)
	at org.support.project.web.filter.ControlManagerFilter.doInvoke(ControlManagerFilter.java:345)
	at org.support.project.web.filter.ControlFilter.invoke(ControlFilter.java:31)
	at org.support.project.web.filter.ControlManagerFilter.doFilter(ControlManagerFilter.java:184)
	... 37 more
Caused by: java.lang.reflect.InvocationTargetException
	at org.support.project.common.util.ObjectUtils.invoke(ObjectUtils.java:132)
	... 41 more
Caused by: java.io.IOException: This archive contains unclosed entries.
	at org.apache.commons.compress.archivers.zip.ZipArchiveOutputStream.finish(ZipArchiveOutputStream.java:438)
	at org.apache.commons.compress.archivers.zip.ZipArchiveOutputStream.close(ZipArchiveOutputStream.java:930)
	at org.support.project.knowledge.logic.DatabaseLogic.getData(DatabaseLogic.java:62)
	at org.support.project.knowledge.control.admin.DatabaseControl.backup(DatabaseControl.java:126)
	... 42 more
@koda-masaru
Copy link
Contributor

データサイズを見ると、何かおかしい気がしますね。
組み込みDB(H2Database)の私の使い方が悪い or H2側の不具合などがあるのかもしれません。

本稼働させる場合は、組み込みDBではなく、PostgreSQLに切り替えを推奨しています。
このまま組み込みDBで運用すると、データのクラッシュなどもありえるかもしれませんので、PostgreSQLへの切り替えをご検討ください。

PostgreSQLへの切り替えは以下の情報を参照願います。

https://service-knowledge.support-project.org/open.knowledge/view/45

@tatsuo98se
Copy link
Author

ご回答ありがとうございます。PostgreSQLへの移行作業を試してみたいと思います。
PostgresSQLへの移行に失敗した場合、元に戻すのは、.knowledge ディレクトリごと、
以前使用していたもの(h2)で上書きすれば良いという認識で良いでしょうか?

参考までに
以下は、こちらで試した事に関する追加情報です

org.h2.tools.Recover の実行結果

http://www.h2database.com/html/advanced.html#using_recover_tool

Version: 1.4.196 の場合

Exception in thread "main" java.lang.IllegalStateException: File corrupted in chunk 13901694, expected page length 4..192, got 821067778 [1.4.196/6]
	at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:765)
	at org.h2.mvstore.Page.read(Page.java:649)
	at org.h2.mvstore.Page.read(Page.java:195)
	at org.h2.mvstore.MVStore.readPage(MVStore.java:1952)
	at org.h2.mvstore.MVMap.readPage(MVMap.java:741)
	at org.h2.mvstore.Page.getChildPage(Page.java:217)
	at org.h2.mvstore.Cursor.fetchNext(Cursor.java:150)
	at org.h2.mvstore.Cursor.next(Cursor.java:50)
	at org.h2.mvstore.MVStore.loadChunkMeta(MVStore.java:695)
	at org.h2.mvstore.MVStore.readStoreHeader(MVStore.java:675)
	at org.h2.mvstore.MVStore.<init>(MVStore.java:358)
	at org.h2.mvstore.MVStore$Builder.open(MVStore.java:2930)
	at org.h2.mvstore.MVStoreTool.info(MVStoreTool.java:346)
	at org.h2.tools.Recover.process(Recover.java:346)
	at org.h2.tools.Recover.runTool(Recover.java:196)
	at org.h2.tools.Recover.main(Recover.java:159)

Ver.1.4.183 の場合 (${tomcat}/webapps/knowledge/WEB-INF/lib以下にあったもの)

  • knowledge_db.mv.txtが133GBを超えても実行が完了しない。

knowledge_db.mv.txtの中身

※1.4.183, 1.4.196両方同じ出力

tail knowledge_db.mv.txt

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

015cc8000 chunkHeader chunk:0,block:0,len:0,map:0,max:0,pages:0,root:0,time:0,version:0
ERROR illegal footer position -128

@tatsuo98se
Copy link
Author

PosgtgreSQLへの移行ですが、画面上はForbiddenエラーが発生し移行が完了できません。
(WindowsおよびDocker環境で試しました)
なお、同様の環境上で初期状態 + 数個の記事を作成したKnowledgeをPostgreSQLに移行する場合は成功します。

h2 databeseが起因の問題と思われ、関連するissueは以下ではないかと感じています
h2database/h2database#610
h2database/h2database#373

DataのExportは成功するので、現状Import機能頼み or h2 databaseの上記issueの対応頼みの状況です。

当面は、破損したDBのKnowledgeはReadOnlyの運用にして、別のKnowledgeを建てようかと思っています。

@tatsuo98se
Copy link
Author

1.10 -> 1.12 migration cause error below.

  • I tried migration on web menu twice. though I do not know what that reason, this log is looked like migrating 1.11 -> 1.12. but I saw a similar error when first try.
service database version: 1.11.1
latest database version: 1.12.1

	at org.support.project.ormapping.transaction.Transaction.invoke(Transaction.java:48)
	at org.support.project.aop.Intercepter.invoke(Intercepter.java:182)
	at org.support.project.knowledge.dao.KnowledgesDao_$$_jvst475_3.executeQueryList(KnowledgesDao_$$_jvst475_3.java)
	at org.support.project.knowledge.dao.gen.GenKnowledgesDao.selectAllWidthPager(GenKnowledgesDao.java:136)
	at org.support.project.knowledge.dao.KnowledgesDao_$$_jvst475_3._d50selectAllWidthPager(KnowledgesDao_$$_jvst475_3.java)
	at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.support.project.ormapping.transaction.Transaction.invoke(Transaction.java:48)
	at org.support.project.aop.Intercepter.invoke(Intercepter.java:174)
	at org.support.project.knowledge.dao.KnowledgesDao_$$_jvst475_3.selectAllWidthPager(KnowledgesDao_$$_jvst475_3.java)
	at org.support.project.knowledge.logic.AggregateLogic.doSetViewCountToKnowledge(AggregateLogic.java:460)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2._d18doSetViewCountToKnowledge(AggregateLogic_$$_jvst475_2.java)
	at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.support.project.ormapping.transaction.Transaction.invoke(Transaction.java:48)
	at org.support.project.aop.Intercepter.invoke(Intercepter.java:174)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2.doSetViewCountToKnowledge(AggregateLogic_$$_jvst475_2.java)
	at org.support.project.knowledge.logic.AggregateLogic.doSetViewCountToKnowledge(AggregateLogic.java:110)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2._d17doSetViewCountToKnowledge(AggregateLogic_$$_jvst475_2.java)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.support.project.ormapping.transaction.Transaction.invoke(Transaction.java:48)
	at org.support.project.aop.Intercepter.invoke(Intercepter.java:174)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2.doSetViewCountToKnowledge(AggregateLogic_$$_jvst475_2.java)
	at org.support.project.knowledge.logic.AggregateLogic.startAggregate(AggregateLogic.java:69)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2._d28startAggregate(AggregateLogic_$$_jvst475_2.java)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.support.project.aop.Intercepter.invoke(Intercepter.java:192)
	at org.support.project.knowledge.logic.AggregateLogic_$$_jvst475_2.startAggregate(AggregateLogic_$$_jvst475_2.java)
	at org.support.project.knowledge.deploy.v1_11_0.Migrate_1_11_2.doMigrate(Migrate_1_11_2.java:21)
	at org.support.project.knowledge.deploy.InitDB.doMigrate(InitDB.java:195)
	at org.support.project.knowledge.deploy.InitDB.start(InitDB.java:189)
	at org.support.project.knowledge.deploy.InitDB.main(InitDB.java:111)
Caused by: org.h2.jdbc.JdbcSQLException: 入出力例外: "java.io.IOException: org.h2.message.DbException: 入出力例外: ""java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]""
IO Exception: ""java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]"" [90028-196]"; "lob: null table: -3 id: 9198816"
IO Exception: "java.io.IOException: org.h2.message.DbException: 入出力例外: ""java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]""
IO Exception: ""java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]"" [90028-196]"; "lob: null table: -3 id: 9198816" [90031-196]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
	at org.h2.message.DbException.get(DbException.java:168)
	at org.h2.message.DbException.convertIOException(DbException.java:330)
	at org.h2.value.ValueLobDb.getString(ValueLobDb.java:296)
	at org.h2.jdbc.JdbcResultSet.getString(JdbcResultSet.java:314)
	at org.support.project.ormapping.common.ResultSetLoader.load(ResultSetLoader.java:104)
	... 62 more
Caused by: java.io.IOException: org.h2.message.DbException: 入出力例外: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]"
IO Exception: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]" [90028-196]
	at org.h2.message.DbException.convertToIOException(DbException.java:364)
	at org.h2.store.LobStorageRemoteInputStream.read(LobStorageRemoteInputStream.java:73)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
	at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
	at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
	at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
	at java.io.InputStreamReader.read(InputStreamReader.java:184)
	at java.io.BufferedReader.fill(BufferedReader.java:161)
	at java.io.BufferedReader.read1(BufferedReader.java:212)
	at java.io.BufferedReader.read(BufferedReader.java:286)
	at org.h2.util.IOUtils.copyAndCloseInput(IOUtils.java:216)
	at org.h2.util.IOUtils.readStringAndClose(IOUtils.java:323)
	at org.h2.value.ValueLobDb.getString(ValueLobDb.java:286)
	... 64 more
Caused by: org.h2.message.DbException: 入出力例外: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]"
IO Exception: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]" [90028-196]
	at org.h2.message.DbException.convert(DbException.java:283)
	at org.h2.engine.SessionRemote.done(SessionRemote.java:636)
	at org.h2.engine.SessionRemote.readLob(SessionRemote.java:786)
	at org.h2.store.LobStorageRemoteInputStream.read(LobStorageRemoteInputStream.java:71)
	... 76 more
Caused by: org.h2.jdbc.JdbcSQLException: 入出力例外: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]"
IO Exception: "java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]" [90028-196]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
	at org.h2.message.DbException.get(DbException.java:168)
	at org.h2.message.DbException.convert(DbException.java:287)
	at org.h2.server.TcpServerThread.sendError(TcpServerThread.java:220)
	at org.h2.server.TcpServerThread.run(TcpServerThread.java:160)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Block not found in id [1, -49, 2, -115, 102] [1.4.196/50]
	at org.h2.mvstore.StreamStore$Stream.read(StreamStore.java:515)
	at java.io.FilterInputStream.read(FilterInputStream.java:133)
	at org.h2.server.TcpServerThread$CachedInputStream.read(TcpServerThread.java:561)
	at org.h2.util.IOUtils.readFully(IOUtils.java:345)
	at org.h2.server.TcpServerThread.process(TcpServerThread.java:472)
	at org.h2.server.TcpServerThread.run(TcpServerThread.java:158)
	... 1 more
Caused by: java.lang.IllegalStateException: Block 13069 not found [1.4.196/50]
	at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:765)
	at org.h2.mvstore.StreamStore.getBlock(StreamStore.java:437)
	at org.h2.mvstore.StreamStore$Stream.nextBuffer(StreamStore.java:552)
	at org.h2.mvstore.StreamStore$Stream.read(StreamStore.java:509)
	... 6 more
	at org.h2.engine.SessionRemote.done(SessionRemote.java:629)
	... 78 more
Processing has been completed. [status]1

@koda-masaru
Copy link
Contributor

Thank you for your detailed information. I think that it problem from H2Database.
Again, I recommend that you switch to PostgreSQL instead of the embedded database if you want to run as stable.


詳細な情報をありがとうございます。組み込みDBに使っているH2Databaseに問題があるようですね。
H2Databaseのバージョンアップを検討しようとおもいます。
ただ、繰り返しますが、本番運用を安定して行うためにはPostgreSQLへの切り替えをお勧めします。

@tatsuo98se
Copy link
Author

Thank you for your reply.
Of course I understand that I should use postgreSQL as database.
But the most problem I'm facing is that I cannot migrate data on h2 to postgreSQL.

I want you to consider to develop below functions.

  • import function.
  • finish to migrate to postgres from h2 even though the system faced database error. then report error at last.

@koda-masaru
Copy link
Contributor

I will provide a feature to ignore errors during data migration to Postgres.
You can select the mode with a check box on data migration menu.
However, if you ignore the error, the data migration feature does not guarantee the migration of all data.
Can i satisfy your request?

@tatsuo98se
Copy link
Author

Thank you for your reply.

I will provide a feature to ignore errors during data migration to Postgres.
You can select the mode with a check box on data migration menu.
However, if you ignore the error, the data migration feature does not guarantee the migration of all data.
Can i satisfy your request?

Yes. I think it's enough to try next step to recover our knowledge.
If you could produce logs which note what data (or part of data) couldn't be migrated, I might be able to do something. (ex. announce which data is incomplete ,refill the data by hand).

Thank you very much again for your proposal.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants