Unable to open database
Closed this issue · 15 comments
Hi,
I cannot get superhighway84 to go thru the first run. This is what gets output:
2022/05/30 19:42:53 initializing logger ...
2022/05/30 19:42:53 initializing cache ...
2022/05/30 19:42:53 initializing TUI and loading database, please wait ...
2022/05/30 19:42:53 initializing database ...
2022/05/30 19:42:54 connecting database ...
2022/05/30 19:52:54 unable to open database: unable to fetch database manifest: failed to get block for bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4: context deadline exceeded
panic: unable to open database: unable to fetch database manifest: failed to get block for bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4: context deadline exceeded
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x1292fe7]
goroutine 1 [running]:
github.com/mrusme/superhighway84/database.(*Database).Disconnect(0xc00218d2c0)
/home/runner/work/superhighway84/superhighway84/database/database.go:224 +0x27
panic({0x13e68e0, 0xc004195c40})
/opt/hostedtoolcache/go/1.18.1/x64/src/runtime/panic.go:838 +0x207
log.Panicln({0xc0055ebf48?, 0xc002030e70?, 0x1832397?})
/opt/hostedtoolcache/go/1.18.1/x64/src/log/log.go:399 +0x65
main.main()
/home/runner/work/superhighway84/superhighway84/superhighway84.go:124 +0x8dd
The log file says:
2022-05-30T20:32:19.632+0200 DEBUG database/database.go:148 getting config root path ...
2022-05-30T20:32:19.634+0200 DEBUG database/database.go:154 setting up plugins ...
2022-05-30T20:32:19.634+0200 DEBUG database/database.go:159 creating IPFS node ...
2022-05-30T20:32:20.287+0200 INFO database/database.go:171 connecting to peers ...
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:124 connected! {"peerID": "QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"}
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:124 connected! {"peerID": "QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"}
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:124 connected! {"peerID": "QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"}
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:124 connected! {"peerID": "QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"}
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:124 connected! {"peerID": "QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"}
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:177 connected to peer!
2022-05-30T20:32:20.635+0200 INFO database/database.go:182 initializing database connection ...
2022-05-30T20:32:20.635+0200 DEBUG database/database.go:51 initializing NewOrbitDB ...
2022-05-30T20:32:20.706+0200 DEBUG database/database.go:79 initializing OrbitDB.Docs ...
2022-05-30T20:32:20.706+0200 DEBUG baseorbitdb/orbitdb.go:531 open orbitdb store {"address": "/orbitdb/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2022-05-30T20:32:20.707+0200 DEBUG baseorbitdb/orbitdb.go:553 Open database {"dbAddress": "/orbitdb/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2022-05-30T20:32:20.707+0200 DEBUG baseorbitdb/orbitdb.go:560 Look from {"directory": "/home/milan/.cache/superhighway84/database"}
2022-05-30T20:32:20.707+0200 DEBUG baseorbitdb/orbitdb.go:575 address '/orbitdb/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84' is valid
2022-05-30T20:32:20.707+0200 DEBUG cacheleveldown/leveldown.go:88 opening cache db {"path": "/home/milan/.cache/superhighway84/database/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2022-05-30T20:52:20.636+0200 ERROR database/database.go:186 %s {"error": "unable to open database: unable to fetch database manifest: failed to get block for bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4: context deadline exceeded", "errorVerbose": "failed to get block for bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4: context deadline exceeded\nunable to fetch database manifest\nberty.tech/go-orbit-db/baseorbitdb.(*orbitDB).Open\n\t/home/milan/go/pkg/mod/berty.tech/go-orbit-db@v1.17.1/baseorbitdb/orbitdb.go:597\nberty.tech/go-orbit-db.(*orbitDB).Docs\n\t/home/milan/go/pkg/mod/berty.tech/go-orbit-db@v1.17.1/orbitdb.go:143\ngithub.com/mrusme/superhighway84/database.(*Database).init\n\t/home/milan/work/superhighway84-0.2.0/database/database.go:80\ngithub.com/mrusme/superhighway84/database.(*Database).Connect\n\t/home/milan/work/superhighway84-0.2.0/database/database.go:184\nmain.main\n\t/home/milan/work/superhighway84-0.2.0/superhighway84.go:108\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:255\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1581\nunable to open database\nberty.tech/go-orbit-db.(*orbitDB).Docs\n\t/home/milan/go/pkg/mod/berty.tech/go-orbit-db@v1.17.1/orbitdb.go:145\ngithub.com/mrusme/superhighway84/database.(*Database).init\n\t/home/milan/work/superhighway84-0.2.0/database/database.go:80\ngithub.com/mrusme/superhighway84/database.(*Database).Connect\n\t/home/milan/work/superhighway84-0.2.0/database/database.go:184\nmain.main\n\t/home/milan/work/superhighway84-0.2.0/superhighway84.go:108\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:255\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1581"}
github.com/mrusme/superhighway84/database.(*Database).Connect
/home/milan/work/superhighway84-0.2.0/database/database.go:186
main.main
/home/milan/work/superhighway84-0.2.0/superhighway84.go:108
runtime.main
/usr/local/go/src/runtime/proc.go:255
The database LOG file in .cache says:
=============== May 30, 2022 (CEST) ===============
19:42:54.143405 log@legend F·NumFile S·FileSize N·Entry C·BadEntry B·BadBlock Ke·KeyError D·DroppedEntry L·Level Q·Se
qNum T·TimeElapsed
19:42:54.161259 db@open opening
19:42:54.161488 version@stat F·[] S·0B[] Sc·[]
19:42:54.168994 db@janitor F·2 G·0
19:42:54.169012 db@open done T·7.728795ms
This is version 0.2.0 and IPFS is 0.12.2 running on Ubuntu 20.04.4.
I ran ipfs init and accepted all the default values offered by superhighway84.
I've tried everything I could find without effect:
- Setting ulimit to 2048
- Setting net.core.rmem_max to 2500000
- Setting ipfs lowpower
- Also tried it on macOS
- Tried the previous version with older IPFS, also unsuccessful
- Tried compiled and prebuilt
- Tried increasing the timeouts in database.go from 600 to 1200
What else can I try? I would appreciate some hints.
Thnx.
Hey there, can you try starting it several more times and waiting for the context to timeout? I saw a similar issue before but it disappeared before I got to debug it. It might have to do with #46 which I'm currently investigating. You could try a Superhighway84 version < 0.2.0, since it was working flawlessly before the upgrade to IPFS 0.12.2.
Hi, thanks for the advice, I will run it several times and see what happens.
I did try v0.1.2 and it also panicked, but already at "initializing TUI and loading database" and much quicker.
Yeah ... I understand #46 is a priority. I hope you will tell us what you found after you crack it!
I ran version 0.2.0 about 10 times consecutively with the same results.
I then tried with 0.1.1 and it waits at:
TUI and loading database, please wait ...
I left that to work for 2 hours, without visible results, but it is doing tons of work in the background, not just hanging. I then restarted it after setting:
ipfs config profile apply lowpower
That might help, because I'm running it in a VM.
Hi,
I did a bit of debugging and it hangs in database.go at:
storetype := "docstore"
db.Store, err = db.OrbitDB.Docs(db.ctx, db.ConnectionString, &orbitdb.CreateDBOptions{
AccessController: ac,
StoreType: &storetype,
StoreSpecificOpts: documentstore.DefaultStoreOptsForMap("id"),
})
It never returns from that call.
Any idea why that could be?
@mp-netis could you check this issue and see if any of that helps?
It does not seem to be that issue.
- I did not modify go.mod
- I initialize the repo with the same version of IPFS as mentioned in go.mod
- IPFS otherwise works.
I do use go1.17.4 and not 1.17 ... but that should not be an issue.
Thank you for confirming. Can you try resetting the IPFS repo and deleting the cache? Here is how that works. I honestly don't know what else to suggest for now otherwise and will have to dig deeper into this.
Yet again, 0.2.0 has some issues in general in which the database doesn't seem to correctly sync anymore, which I'm currently investigating. Maybe that same issue is what prevents a fresh install from starting in first place.
Hi, I have been resetting repo, cache and config all the time. I now tried it all together again, with the prebuilt 0.1.1. and all the kernel settings ... unfortunately same behaviour.
We must be missing something very trivial. If it works from fresh for you and also @diyism, there must be something strange on my end.
@mp-netis v0.2.1 is building as I write this. Feel free to give it another try when it's published. It should support IPFS 0.12 and sync right away.
Hey @mrusme I'm having the same issue as @mp-netis . I am trying to runsh84 behind Docker though. This is my current Dockerfile:
FROM golang:latest AS superhighway84
RUN git clone https://github.com/mrusme/superhighway84.git
RUN cd superhighway84 && go build .
FROM ubuntu:latest
RUN apt-get -y update && apt-get install -y libssl-dev
COPY --from=ipfs/kubo:v0.16.0 /usr/local/bin/ipfs /usr/local/bin/ipfs
COPY --from=superhighway84 /go/superhighway84/superhighway84 /usr/local/bin/superhighway84
ENTRYPOINT sh -c "/usr/local/bin/ipfs init && /usr/local/bin/superhighway84"
Building and running docker as (I've tried without --net=host and --privileged as well):
docker build -t superhighway84 .
docker run -it --rm --privileged --net=host superhighway84
Any ideas?
Hey there, have you checked the SH84 log that's usually under ~/.cache/superhighway84.log? Can you share the output?
Thanks for the quick reply. That's the output:
2023-01-17T02:58:45.167Z DEBUG database/database.go:146 getting config root path ...
2023-01-17T02:58:45.167Z DEBUG database/database.go:152 setting up plugins ...
2023-01-17T02:58:45.171Z DEBUG database/database.go:157 creating IPFS node ...
2023-01-17T02:58:45.565Z INFO database/database.go:169 connecting to peers ...
2023-01-17T02:58:45.565Z DEBUG database/database.go:122 connected! {"peerID": "QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"}
2023-01-17T02:58:45.565Z DEBUG database/database.go:122 connected! {"peerID": "QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"}
2023-01-17T02:58:45.565Z DEBUG database/database.go:122 connected! {"peerID": "QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"}
2023-01-17T02:58:45.565Z DEBUG database/database.go:122 connected! {"peerID": "QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"}
2023-01-17T02:58:45.565Z DEBUG database/database.go:122 connected! {"peerID": "QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"}
2023-01-17T02:58:45.565Z DEBUG database/database.go:175 connected to peer!
2023-01-17T02:58:45.565Z INFO database/database.go:179 initializing database connection ...
2023-01-17T02:58:45.565Z DEBUG database/database.go:49 initializing NewOrbitDB ...
2023-01-17T02:58:45.636Z DEBUG database/database.go:77 initializing OrbitDB.Docs ...
2023-01-17T02:58:45.636Z DEBUG baseorbitdb/orbitdb.go:537 open orbitdb store {"address": "/orbitdb/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2023-01-17T02:58:45.636Z DEBUG baseorbitdb/orbitdb.go:559 Open database {"dbAddress": "/orbitdb/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2023-01-17T02:58:45.636Z DEBUG baseorbitdb/orbitdb.go:566 Look from {"directory": "/root/.cache/superhighway84/database"}
2023-01-17T02:58:45.636Z DEBUG cacheleveldown/leveldown.go:88 opening cache db {"path": "/root/.cache/superhighway84/database/bafyreifdpagppa7ve45odxuvudz5snbzcybwyfer777huckl4li4zbc5k4/superhighway84"}
2023-01-17T03:08:45.682Z ERROR database/database.go:183 %s {"error": "unable to open database: unable to fetch database manifest: context deadline exceeded"}
github.com/mrusme/superhighway84/database.(*Database).Connect
/go/superhighway84/database/database.go:183
main.main
/go/superhighway84/superhighway84.go:109
runtime.main
/usr/local/go/src/runtime/proc.go:250
Thanks, could you give the lowpower mode a try, as well as the RelayClient? Also make sure to -p 4001:4001 on your container as well as (ideally) on your router.
Thanks. I tried these but didn't help. I'm not sure if you were able to replicate using the Dockerfile. I tried on Ubuntu 22.04.
This is the first IPFS project I tried. I'll get more familiar with IPFS and see if I can find a solution for what's going on.
Haven't tried running it within a Docker container tbh. If you don't mind the effort, launch some micro VPS online and try launching it there. If it fails to connect on that as well there might indeed be an issue. So far I'd say though that it's simply not able to fetch the DB in time, before the context cancels. That could be due to it being unable to set up P2P connectivity.