Exception rrd store when trying to override the data file about docker-neo4j

[willis7]

Not sure if my error is exactly the same, but I seemed to narrow mine down to the addition of a volume.

Starting Neo4j Server console-mode...
Using additional JVM arguments:  -server -XX:+DisableExplicitGC -Dorg.neo4j.server.properties=conf/neo4j-server.properties -Djava.util.logging.config.file=conf/logging.properties -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:-OmitStackTraceInFastThrow -XX:hashCode=5 -Dneo4j.ext.udc.source=docker
2015-10-14 19:49:54.358+0000 INFO  [API] Setting startup timeout to: 120000ms based on 120000
2015-10-14 19:49:58.497+0000 INFO  [API] Successfully started database
2015-10-14 19:49:58.567+0000 ERROR [API] Unable to open rrd store, attempting to recreate it
java.io.IOException: Invalid file header. File [/data/graph.db/rrd] is not a RRD4J RRD file
    at org.rrd4j.core.Header.validateHeader(Header.java:208) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:214) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:184) ~[rrd4j-2.2.jar:na]
    at org.neo4j.server.rrd.RrdFactory.validateStepSize(RrdFactory.java:245) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:168) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
2015-10-14 19:49:58.581+0000 ERROR [API] Unable to create new rrd store
java.io.IOException: Invalid argument
    at sun.nio.ch.FileChannelImpl.map0(Native Method) ~[na:1.8.0_66-internal]
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:925) ~[na:1.8.0_66-internal]
    at org.rrd4j.core.RrdNioBackend.mapFile(RrdNioBackend.java:63) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdNioBackend.setLength(RrdNioBackend.java:86) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:148) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:101) ~[rrd4j-2.2.jar:na]
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:200) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.recreateArchive(RrdFactory.java:265) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:184) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
2015-10-14 19:49:58.583+0000 INFO  [API] Successfully shutdown Neo4j Server.
2015-10-14 19:49:58.817+0000 INFO  [API] Successfully stopped database
2015-10-14 19:49:58.819+0000 ERROR [API] Failed to start Neo Server on port [7474]
org.neo4j.server.ServerStartupException: Starting Neo4j Server failed: java.io.IOException: Invalid argument
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:258) ~[neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
Caused by: java.lang.RuntimeException: java.io.IOException: Invalid argument
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:205) ~[neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.recreateArchive(RrdFactory.java:265) ~[neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:184) ~[neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) ~[neo4j-server-2.2.5.jar:2.2.5]
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) ~[neo4j-server-2.2.5.jar:2.2.5]
    ... 2 common frames omitted
Caused by: java.io.IOException: Invalid argument
    at sun.nio.ch.FileChannelImpl.map0(Native Method) ~[na:1.8.0_66-internal]
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:925) ~[na:1.8.0_66-internal]
    at org.rrd4j.core.RrdNioBackend.mapFile(RrdNioBackend.java:63) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdNioBackend.setLength(RrdNioBackend.java:86) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:148) ~[rrd4j-2.2.jar:na]
    at org.rrd4j.core.RrdDb.<init>(RrdDb.java:101) ~[rrd4j-2.2.jar:na]
    at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:200) ~[neo4j-server-2.2.5.jar:2.2.5]
    ... 6 common frames omitted

I am using Docker Compose :

db:
  image: neo4j/neo4j
  ports:
   - "7474:7474"
  environment:
    NEO4J_AUTH: none
  volumes:
   - $PWD/build/neo4j-data:/data
web:
  build: .
  links:
   - db
  ports:
   - "8000:8000"

as soon as I remove the volume it works.

[benbc]

@mfkilgore I am still struggling to reproduce this.

Can you confirm that the database is not running after you see that error?
Can you tell me what your VirtualBox version is?
Are you doing anything to expose the volume from within the VirtualBox VM (e.g. shared folders)?

[benbc]

@willis7 Can you tell me what versions of docker-machine, docker, VirtualBox and OSX you are using, please?

[willis7]

@benbc

Docker version 1.8.2, build 0a8c2e3
docker-compose version: 1.4.0
docker-machine version 0.4.1 (e2c88d6)
VB v: 5.0.4
OSX: El Capitan

I hope this helps

[mfkilgore]

@benbc
VB is Version 5.0.6 r103037
Yes, the database is shut down here is more of the log file from yesterday -

015-10-14 15:50:46.438+0000 INFO [o.n.s.d.LifecycleManagingDatabase]: Successfully started database
2015-10-14 15:50:46.443+0000 INFO [o.n.k.i.DiagnosticsManager]: --- SERVER STARTED START ---
2015-10-14 15:50:46.503+0000 ERROR [o.n.s.r.RrdFactory]: Unable to open rrd store, attempting to recreate it
java.io.IOException: Invalid file header. File [/data/graph.db/rrd] is not a RRD4J RRD file
at org.rrd4j.core.Header.validateHeader(Header.java:208) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:214) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:184) ~[rrd4j-2.2.jar:na]
at org.neo4j.server.rrd.RrdFactory.validateStepSize(RrdFactory.java:245) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:168) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
2015-10-14 15:50:46.505+0000 ERROR [o.n.s.r.RrdFactory]: current RRDB is invalid, renamed it to /var/lib/neo4j/data/graph.db/rrd-invalid-1444837846504
2015-10-14 15:50:46.566+0000 ERROR [o.n.s.r.RrdFactory]: Unable to create new rrd store
java.io.IOException: Invalid argument
at sun.nio.ch.FileChannelImpl.map0(Native Method) ~[na:1.8.0_66-internal]
at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:925) ~[na:1.8.0_66-internal]
at org.rrd4j.core.RrdNioBackend.mapFile(RrdNioBackend.java:63) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdNioBackend.setLength(RrdNioBackend.java:86) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:148) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:101) ~[rrd4j-2.2.jar:na]
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:200) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.recreateArchive(RrdFactory.java:265) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:184) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
2015-10-14 15:50:46.567+0000 INFO [o.n.s.CommunityNeoServer]: Successfully shutdown Neo4j Server.
2015-10-14 15:50:46.570+0000 INFO [o.n.k.EmbeddedGraphDatabase]: Shutdown started
2015-10-14 15:50:46.570+0000 INFO [o.n.k.EmbeddedGraphDatabase]: Database is now unavailable
2015-10-14 15:50:46.575+0000 DEBUG [o.n.k.EmbeddedGraphDatabase]: GC Monitor stopped.
2015-10-14 15:50:46.630+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.relationshiptypestore.db.names, truncating at 64 vs file size 64
2015-10-14 15:50:46.641+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.relationshiptypestore.db, truncating at 28 vs file size 28
2015-10-14 15:50:46.649+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.labeltokenstore.db.names, truncating at 64 vs file size 64
2015-10-14 15:50:46.664+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.labeltokenstore.db, truncating at 22 vs file size 22
2015-10-14 15:50:46.677+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.propertystore.db.strings, truncating at 154 vs file size 154
2015-10-14 15:50:46.687+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.propertystore.db.index.keys, truncating at 64 vs file size 64
2015-10-14 15:50:46.698+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.propertystore.db.index, truncating at 25 vs file size 25
2015-10-14 15:50:46.706+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.propertystore.db.arrays, truncating at 153 vs file size 153
2015-10-14 15:50:46.717+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.propertystore.db, truncating at 20 vs file size 20
2015-10-14 15:50:46.729+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.relationshipstore.db, truncating at 24 vs file size 24
2015-10-14 15:50:46.741+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.nodestore.db.labels, truncating at 93 vs file size 93
2015-10-14 15:50:46.751+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.nodestore.db, truncating at 16 vs file size 16
2015-10-14 15:50:46.760+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.schemastore.db, truncating at 82 vs file size 82
2015-10-14 15:50:46.766+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore.relationshipgroupstore.db, truncating at 54 vs file size 54
2015-10-14 15:50:46.780+0000 DEBUG [o.n.k.i.s.StoreFactory]: Closing /var/lib/neo4j/data/graph.db/neostore, truncating at 114 vs file size 8190
2015-10-14 15:50:46.788+0000 INFO [o.n.k.NeoStoreDataSource]: NeoStore closed
2015-10-14 15:50:46.790+0000 INFO [o.n.k.i.DiagnosticsManager]: --- STOPPING diagnostics START ---
2015-10-14 15:50:46.792+0000 INFO [o.n.k.i.DiagnosticsManager]: --- STOPPING diagnostics END ---
2015-10-14 15:50:46.800+0000 INFO [o.n.s.d.LifecycleManagingDatabase]: Successfully stopped database
2015-10-14 15:50:46.804+0000 ERROR [o.n.s.CommunityBootstrapper]: Failed to start Neo Server on port [7474]
org.neo4j.server.ServerStartupException: Starting Neo4j Server failed: java.io.IOException: Invalid argument
at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:258) ~[neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.5.jar:2.2.5]
Caused by: java.lang.RuntimeException: java.io.IOException: Invalid argument
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:205) ~[neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.recreateArchive(RrdFactory.java:265) ~[neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:184) ~[neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.rrd.RrdFactory.createRrdDbAndSampler(RrdFactory.java:95) ~[neo4j-server-2.2.5.jar:2.2.5]
at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:216) ~[neo4j-server-2.2.5.jar:2.2.5]
... 2 common frames omitted
Caused by: java.io.IOException: Invalid argument
at sun.nio.ch.FileChannelImpl.map0(Native Method) ~[na:1.8.0_66-internal]
at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:925) ~[na:1.8.0_66-internal]
at org.rrd4j.core.RrdNioBackend.mapFile(RrdNioBackend.java:63) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdNioBackend.setLength(RrdNioBackend.java:86) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:148) ~[rrd4j-2.2.jar:na]
at org.rrd4j.core.RrdDb.(RrdDb.java:101) ~[rrd4j-2.2.jar:na]
at org.neo4j.server.rrd.RrdFactory.createRrdb(RrdFactory.java:200) ~[neo4j-server-2.2.5.jar:2.2.5]
... 6 common frames omitted

[mfkilgore]

@benbc And to complete the answer, no except for the use of VB as part of Docker Toolbox, I am not accessing VB for any other purpose, nothing exposed or shared.

[mfkilgore]

@benbc As a follow up, I removed docker and VB from my machine and reinstalled Docker Toolbox again. Versions are the same and with the exception of seeing that 2.2.6 is now latest, the results are still the same.

[benbc]

@mfkilgore @willis7 Although I still haven't managed to reproduce this, I believe that the underlying problem is fixed in the new Neo4j milestone release. Could you please try neo4j/neo4j:2.3.0-RC1?

[mfkilgore]

@benbc confirming here that the 2.3.0-RC1 addressed the problem. Still interesting that you could not reproduce it with 2.2.5 or 2.2.6, but glad to have it resolved going forward.

[benbc]

@mfkilgore Thanks. My suspicion is that it's a precise versioning thing. I am still using OSX 10.9. I was going to start going round the office trying it on other people's machines when I learnt that the underlying cause has been removed for 2.3.0.

[jexp]

Afaik it is only fixed b/c webadmin is disabled if it is enabled again it will break again

[benbc]

@jexp Yes, that's right. Although it is only the RRD component that is disabled, not the whole of webadmin. I think it's reasonable to say that RRD is not supported in Docker. The previous workaround of putting the RRD file outside /data was unsatisfactory because it means the container writes to one of the image layers, which are intended to be read-only.

[jexp]

Actually in RC the whole was

I don't get your point with the instance aufs? Many processes within the container write to it, it's throwaway, thats the whole point of isolation :)

[benbc]

@mfkilgore @willis7 Since the problematic component is disabled by default in the official Neo4j image, I'm going to close this issue. Please reopen if you see the problem again.