Recover of unresolved transactions failed.

[fork]

Evidently windows crashed on me with a blue screen of death at the worst possible time. It tries to recover the unresolved transactions but fails with a message "Wrong version in log. Expected 753, but got 754". What does the message "Wrong version in log. Expected 753, but got 754" mean. Is my database corrupted beyond any possible hope of recovery?

org.neo4j.graphdb.TransactionFailureException: Recovery failed.

at org.neo4j.kernel.impl.transaction.TxManager.recover(TxManager.java:371)

at org.neo4j.kernel.impl.transaction.TxManager.init(TxManager.java:185)

at org.neo4j.kernel.impl.transaction.TxModule.start(TxModule.java:96)

at org.neo4j.kernel.GraphDbInstance.start(GraphDbInstance.java:161)

at org.neo4j.kernel.EmbeddedGraphDbImpl.<init>(EmbeddedGraphDbImpl.java:189)

at org.neo4j.kernel.EmbeddedGraphDatabase.<init>(EmbeddedGraphDatabase.java:79)

at org.neo4j.kernel.EmbeddedGraphDatabase.<init>(EmbeddedGraphDatabase.java:63)

at chess.db.gen.server.Database.<init>(Database.java:44)

at chess.db.gen.server.InitServletContextListener.contextInitialized(InitServletContextListener.java:25)

at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:543)

at org.mortbay.jetty.servlet.Context.startContext(Context.java:136)

at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1220)

at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:513)

at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:448)

at com.google.gwt.dev.shell.jetty.JettyLauncher$WebAppContextWithReload.doStart(JettyLauncher.java:468)

at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:39)

at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)

at org.mortbay.jetty.handler.RequestLogHandler.doStart(RequestLogHandler.java:115)

at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:39)

at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)

at org.mortbay.jetty.Server.doStart(Server.java:222)

at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:39)

at com.google.gwt.dev.shell.jetty.JettyLauncher.start(JettyLauncher.java:672)

at com.google.gwt.dev.DevMode.doStartUpServer(DevMode.java:509)

at com.google.gwt.dev.DevModeBase.startUp(DevModeBase.java:1068)

at com.google.gwt.dev.DevModeBase.run(DevModeBase.java:811)

at com.google.gwt.dev.DevMode.main(DevMode.java:311)

Caused by: java.io.IOException: Wrong version in log. Expected 753, but got 754

at org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.readAndAssertLogHeader(XaLogicalLog.java:721)

at org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.rotate(XaLogicalLog.java:1374)

at org.neo4j.kernel.impl.transaction.xaframework.LogBackedXaDataSource.rotateLogicalLog(LogBackedXaDataSource.java:96)

at org.neo4j.kernel.impl.transaction.TxManager.recover(TxManager.java:366)

... 26 more

[Tobias Lindaaker]

Could you please provide a bit more information:

 * Which version of Neo4j did you get this exception with? (from the stacktrace it looks like you are running Neo4j 1.4, is that correct?)

 * Which version of Neo4j was used to create the database?

 * Which other versions of Neo4j have you upgraded through with this datastore?

If you could provide us with messages.log from the database dir it would contain the answers to the questions above as well as some more information that would help diagnosing the issue. It would be great if you could send that to us. The mailing list might filter attachments, or you might not want to publish that log in public since it contains classpath information and other things you might consider private, in that case you could send the file directly to me.

Cheers,

Tobias

--
Tobias Lindaaker <tobias.l...@neotechnology.com>
Hacker, Neo Technology
www.neotechnology.com
Cellphone: +46 706 534857 (Swe); +1 650 450 3806 (US)

[fork]

I am indeed running Neo4j 1.4 and the database was created with 1.4 as well. I sent an email to you with messages.log attached.

[Peter Neubauer]

Hi there,
if you just remove the logical logs and start up again, are things
working then? The db should start then, but make a copy before you do
to be sure and maybe keep it is a tarpit.

Cheers,

/peter neubauer

Google:    neubauer.peter
Skype:     peter.neubauer
Phone:     +46 704 106975
LinkedIn:  http://www.linkedin.com/in/neubauer
Twitter:    @peterneubauer
Tungle:    tungle.me/peterneubauer

brew install neo4j && neo4j start
heroku addons:add neo4j

[fork]

Which files exactly are the logical logs?

And even if the database starts up seemingly fine how do I know the database is in a consistent? Couldn't there be transactions partially written to disk requiring an undo or a redo?

[fork]

Would it be possible to look at the logs of the uncommited transactions (after finding out the binary format of the logs) so that I can make a list of the uncommited transactions. Then create a copy of the database where the logs are deleted so that I can start up the database without a TransactionFailureException message so that I can inspect the database to find out which uncommited transactions among the list just mentioned have been written to the database and which have not been written to the database or only partially written. And based off this write some code that will fix the parts of the database that are only partially written and hope that this process doesn't miss anything else that would leave the database inconsistent.

[Mattias Persson]

The logs to delete in this particular case would be (one of those two should exist):

  nioneo_logical.log.1
  nioneo_logical.log.2

To view the binary logical log format in text form, although not exactly all that useful for the end user, is to do something like:

  java -cp "my-neo4j-installation/lib/*" org.neo4j.kernel.impl.util.DumpLogicalLog my/db/

Since you have done recovery on these logs before your database should be in a consistent state already.

2012/1/21 fork <cch...@gmail.com>

Would it be possible to look at the logs of the uncommited transactions (after finding out the binary format of the logs) so that I can make a list of the uncommited transactions. Then create a copy of the database where the logs are deleted so that I can start up the database without a TransactionFailureException message so that I can inspect the database to find out which uncommited transactions among the list just mentioned have been written to the database and which have not been written to the database or only partially written. And based off this write some code that will fix the parts of the database that are only partially written and hope that this process doesn't miss anything else that would leave the database inconsistent.

--
Mattias Persson, [mat...@neotechnology.com]
Hacker, Neo Technology
www.neotechnology.com

[fork]

Mattias, I tried deleting

nioneo_logical.log.1

nioneo_logical.log.2

but then the database raised an IllegalStateException:

Caused by: java.lang.IllegalStateException: Active marked as 1 but no dragon\nioneo_logical.log.1 exist

at org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.open(XaLogicalLog.java:175)

at org.neo4j.kernel.impl.transaction.xaframework.XaContainer.openLogicalLog(XaContainer.java:97)

at org.neo4j.kernel.impl.nioneo.xa.NeoStoreXaDataSource.<init>(NeoStoreXaDataSource.java:141)

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)

at java.lang.reflect.Constructor.newInstance(Unknown Source)

at org.neo4j.kernel.impl.transaction.XaDataSourceManager.create(XaDataSourceManager.java:75)

at org.neo4j.kernel.impl.transaction.TxModule.registerDataSource(TxModule.java:147)

... 24 more

So then I tried to also delete nioneo_logical.log.active

but this caused it to revert back to giving the exception

Caused by: java.io.IOException: Wrong version in log. Expected 786, but got 787

at org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.readAndAssertLogHeader(XaLogicalLog.java:721)

at org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.rotate(XaLogicalLog.java:1374)

at org.neo4j.kernel.impl.transaction.xaframework.LogBackedXaDataSource.rotateLogicalLog(LogBackedXaDataSource.java:96)

at org.neo4j.kernel.impl.transaction.TxManager.recover(TxManager.java:366)

... 26 more

After deleting nioneo_logical.log.1 and nioneo_logical.log.2 is there a way to make the database completely ignore their absense and start up without an exception?

[Mattias Persson]

That sounds really strange and I've got no clue at the moment about why it happened. Is everything else intact?

2012/2/14 Cary Cherng <cch...@gmail.com>

Thanks for the tool. Unfortunately, I encountered a new problem.

I changed  nioneo_logical_log.1 to set the log version to 753 from 754 like you suggested.

After that, on startup the database gave a new error which I tracked to the lucene index. It was the same kind of error so I had to change  index/lucene.log.1 to set the log version to 786 from 787.

Before starting up the database again I checked that the directory index/lucene/node/positions/

contained 4.5 gigabytes of data across 40 files. But the very act of starting up the database deleted everything in that directory leaving only 6 kilobytes among the three files

index/lucene/node/positions/segments.gen

index/lucene/node/positions/segments_zf

index/lucene/node/positions/write.lock

Thankfully I made a backup of the database before trying these changes. Any clue as to why all the files in the directory index/lucene/node/positions/ were deleted on starting up the database?

On Mon, Feb 13, 2012 at 10:57 PM, Mattias Persson <mat...@neotechnology.com> wrote:

In that case it's probably better to change the version in the logical log. I quickly wrote a tool to do that: http://pastebin.com/iiPMSPFA , use it like:

  java -cp .... org.neo4j.ChangeLogVersion my/db/nioneo_logical_log.1

to just have it display which version that log is set to have, or:

  java -cp .... org.neo4j.ChangeLogVersion my/db/nioneo_logical_log.1 753

to set it to a specific version. If the exception message said "Wrong version in log. Expected 753, but got 754" then that means that the log version is 754 but it's expected to be 753, so set the log version to 753. The code is written, compiled and tested against the exact same version that you're running (1.4.M06). After this is done, if it succeeds, it would be wise to move to a more recent version... perhaps 1.5.2 or 1.6. And please do a backup before running this tool.

2012/2/14 Cary Cherng <cch...@gmail.com>

Since data is stored in binary format in  neostore is there some tool I can use to view it and maybe edit it?

On Fri, Feb 10, 2012 at 1:27 AM, Mattias Persson <mat...@neotechnology.com> wrote:

Thanks, oh and I forgot: could you send messages.log also?

2012/2/10 Cary Cherng <cch...@gmail.com>

I have attached log.tar.gz which has files

  neostore

  nioneo_logical.log1

  nioneo_logical.log2

If I go about editing  neostore, what bytes do I need to change? What is the binary format of  neostore?

On Thu, Feb 9, 2012 at 11:25 PM, Mattias Persson <mat...@neotechnology.com> wrote:

I'm guessing it could be solved by editing the neostore file which carries, among other things, next expected log version. But before doing that could you perhaps send me all these files:

  nioneo_logical.log*
  neostore

in a .tar.gz or something?

2012/2/9 Cary Cherng <cch...@gmail.com>

I have the db but I don't think there is an easy way to send it to you. It's 5 gigabytes in size.

Using the command "DumpLogicalLog" that you told me about seemed to indicate that there were no unresolved transactions. However, when I start up the database it complains about "wrong version in log".

This suggests that although the transactions have been resolved, the metadata that keeps track of what is the current log version is out of sync with the version number in the logs and all that is needed is to delete the db's reference to a log version. If there is an easy way to get the db to forget about the log version to expect, perhaps by editing some file or deleting some file, I could heuristically test the db after that to see if everything is fine.

On Thu, Feb 9, 2012 at 2:39 AM, Mattias Persson <mat...@neotechnology.com> wrote:

This is an interesting case, do you still have the db lying around and able to send it to me somehow (dropbox or something)?

2012/2/7 Cary Cherng <cch...@gmail.com>

Mattias, do you know an answer to this problem?

[Cary Cherng]

I did some more investigating and found out that it is not the starting up of the database that deletes the files. By stepping through the code in debug mode I found that the following code causes the 4.5 gigabytes to disappear

Node node = positionIndex.get("position", position.toString()).getSingle();

Notice that this is a "get" call on an index. How would a get call cause the 4.5 gigabytes to disappear? Normally one would think of a "get" method call as purely reading without any writes.

[Cary Cherng]

On a second thought. Could it be that changing the log version on

index/lucene.log.1 

caused the lucene index to think that there is no index and thus caused it to create a new lucene index thus erasing everything that is already there.

[Mattias Persson]

Since you're in debug mode, could you perhaps step further into the code and see what happens in LuceneDataSource#getIndexWriter for example?

2012/2/14 Cary Cherng <cch...@gmail.com>

[Cary Cherng]

Right now I only have the jars like neo4j-lucene-index-1.4.M06.jar but not their cooresponding source code. How would I identify the cooresponding old source code and obtain it so that I could make stepping through the code possible?

[Cary Cherng]

I was able to figure out where to get the source code for:

neo4j-lucene-index-1.4.M06

lucene-core-3.1.0

And I started stepping through the code for getIndexWriter as you suggested.

LuceneDataSource.getIndexWriter (creates IndexWriter on line 588)

IndexWriter constructor (creates IndexFileDeleter on line 1155)

IndexFileDeleter constructor (calls deleteFile on line 242)

 

Stepping through the code for the constructor of IndexFileDeleter I think the problem is that it never calls incRef and therefore the refcount is 0 for all the files and this causes deleteFile to be called for each file on line 242.

From what little I can infer from the code it looks like deleteFile is being called because the files

segments_zf

segments.gen

contain purely zero filled bytes as I found out by opening them with a hex editor.

Presumably there is suppose to be some data in those files? Maybe you have some insight as to what is going on?

[Mattias Persson]

If you can send your messages.log file after such a recovery failure it would be great.

2012/2/21 Penny E <pe...@socialforce.com>

I'm having a similar problem.  After the graph is closed down
ungracefully, recovery often (but not always) fails with messages
similar to those shown below.  Is there any progress on this?  How can
I complete the recovery?

gremlin> neo = new Neo4jGraph("graph-output")
Feb 21, 2012 1:49:14 PM
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog
doInternalRecovery
INFO: Non clean shutdown detected on log [graph-output/
nioneo_logical.log.2]. Recovery started ...
Feb 21, 2012 1:49:16 PM
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog
doInternalRecovery
INFO: Non clean shutdown detected on log [/Users/pespinoza/Documents/
git/neo4j_import/graph-output/index/lucene.log.2]. Recovery
started ...
Feb 21, 2012 1:49:17 PM org.neo4j.kernel.impl.transaction.TxManager
init
INFO: Unresolved transactions found, recovery started ...
No mapping found for branchId[0x162374]
Display stack trace? [yN] y
org.neo4j.graphdb.TransactionFailureException: No mapping found for
branchId[0x162374]
       at
org.neo4j.kernel.impl.transaction.XaDataSourceManager.getXaResource(XaDataSourceManager.java:
189)
       at
org.neo4j.kernel.impl.transaction.TxManager.getXaResource(TxManager.java:
1037)
       at
org.neo4j.kernel.impl.transaction.TxManager.buildRecoveryInfo(TxManager.java:
515)
       at org.neo4j.kernel.impl.transaction.TxManager.recover(TxManager.java:
322)
       at org.neo4j.kernel.impl.transaction.TxManager.init(TxManager.java:
203)
       at org.neo4j.kernel.impl.transaction.TxModule.start(TxModule.java:
101)
       at org.neo4j.kernel.GraphDbInstance.start(GraphDbInstance.java:155)
       at
org.neo4j.kernel.EmbeddedGraphDbImpl.<init>(EmbeddedGraphDbImpl.java:
190)
       at
org.neo4j.kernel.EmbeddedGraphDatabase.<init>(EmbeddedGraphDatabase.java:
80)
       at
org.neo4j.kernel.EmbeddedGraphDatabase.<init>(EmbeddedGraphDatabase.java:
64)
       at
com.tinkerpop.blueprints.pgm.impls.neo4j.Neo4jGraph.<init>(Neo4jGraph.java:
94)
       at
com.tinkerpop.blueprints.pgm.impls.neo4j.Neo4jGraph.<init>(Neo4jGraph.java:
67)
       at
com.tinkerpop.blueprints.pgm.impls.neo4j.Neo4jGraph.<init>(Neo4jGraph.java:
63)
       at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
       at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:
39)
       at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:
27)
       at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
       at
org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:
77)
       at org.codehaus.groovy.runtime.callsite.ConstructorSite
$ConstructorSiteNoUnwrapNoCoerce.callConstructor(ConstructorSite.java:
102)
       at
org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:
54)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:
182)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:
190)
       at groovysh_evaluate.run(groovysh_evaluate:32)
       at groovysh_evaluate$run.call(Unknown Source)
       at
org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:
42)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
108)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
112)
       at
org.codehaus.groovy.tools.shell.Interpreter.evaluate(Interpreter.groovy:
67)
       at org.codehaus.groovy.tools.shell.Interpreter$evaluate.call(Unknown
Source)
       at
org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:
42)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
108)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
116)
       at org.codehaus.groovy.tools.shell.Groovysh.execute(Groovysh.groovy:
152)
       at org.codehaus.groovy.tools.shell.Shell.leftShift(Shell.groovy:114)
       at org.codehaus.groovy.tools.shell.Shell$leftShift$0.call(Unknown
Source)
       at
org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:
42)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
108)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:
116)
       at
org.codehaus.groovy.tools.shell.ShellRunner.work(ShellRunner.groovy:
88)
       at org.codehaus.groovy.tools.shell.InteractiveShellRunner.super
$2$work(InteractiveShellRunner.groovy)
       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
39)
       at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:
25)
       at java.lang.reflect.Method.invoke(Method.java:597)
       at
org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:
90)
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1054)
       at
org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuperN(ScriptBytecodeAdapter.java:
128)
       at
org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuper0(ScriptBytecodeAdapter.java:
148)
       at
org.codehaus.groovy.tools.shell.InteractiveShellRunner.work(InteractiveShellRunner.groovy:
100)
       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
39)
       at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:
25)
       at java.lang.reflect.Method.invoke(Method.java:597)
       at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite
$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:
267)
       at
org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.callCurrent(PogoMetaMethodSite.java:
52)
       at
org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:
46)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:
133)
       at
org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:
137)
       at org.codehaus.groovy.tools.shell.ShellRunner.run(ShellRunner.groovy:
57)
       at org.codehaus.groovy.tools.shell.InteractiveShellRunner.super
$2$run(InteractiveShellRunner.groovy)
       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
39)
       at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:
25)
       at java.lang.reflect.Method.invoke(Method.java:597)
       at
org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:
90)
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1054)
       at
org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuperN(ScriptBytecodeAdapter.java:
128)
       at
org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuper0(ScriptBytecodeAdapter.java:
148)
       at
org.codehaus.groovy.tools.shell.InteractiveShellRunner.run(InteractiveShellRunner.groovy:
66)
       at com.tinkerpop.gremlin.groovy.console.Console.<init>(Console.java:
50)
       at com.tinkerpop.gremlin.groovy.console.Console.<init>(Console.java:
57)
       at com.tinkerpop.gremlin.groovy.console.Console.main(Console.java:62)

On Jan 26, 2:46 pm, fork <cche...@gmail.com> wrote:
> Mattias, I tried deleting
>
> nioneo_logical.log.1
> nioneo_logical.log.2
>
> but then the database raised an IllegalStateException:
>
> Caused by: java.lang.IllegalStateException: Active marked as 1 but no
> dragon\nioneo_logical.log.1 exist
> at
> org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.open(XaLogicalLo g.java:175)
> at
> org.neo4j.kernel.impl.transaction.xaframework.XaContainer.openLogicalLog(Xa Container.java:97)
> at

> org.neo4j.kernel.impl.nioneo.xa.NeoStoreXaDataSource.<init>(NeoStoreXaDataS ource.java:141)

> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
> at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
> at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
> at java.lang.reflect.Constructor.newInstance(Unknown Source)
> at

> org.neo4j.kernel.impl.transaction.XaDataSourceManager.create(XaDataSourceMa nager.java:75)

> at
> org.neo4j.kernel.impl.transaction.TxModule.registerDataSource(TxModule.java :147)
> ... 24 more
>
> So then I tried to also delete nioneo_logical.log.active
>
> but this caused it to revert back to giving the exception
>
> Caused by: java.io.IOException: Wrong version in log. Expected 786, but got
> 787
> at
> org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.readAndAssertLog Header(XaLogicalLog.java:721)
> at
> org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.rotate(XaLogical Log.java:1374)
> at

> org.neo4j.kernel.impl.transaction.xaframework.LogBackedXaDataSource.rotateL ogicalLog(LogBackedXaDataSource.java:96)

[penny]

Here's the relevant lines from messages.log

2012-02-22 11:00:44.398-0800: failed-recovery-graph/neostore non clean
shutdown detected
2012-02-22 11:00:44.420-0800: failed-recovery-graph/
neostore.relationshiptypestore.db non clean shutdown detected
2012-02-22 11:00:44.422-0800: failed-recovery-graph/
neostore.relationshiptypestore.db.names non clean shutdown detected
2012-02-22 11:00:44.433-0800: failed-recovery-graph/
neostore.propertystore.db non clean shutdown detected
2012-02-22 11:00:44.435-0800: failed-recovery-graph/
neostore.propertystore.db.strings non clean shutdown detected
2012-02-22 11:00:44.437-0800: failed-recovery-graph/
neostore.propertystore.db.index non clean shutdown detected
2012-02-22 11:00:44.438-0800: failed-recovery-graph/
neostore.propertystore.db.index.keys non clean shutdown detected
2012-02-22 11:00:44.440-0800: failed-recovery-graph/
neostore.propertystore.db.arrays non clean shutdown detected
2012-02-22 11:00:44.443-0800: failed-recovery-graph/
neostore.relationshipstore.db non clean shutdown detected
2012-02-22 11:00:44.445-0800: failed-recovery-graph/
neostore.nodestore.db non clean shutdown detected
2012-02-22 11:00:44.464-0800: Non clean shutdown detected on log
[failed-recovery-graph/nioneo_logical.log.1]. Recovery started ...
2012-02-22 11:00:44.468-0800: [failed-recovery-graph/
nioneo_logical.log.1] logVersion=1 with committed tx=19
2012-02-22 11:00:44.468-0800: [failed-recovery-graph/
nioneo_logical.log.1] entries found=0 lastEntryPos=16
2012-02-22 11:00:44.469-0800: Internal recovery completed, scanned 0
log entries. Recovered 0 transactions. Last tx recovered: -1
2012-02-22 11:00:44.469-0800: XaResourceManager[failed-recovery-graph/
nioneo_logical.log] sorting 0 xids
2012-02-22 11:00:44.469-0800: XaResourceManager[failed-recovery-graph/
nioneo_logical.log] checkRecoveryComplete 0 xids
2012-02-22 11:00:44.473-0800: failed-recovery-graph/
neostore.relationshiptypestore.db.names rebuild id generator,
highId=15 defragged count=0
2012-02-22 11:00:44.477-0800: failed-recovery-graph/
neostore.propertystore.db.index.keys rebuild id generator, highId=6
defragged count=0
2012-02-22 11:00:44.498-0800: failed-recovery-graph/
neostore.propertystore.db.index rebuild id generator, highId=5
defragged count=0
2012-02-22 11:00:44.528-0800: failed-recovery-graph/
neostore.propertystore.db.strings rebuild id generator, highId=17044
defragged count=0
2012-02-22 11:00:44.530-0800: failed-recovery-graph/
neostore.propertystore.db.arrays rebuild id generator, highId=1
defragged count=0
2012-02-22 11:00:44.761-0800: failed-recovery-graph/
neostore.propertystore.db rebuild id generator, highId=10705 defragged
count=0
2012-02-22 11:00:44.870-0800: failed-recovery-graph/
neostore.relationshipstore.db rebuild id generator, highId=10425
defragged count=0
2012-02-22 11:00:44.875-0800: failed-recovery-graph/
neostore.nodestore.db rebuild id generator, highId=3395 defragged
count=0
2012-02-22 11:00:44.877-0800: failed-recovery-graph/neostore rebuild
id generator, highId=6 defragged count=0
2012-02-22 11:00:44.879-0800: XaResourceManager[failed-recovery-graph/
nioneo_logical.log] recovery completed.
2012-02-22 11:00:44.879-0800: Recovery on log [failed-recovery-graph/
nioneo_logical.log.1] completed.
2012-02-22 11:00:44.914-0800: Non clean shutdown detected on log [.../
failed-recovery-graph/index/lucene.log.2]. Recovery started ...
2012-02-22 11:00:44.914-0800: [.../failed-recovery-graph/index/
lucene.log.2] logVersion=1 with committed tx=8
2012-02-22 11:00:45.210-0800: Failed to load index provider lucene
Could not create data source lucene-index[lucene-index]
org.neo4j.graphdb.TransactionFailureException: Could not create data
source lucene-index[lucene-index]
at
org.neo4j.kernel.impl.transaction.TxModule.registerDataSource(TxModule.java:
186)
at
org.neo4j.index.impl.lucene.LuceneIndexImplementation.<init>(LuceneIndexImplementation.java:
70)
at
org.neo4j.index.lucene.LuceneIndexProvider.load(LuceneIndexProvider.java:
37)
at
org.neo4j.kernel.KernelData.loadIndexImplementations(KernelData.java:
146)
at org.neo4j.kernel.EmbeddedGraphDbImpl
$2.initializeIndexProviders(EmbeddedGraphDbImpl.java:180)
at org.neo4j.kernel.GraphDbInstance.start(GraphDbInstance.java:153)

Caused by: java.lang.reflect.InvocationTargetException

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:
39)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:
27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at

org.neo4j.kernel.impl.transaction.XaDataSourceManager.create(XaDataSourceManager.java:
77)
at
org.neo4j.kernel.impl.transaction.TxModule.registerDataSource(TxModule.java:
180)
... 72 more
Caused by: java.lang.RuntimeException:
org.apache.lucene.index.CorruptIndexException: unrecognized format -3
in file "_0.fnm"
at
org.neo4j.index.impl.lucene.LuceneDataSource.getIndexWriter(LuceneDataSource.java:
606)
at
org.neo4j.index.impl.lucene.CommitContext.ensureWriterInstantiated(CommitContext.java:
59)
at org.neo4j.index.impl.lucene.LuceneCommand
$RemoveCommand.perform(LuceneCommand.java:247)
at
org.neo4j.index.impl.lucene.LuceneTransaction.doCommit(LuceneTransaction.java:
259)
at
org.neo4j.kernel.impl.transaction.xaframework.XaTransaction.commit(XaTransaction.java:
319)
at
org.neo4j.kernel.impl.transaction.xaframework.XaResourceManager.injectTwoPhaseCommit(XaResourceManager.java:
380)
at
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.applyTwoPhaseCommitEntry(XaLogicalLog.java:
563)
at
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.applyEntry(XaLogicalLog.java:
439)
at
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.doInternalRecovery(XaLogicalLog.java:
803)
at
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.open(XaLogicalLog.java:
242)
at
org.neo4j.kernel.impl.transaction.xaframework.XaLogicalLog.open(XaLogicalLog.java:
212)
at
org.neo4j.kernel.impl.transaction.xaframework.XaContainer.openLogicalLog(XaContainer.java:
116)
at
org.neo4j.index.impl.lucene.LuceneDataSource.<init>(LuceneDataSource.java:
219)
... 78 more
Caused by: org.apache.lucene.index.CorruptIndexException: unrecognized
format -3 in file "_0.fnm"
at org.apache.lucene.index.FieldInfos.read(FieldInfos.java:349)
at org.apache.lucene.index.FieldInfos.<init>(FieldInfos.java:71)
at org.apache.lucene.index.IndexWriter.getFieldInfos(IndexWriter.java:
1197)
at
org.apache.lucene.index.IndexWriter.getCurrentFieldInfos(IndexWriter.java:
1213)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1149)
at
org.neo4j.index.impl.lucene.LuceneDataSource.getIndexWriter(LuceneDataSource.java:
593)
... 90 more
2012-02-22 11:00:45.213-0800: TM opening log: failed-recovery-graph/
tm_tx_log.1
2012-02-22 11:00:45.215-0800: TM non resolved transactions found in
failed-recovery-graph/tm_tx_log.1

On Feb 22, 12:42 am, Mattias Persson <matt...@neotechnology.com>
wrote:

> > org.codehaus.groovy.tools.shell.InteractiveShellRunner.run(InteractiveShell Runner.groovy:

> ...
>
> read more »

[Mattias Persson]

Thanks,

Have you opened your indexes with some other program, or even a more recent neo4j version?.... to then go back and try to read it with an older version? It would perhaps be possible for me to spot if you sent me the whole messages.log

Best,
Mattias

2012/2/22 penny <pe...@socialforce.com>

[penny]

On further investigation, this seems to be a version mismatch issue.
I was using the latest stable Neo4j (1.6) when loading the graph, but
Gremlin seems to be still using 1.5. My apologies for the
distraction.

> ...
>
> read more »

[Peter Neubauer]

Great thanks for getting back!

Cheers,

/peter neubauer

G:  neubauer.peter
S:  peter.neubauer
P:  +46 704 106975
L:   http://www.linkedin.com/in/neubauer
T:   @peterneubauer

Neo4j 1.6 released                 - dzone.com/6S4K
The Neo4j Heroku Challenge   - http://neo4j-challenge.herokuapp.com/