search

lbehnke / h2database

Automatically exported from code.google.com/p/h2database
0 stars 0 forks source link

Restore Database with org.h2.tools.RunScript fails #96

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
Hello dear H2 Developer(s),

I got a problem to restore my big Database when I extracted the data with
the "SCRIPT TO 'zipfile'" command! For your information: When I use "SCRIPT
NODATA TO 'zipfile'" to produce the zip, it is no problem to create/load
the database! Ok, in this case there is not much data in the zip.

On the machine where I created the zip file, the following software is used ..
OS: SUSE Linux Enterprise Server 10 (s390x) PATCHLEVEL = 2
Java: IBM J9 VM (build 2.3, J2RE 1.5.0 IBM J9 2.3 Linux s390x-64
j9vmxz6423-20081129 (JIT enabled)
H2: V1.1.112

On the machine where I try to restore, the following software is used ..
OS: SUSE Linux Enterprise Server 11 (s390x) PATCHLEVEL = 0
Java: IBM J9 VM (build 2.4, J2RE 1.6.0 IBM J9 2.4 Linux s390x-64
jvmxz6460sr5-20090519_35743 (JIT enabled, AOT enabled)
H2: V1.1.115

Steps to reproduce the problem:
1. Take the scripted DB from URL:
http://www.swissbyte.com/systemdb_zuz00i-0003_20090709.zip (389MB)
2. Run the RunScript tool

Instead of running through without any messages it shows me the following
stack trace ..

f539438@CHVPMRV1VS0003:/opt/jane1> jre/bin/java -Xmx8024m -cp
master/lib/ns_runtime.jar org.h2.tools.RunScript -url
jdbc:h2:db/sysdb/systemdb -user sa -script
recovery/backup/systemdb_zuz00i-0003_20090709.zip -options compression zip
Exception in thread "main" org.h2.jdbc.JdbcSQLException: Syntax error in
SQL statement
INSERT INTO SYSTEMDB.APP_LOG(TASK_ID, DDNAME, SEQNR, TS, MSG) VALUES
(1599, 'APPLOG', 1310, 1228348657464, '[*]Processed now 8,260,000 Input
Data Object with speed 6,250 InputData/Sec'),
(1683, 'APPLOG', 109, 1228348657844, 'Processed now 1,660,452 Input records
with speed 6,667 InputRecord/Sec'),
(1679, 'APPLOG', 69, 1228348660413, 'Processed now 740,419 Input records
with speed 5,001 InputRecord/Sec'),
(1672, 'APPLOG', 295, 1228348660739, 'Processed now 2,943,470 Input records
with speed 1,176 InputRecord/Sec'),
(1683, 'APPLOG', 110, 1228348661649, 'Processed now 1,680,453 Input records
with speed 6,667 InputRecord/Sec'),
(1672, 'APPLOG', 296, 1228348662232, 'Processed now 1,260,000 Input Data
Object with speed 3,571 InputData/Sec'),
(1683, 'APPLOG', 111, 1228348664186, 'Processed now 240,000 Input Data
Object with speed 8,333 InputData/Sec'),
(1679, 'APPLOG', 70, 1228348664833, 'Inserted now 8,000,000 DB Data Object
with speed 5,617 DB Rows/Sec'),
(1683, 'APPLOG', 112, 1228348665042, 'Processed now 1,700,455 Input records
with speed 6,667 InputRecord/Sec'),
(1679, 'APPLOG', 71, 1228348665281, 'Processed now 760,420 Input records
with speed 5,000 InputRecord/Sec'),
(1599, 'APPLOG', 1311, 1228348665299, 'Processed now 8,270,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 113, 1228348669072, 'Processed now 1,720,458 Input records
with speed 5,000 InputRecord/Sec'),
(1597, 'APPLOG', 1438, 1228348669201, 'Processed now 9,460,000 Input Data
Object with speed 3,125 InputData/Sec'),
(1597, 'APPLOG', 1439, 1228348670292, 'Processed now 9,460,473 Input
records with speed 526 InputRecord/Sec'),
(1599, 'APPLOG', 1312, 1228348670383, 'Processed now 8,340,420 Input
records with speed 1,333 InputRecord/Sec'),
(1679, 'APPLOG', 72, 1228348671235, 'Processed now 780,431 Input records
with speed 4,002 InputRecord/Sec'),
(1683, 'APPLOG', 114, 1228348672034, 'Processed now 250,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 115, 1228348672036, 'Inserted now 1,000,000 DB Data Object
with speed 4,901 DB Rows/Sec'),
(1599, 'APPLOG', 1313, 1228348672264, 'Processed now 8,280,000 Input Data
Object with speed 8,333 InputData/Sec'),
(1683, 'APPLOG', 116, 1228348672542, 'Processed now 1,740,459 Input records
with speed 6,667 InputRecord/Sec'),
(1672, 'APPLOG', 297, 1228348675031, 'Processed now 1,270,000 Input Data
Object with speed 4,166 InputData/Sec'),
(1683, 'APPLOG', 117, 1228348676154, 'Processed now 1,760,467 Input records
with speed 6,669 InputRecord/Sec'),
(1672, 'APPLOG', 298, 1228348676276, 'Processed now 2,963,472 Input records
with speed 1,333 InputRecord/Sec'),
(1679, 'APPLOG', 73, 1228348677078, 'Processed now 800,458 Input records
with speed 4,005 InputRecord/Sec'),
(1679, 'APPLOG', 74, 1228348678368, 'Processed now 170,000 Input Data
Object with speed 1,388 InputData/Sec'),
(1683, 'APPLOG', 118, 1228348679152, 'Processed now 260,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 119, 1228348679759, 'Processed now 1,780,468 Input records
with speed 6,667 InputRecord/Sec'),
(1597, 'APPLOG', 1440, 1228348682917, 'Processed now 9,470,000 Input Data
Object with speed 3,846 InputData/Sec'),
(1683, 'APPLOG', 120, 1228348683584, 'Processed now 1,800,470 Input records
with speed 6,667 InputRecord/Sec'),
(1683, 'APPLOG', 121, 1228348686518, 'Processed now 270,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 122, 1228348687297, 'Processed now 1,820,476 Input records
with speed 6,668 InputRecord/Sec'),
(1679, 'APPLOG', 75, 1228348687361, 'Processed now 820,469 Input records
with speed 2,001 InputRecord/Sec'),
(1683, 'APPLOG', 123, 1228348689669, 'Processed now 1,840,480 Input records
with speed 10,002 InputRecord/Sec'),
(1672, 'APPLOG', 299, 1228348690172, 'Processed now 1,280,000 Input Data
Object with speed 3,333 InputData/Sec'),
(1672, 'APPLOG', 300, 1228348690750, 'Processed now 2,983,473 Input records
with speed 1,428 InputRecord/Sec'),
(1683, 'APPLOG', 124, 1228348692039, 'Processed now 1,860,486 Input records
with speed 10,003 InputRecord/Sec'); expected ); SQL statement:

INSERT INTO SYSTEMDB.APP_LOG(TASK_ID, DDNAME, SEQNR, TS, MSG) VALUES
(1599, 'APPLOG', 1310, 1228348657464, 'Processed now 8,260,000 Input Data
Object with speed 6,250 InputData/Sec'),
(1683, 'APPLOG', 109, 1228348657844, 'Processed now 1,660,452 Input records
with speed 6,667 InputRecord/Sec'),
(1679, 'APPLOG', 69, 1228348660413, 'Processed now 740,419 Input records
with speed 5,001 InputRecord/Sec'),
(1672, 'APPLOG', 295, 1228348660739, 'Processed now 2,943,470 Input records
with speed 1,176 InputRecord/Sec'),
(1683, 'APPLOG', 110, 1228348661649, 'Processed now 1,680,453 Input records
with speed 6,667 InputRecord/Sec'),
(1672, 'APPLOG', 296, 1228348662232, 'Processed now 1,260,000 Input Data
Object with speed 3,571 InputData/Sec'),
(1683, 'APPLOG', 111, 1228348664186, 'Processed now 240,000 Input Data
Object with speed 8,333 InputData/Sec'),
(1679, 'APPLOG', 70, 1228348664833, 'Inserted now 8,000,000 DB Data Object
with speed 5,617 DB Rows/Sec'),
(1683, 'APPLOG', 112, 1228348665042, 'Processed now 1,700,455 Input records
with speed 6,667 InputRecord/Sec'),
(1679, 'APPLOG', 71, 1228348665281, 'Processed now 760,420 Input records
with speed 5,000 InputRecord/Sec'),
(1599, 'APPLOG', 1311, 1228348665299, 'Processed now 8,270,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 113, 1228348669072, 'Processed now 1,720,458 Input records
with speed 5,000 InputRecord/Sec'),
(1597, 'APPLOG', 1438, 1228348669201, 'Processed now 9,460,000 Input Data
Object with speed 3,125 InputData/Sec'),
(1597, 'APPLOG', 1439, 1228348670292, 'Processed now 9,460,473 Input
records with speed 526 InputRecord/Sec'),
(1599, 'APPLOG', 1312, 1228348670383, 'Processed now 8,340,420 Input
records with speed 1,333 InputRecord/Sec'),
(1679, 'APPLOG', 72, 1228348671235, 'Processed now 780,431 Input records
with speed 4,002 InputRecord/Sec'),
(1683, 'APPLOG', 114, 1228348672034, 'Processed now 250,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 115, 1228348672036, 'Inserted now 1,000,000 DB Data Object
with speed 4,901 DB Rows/Sec'),
(1599, 'APPLOG', 1313, 1228348672264, 'Processed now 8,280,000 Input Data
Object with speed 8,333 InputData/Sec'),
(1683, 'APPLOG', 116, 1228348672542, 'Processed now 1,740,459 Input records
with speed 6,667 InputRecord/Sec'),
(1672, 'APPLOG', 297, 1228348675031, 'Processed now 1,270,000 Input Data
Object with speed 4,166 InputData/Sec'),
(1683, 'APPLOG', 117, 1228348676154, 'Processed now 1,760,467 Input records
with speed 6,669 InputRecord/Sec'),
(1672, 'APPLOG', 298, 1228348676276, 'Processed now 2,963,472 Input records
with speed 1,333 InputRecord/Sec'),
(1679, 'APPLOG', 73, 1228348677078, 'Processed now 800,458 Input records
with speed 4,005 InputRecord/Sec'),
(1679, 'APPLOG', 74, 1228348678368, 'Processed now 170,000 Input Data
Object with speed 1,388 InputData/Sec'),
(1683, 'APPLOG', 118, 1228348679152, 'Processed now 260,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 119, 1228348679759, 'Processed now 1,780,468 Input records
with speed 6,667 InputRecord/Sec'),
(1597, 'APPLOG', 1440, 1228348682917, 'Processed now 9,470,000 Input Data
Object with speed 3,846 InputData/Sec'),
(1683, 'APPLOG', 120, 1228348683584, 'Processed now 1,800,470 Input records
with speed 6,667 InputRecord/Sec'),
(1683, 'APPLOG', 121, 1228348686518, 'Processed now 270,000 Input Data
Object with speed 7,142 InputData/Sec'),
(1683, 'APPLOG', 122, 1228348687297, 'Processed now 1,820,476 Input records
with speed 6,668 InputRecord/Sec'),
(1679, 'APPLOG', 75, 1228348687361, 'Processed now 820,469 Input records
with speed 2,001 InputRecord/Sec'),
(1683, 'APPLOG', 123, 1228348689669, 'Processed now 1,840,480 Input records
with speed 10,002 InputRecord/Sec'),
(1672, 'APPLOG', 299, 1228348690172, 'Processed now 1,280,000 Input Data
Object with speed 3,333 InputData/Sec'),
(1672, 'APPLOG', 300, 1228348690750, 'Processed now 2,983,473 Input records
with speed 1,428 InputRecord/Sec'),
(1683, 'APPLOG', 124, 1228348692039, 'Processed now 1,860,486 Input records
with speed 10,003 InputRecord/Sec') [42001-115]
        at org.h2.message.Message.getSQLException(Message.java:105)
        at org.h2.message.Message.getSQLException(Message.java:116)
        at org.h2.message.Message.getSyntaxError(Message.java:141)
        at org.h2.command.Parser.read(Parser.java:2521)
        at org.h2.command.Parser.readIfMore(Parser.java:762)
        at org.h2.command.Parser.parseInsert(Parser.java:904)
        at org.h2.command.Parser.parsePrepared(Parser.java:368)
        at org.h2.command.Parser.parse(Parser.java:290)
        at org.h2.command.Parser.parse(Parser.java:262)
        at org.h2.command.Parser.prepare(Parser.java:204)
        at org.h2.engine.Session.prepare(Session.java:394)
        at org.h2.engine.Session.prepare(Session.java:381)
        at
org.h2.command.dml.RunScriptCommand.execute(RunScriptCommand.java:60)
        at org.h2.command.dml.RunScriptCommand.update(RunScriptCommand.java:46)
        at org.h2.command.CommandContainer.update(CommandContainer.java:72)
        at org.h2.command.Command.executeUpdate(Command.java:208)
        at org.h2.jdbc.JdbcStatement.execute(JdbcStatement.java:158)
        at org.h2.tools.RunScript.processRunscript(RunScript.java:273)
        at org.h2.tools.RunScript.run(RunScript.java:138)
        at org.h2.tools.RunScript.main(RunScript.java:68)

This "[*]Processed..." in one of the first lines of the output is not
stored in this way within the data! Where does it come from?

Workaround? No
Problem importance? Important
Defect or feature request? Defect

Check my workflow in the attached 'h2-error.txt' file. Thanks in advance
for a quick solution.

Regards, Kilian

Original issue reported on code.google.com by kilian.f...@gmail.com on 10 Jul 2009 at 7:41

Attachments:

GoogleCodeExporter commented 9 years ago 
Hi,

The [*] is added to the place where the syntax error occurred. It's weird, 
because
there is no syntax error: I successfully ran this part of the script. I could 
also
ran the rest of the script without problems. I don't have the IBM JVM however, 
I use
Mac OS X and a Sun JVM (1.5).

I used the H2 Console (with -Xmx1024m) and ran:

-- setting to speed up import (reset afterwards)
set log 0;
set cache_size 32*1024;
set lock_mode 0;
set undo_log 0;
set write_delay 5000;
set throttle 1; -- don't use 100% CPU
runscript from '~/Downloads/systemdb_zuz00i-0003_20090709.zip' compression zip;
-- should now reset the settings

Import took 48 min
5.97 GB data file
4.72 GB index file

Original comment by thomas.t...@gmail.com on 10 Jul 2009 at 6:52

GoogleCodeExporter commented 9 years ago 
Hi Thomas,

it really seems to be a problem with the IBM JVM. I tried to load the data on 
other
machines with different Sun JVM's (v1.5, v1.6) and different H2 versions 
(v1.0.78,
v1.1.115) and there was no problem at all.

One more question: I don't use the H2 Console. Is it possible to supply this 
setting
parameters as 'set log 0' or 'set undo_log 0' to the RunScript tool?

Regards, Kilian Felder

Original comment by kilian.f...@gmail.com on 14 Jul 2009 at 5:25

GoogleCodeExporter commented 9 years ago 
Hi,

> parameters as 'set log 0' or 'set undo_log 0' to the RunScript tool?

Yes, any settings can be passed in the database URL:

jdbc:h2:~/test;log=0;undo_log=0

Original comment by thomas.t...@gmail.com on 17 Jul 2009 at 4:39

GoogleCodeExporter commented 9 years ago 
Please tell me if you know more
(is it really a bug of the IBM VM, how did you work around the problem).

Original comment by thomas.t...@gmail.com on 18 Jul 2009 at 9:57

GoogleCodeExporter commented 9 years ago 
Hi Thomas,

Your comment 3: Thanks for the info. I had to mask the semicolon on the command 
line,
otherwise I received an error. Command is successful with:
jdbc:h2:~/test\;log=0\;undo_log=0

Your comment 4: I don't know exactly if it's a bug of the IBM VM but: IBM VM 5 
and 6
are not yet tested on zLinux (s390x) with SLES 11 installed (see
http://www.ibm.com/developerworks/java/jdk/linux/tested.html and check for 
'System z
64-bit'). My workaround to restore the DB on this zLinux system: I took IBM VM 
4 and
therefore a lower H2 release. And it worked ..
OS: SUSE Linux Enterprise Server 11 (s390x) PATCHLEVEL = 0
Java: Classic VM (build 1.4.2, J2RE 1.4.2 IBM build cxz64142-20080923 (SR12) 
(JIT
enabled: jitc))
H2: V1.1.113

Regards,
Kilian Felder

Original comment by kilian.f...@gmail.com on 20 Jul 2009 at 10:59

GoogleCodeExporter commented 9 years ago 
> I had to mask the semicolon on the command line, otherwise I received an 
error.

What error message and stack trace did you get?
Is the database URL in a properties file? 

Java 1.4 is no longer supported by Sun, that's why I thought H2 doesn't need to
support it... It is still possible to create a jar file for Java 1.4 by using
Retrotranslator (http://retrotranslator.sourceforge.net/).

Original comment by thomas.t...@gmail.com on 21 Jul 2009 at 3:23

GoogleCodeExporter commented 9 years ago 
Command and appropriate stack trace ...

% /opt/ibm/java-i386-60/jre/bin/java -Xmx1024m -cp
/opt/jane1/master/lib/h2-1.1.115.jar org.h2.tools.RunScript -url
jdbc:h2:/disk2/kfe/db/sysdb/systemdb;log=0;undo_log=0 -user sa -script 
systemdb.zip
-options compression zip
Exception in thread "main" org.h2.jdbc.JdbcSQLException: IO Exception:
java.io.FileNotFoundException: backup.sql (No such file or directory); 
backup.sql
[90031-115]
        at org.h2.message.Message.getSQLException(Message.java:105)
        at org.h2.message.Message.convertIOException(Message.java:295)
        at org.h2.tools.RunScript.process(RunScript.java:317)
        at org.h2.tools.RunScript.run(RunScript.java:140)
        at org.h2.tools.RunScript.main(RunScript.java:68)
Caused by: java.io.FileNotFoundException: backup.sql (No such file or directory)
        at java.io.FileInputStream.<init>(FileInputStream.java:112)
        at java.io.FileInputStream.<init>(FileInputStream.java:72)
        at org.h2.store.fs.FileSystemDisk.openFileInputStream(FileSystemDisk.java:362)
        at org.h2.util.FileUtils.openFileInputStream(FileUtils.java:229)
        at org.h2.tools.RunScript.process(RunScript.java:182)
        at org.h2.tools.RunScript.process(RunScript.java:312)
        ... 2 more
-bash: -user: command not found

But this is the normal behavior when you use the Linux Command Line because the
semicolon is treated as the command delimiter. Therefore "log=0" and 
"undo_log=0 ..."
are treated as separate commands. No problem for me. Only good to know.

Regards,
Kilian Felder

P.S. Thanks for the hint with the Retrotranslator!

Original comment by kilian.f...@gmail.com on 21 Jul 2009 at 7:14

GoogleCodeExporter commented 9 years ago 
Hi,

I didn't know about that... I will change the documentation of the various 
tools that
support an URL to -url "<url>" - I hope that's saver. Thanks for your help!

Regards,
Thomas

Original comment by thomas.t...@gmail.com on 31 Jul 2009 at 6:48