krotik / eliasdb

EliasDB a graph-based database.
Mozilla Public License 2.0
994 stars 49 forks source link

Crashing the server while checking out the tutorial #39

Open oderwat opened 3 years ago

oderwat commented 3 years ago

When I run the tutorial and enter get line (instead of get Line) I get a list with 1 column of the "Line" keys.

When I then run get Line I don't get any result and the server shows a lot of panics with "Could not take ownership of lockfile db/mainLine.nodes: Could not write lockfile...".

I also wonder what get line would actually mean in that case?

krotik commented 3 years ago

Could you elaborate a bit on how I could reproduce this? If I run the tutorial on my machine and write get line I get an expected error message about the unknown node kind.

oderwat commented 3 years ago

WOW. Just look:

This is what I do:

$ git clone git@github.com:krotik/eliasdb.git
Klone nach 'eliasdb' ...
remote: Enumerating objects: 2597, done.
remote: Counting objects: 100% (606/606), done.
remote: Compressing objects: 100% (469/469), done.
remote: Total 2597 (delta 193), reused 408 (delta 125), pack-reused 1991
Empfange Objekte: 100% (2597/2597), 37.13 MiB | 5.88 MiB/s, fertig.
Löse Unterschiede auf: 100% (1337/1337), fertig.
$ cd eliasdb
$ make build-mac
rm -f eliasdb
go mod init || true
go: /Users/hara/devsys/workspace/go/eliasdb/go.mod already exists
go mod tidy
gofmt -l -w -s .
go vet ./...
GOOS=darwin GOARCH=amd64 go build -o eliasdb.mac cli/eliasdb.go
$ cp eliasdb.mac eliasdb
$ ./examples/tutorial/start.sh
2021/05/23 14:34:21 EliasDB 1.2.0
2021/05/23 14:34:21 Starting datastore in db
2021/05/23 14:34:21 Creating GraphManager instance
Importing from: ../res/tutorial_data.zip
Importing main.json to partition main
2021/05/23 14:34:23 Creating key (key.pem) and certificate (cert.pem) in: ssl
2021/05/23 14:34:24 Ensuring web folder: web
2021/05/23 14:34:24 Ensuring web terminal: web/db/term.html
2021/05/23 14:34:24 Starting HTTPS server on: 127.0.0.1:9090
2021/05/23 14:34:25 Writing fingerprint file: web/fingerprint.json
2021/05/23 14:34:25 Waiting for shutdown

Opening browser https://localhost:9090/db/term.hmtl. Entering get line clicking 'OK'.

image

Console says:

image

Terminal shows panic:

2021/05/23 15:42:56 http: TLS handshake error from [::1]:55013: remote error: tls: unknown certificate
2021/05/23 15:43:00 http: TLS handshake error from [::1]:55035: remote error: tls: unknown certificate
2021/05/23 15:43:06 http: panic serving [::1]:55036: Could not take ownership of lockfile db/mainline.nodes: Could not write lockfile - read result after writing: 1621777367075620000(expected: 1621777386105977000)<nil>
goroutine 130 [running]:
net/http.(*conn).serve.func1(0x140023d6000)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:1824 +0x108
panic(0x10129d480, 0x140002c4a90)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/runtime/panic.go:971 +0x3f4
github.com/krotik/eliasdb/storage.initByteDiskStorageManager(0x140016c3900, 0x14000d4cdc8, 0x2faf080)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:657 +0xd94
github.com/krotik/eliasdb/storage.NewByteDiskStorageManager(0x1400030ae40, 0x11, 0x0, 0x1012473f0)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:235 +0xcc
github.com/krotik/eliasdb/storage.NewDiskStorageManager(...)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:101
github.com/krotik/eliasdb/graph/graphstorage.(*DiskGraphStorage).StorageManager(0x14000546ea0, 0x14000d4cdb0, 0xe, 0x14000d4ca00, 0x4, 0x101139a90)
    /Users/hara/devsys/workspace/go/eliasdb/graph/graphstorage/diskgraphstorage.go:149 +0x148
github.com/krotik/eliasdb/graph.(*Manager).getNodeStorageHTree(0x14000525080, 0x1400357e2e1, 0x4, 0x14000d4cad4, 0x4, 0x14000538b00, 0x0, 0x0, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/graph/helpers.go:213 +0x2cc
github.com/krotik/eliasdb/graph.(*Manager).NodeKeyIterator(0x14000525080, 0x1400357e2e1, 0x4, 0x14000d4cad4, 0x4, 0x1, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/graph/graphmanager_nodes.go:47 +0x4c
github.com/krotik/eliasdb/eql/interpreter.(*getRuntime).Validate(0x140002d8010, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/eql/interpreter/get.go:89 +0xec
github.com/krotik/eliasdb/eql/interpreter.(*getRuntime).Eval(0x140002d8010, 0xa, 0x14000d4cad0, 0x8, 0x10137b338)
    /Users/hara/devsys/workspace/go/eliasdb/eql/interpreter/get.go:143 +0x84
github.com/krotik/eliasdb/eql.RunQueryWithNodeInfo(0x14000d4cb00, 0xa, 0x1400357e2e1, 0x4, 0x14000d4cad0, 0x8, 0x14000525080, 0x1013861d0, 0x14001822688, 0x140013fb970, ...)
    /Users/hara/devsys/workspace/go/eliasdb/eql/query.go:69 +0x31c
github.com/krotik/eliasdb/eql.RunQuery(0x14000d4cb00, 0xa, 0x1400357e2e1, 0x4, 0x14000d4cad0, 0x8, 0x14000525080, 0x101141dce, 0x10, 0x14001822601, ...)
    /Users/hara/devsys/workspace/go/eliasdb/eql/query.go:37 +0x90
github.com/krotik/eliasdb/api/v1.(*queryEndpoint).HandleGET(0x14001822680, 0x101386590, 0x14003436460, 0x140017ba800, 0x140002c47e0, 0x1, 0x1)
    /Users/hara/devsys/workspace/go/eliasdb/api/v1/query.go:133 +0x350
github.com/krotik/eliasdb/api.RegisterRestEndpoints.func1.1(0x101386590, 0x14003436460, 0x140017ba800)
    /Users/hara/devsys/workspace/go/eliasdb/api/rest.go:162 +0x198
net/http.HandlerFunc.ServeHTTP(0x14000534640, 0x101386590, 0x14003436460, 0x140017ba800)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2069 +0x40
net/http.(*ServeMux).ServeHTTP(0x1016a6780, 0x101386590, 0x14003436460, 0x140017ba800)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2448 +0x190
net/http.serverHandler.ServeHTTP(0x140034361c0, 0x101386590, 0x14003436460, 0x140017ba800)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2887 +0xbc
net/http.(*conn).serve(0x140023d6000, 0x101388440, 0x14000db7540)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:1952 +0x710
created by net/http.(*Server).Serve
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:3013 +0x308
2021/05/23 15:43:06 http: TLS handshake error from [::1]:55063: remote error: tls: unknown certificate
2021/05/23 15:43:07 http: panic serving [::1]:55064: Could not take ownership of lockfile db/mainline.nodes: Could not write lockfile - read result after writing: 1621777367075620000(expected: 1621777386635550000)<nil>
goroutine 135 [running]:
net/http.(*conn).serve.func1(0x140023d6780)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:1824 +0x108
panic(0x10129d480, 0x140001b8050)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/runtime/panic.go:971 +0x3f4
github.com/krotik/eliasdb/storage.initByteDiskStorageManager(0x140016c3a80, 0x14000d4dd40, 0x2faf080)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:657 +0xd94
github.com/krotik/eliasdb/storage.NewByteDiskStorageManager(0x1400030b170, 0x11, 0x0, 0x1012473f0)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:235 +0xcc
github.com/krotik/eliasdb/storage.NewDiskStorageManager(...)
    /Users/hara/devsys/workspace/go/eliasdb/storage/diskstoragemanager.go:101
github.com/krotik/eliasdb/graph/graphstorage.(*DiskGraphStorage).StorageManager(0x14000546ea0, 0x14000d4dd30, 0xe, 0x14000d4da00, 0x4, 0x101139a90)
    /Users/hara/devsys/workspace/go/eliasdb/graph/graphstorage/diskgraphstorage.go:149 +0x148
github.com/krotik/eliasdb/graph.(*Manager).getNodeStorageHTree(0x14000525080, 0x1400357e5e1, 0x4, 0x14000d4da84, 0x4, 0x14000538d00, 0x0, 0x0, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/graph/helpers.go:213 +0x2cc
github.com/krotik/eliasdb/graph.(*Manager).NodeKeyIterator(0x14000525080, 0x1400357e5e1, 0x4, 0x14000d4da84, 0x4, 0x1, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/graph/graphmanager_nodes.go:47 +0x4c
github.com/krotik/eliasdb/eql/interpreter.(*getRuntime).Validate(0x140002c4c40, 0x0, 0x0)
    /Users/hara/devsys/workspace/go/eliasdb/eql/interpreter/get.go:89 +0xec
github.com/krotik/eliasdb/eql/interpreter.(*getRuntime).Eval(0x140002c4c40, 0xa, 0x14000d4da80, 0x8, 0x10137b338)
    /Users/hara/devsys/workspace/go/eliasdb/eql/interpreter/get.go:143 +0x84
github.com/krotik/eliasdb/eql.RunQueryWithNodeInfo(0x14000d4da90, 0xa, 0x1400357e5e1, 0x4, 0x14000d4da80, 0x8, 0x14000525080, 0x1013861d0, 0x14001822778, 0x140007ed970, ...)
    /Users/hara/devsys/workspace/go/eliasdb/eql/query.go:69 +0x31c
github.com/krotik/eliasdb/eql.RunQuery(0x14000d4da90, 0xa, 0x1400357e5e1, 0x4, 0x14000d4da80, 0x8, 0x14000525080, 0x101141dce, 0x10, 0x14001822701, ...)
    /Users/hara/devsys/workspace/go/eliasdb/eql/query.go:37 +0x90
github.com/krotik/eliasdb/api/v1.(*queryEndpoint).HandleGET(0x14001822770, 0x101386590, 0x14003436620, 0x14000521f00, 0x140002c4b50, 0x1, 0x1)
    /Users/hara/devsys/workspace/go/eliasdb/api/v1/query.go:133 +0x350
github.com/krotik/eliasdb/api.RegisterRestEndpoints.func1.1(0x101386590, 0x14003436620, 0x14000521f00)
    /Users/hara/devsys/workspace/go/eliasdb/api/rest.go:162 +0x198
net/http.HandlerFunc.ServeHTTP(0x14000534640, 0x101386590, 0x14003436620, 0x14000521f00)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2069 +0x40
net/http.(*ServeMux).ServeHTTP(0x1016a6780, 0x101386590, 0x14003436620, 0x14000521f00)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2448 +0x190
net/http.serverHandler.ServeHTTP(0x140034361c0, 0x101386590, 0x14003436620, 0x14000521f00)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:2887 +0xbc
net/http.(*conn).serve(0x140023d6780, 0x101388440, 0x1400084ccc0)
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:1952 +0x710
created by net/http.(*Server).Serve
    /opt/homebrew/Cellar/go/1.16.3/libexec/src/net/http/server.go:3013 +0x308

When I then restart the Server and refresh the browser and enter get line again I get:

image

(no new output in terminal)

Entering get Line (instead) and clicking 'OK'.

Nothing appears in the browser. Console says:

image

Terminal now shows the same panic.

I have multiple Macs and this was done in my free time on my "Macbook Air M1" (Apple Silicone / ARM64 architecture). I realized that this way it was forcing an AMD64 build through the Makefile. So I changed the architecture in the Makefile to arm64 and rebuild it. Still does not work. Did a go build cli/eliasdb.go, also does not work.

So I got off the couch and went into the office to try it on an Intel Mac. There it works as expected. Was zum Teufel?

I even copied the one from the Intel Mac over to the Apple Silicon Mac. Also does not work as expected.

So it comes down to: The problem only appears on Macs with Apple Silicon. And that is most likely not your problem. It may also just be something that happens only on the Macbook Air M1. I can check that on Tuesday with a colleague who runs the Mac Mini M1. I may check later today what happens on a RasPi 4B, using Docker (your image, local image) using Parallels Debian.

Still, I wonder. What does it do? This only happens with get line. When I do get foo I get an error about that node not existing. Why does it show no result on the first try (when the zip got imported), but there is a result when I run the server again.

I also changed access rights for user processes and run It with sudo. Does not change anything.

oderwat commented 3 years ago

Running it inside Docker using your Image (krotik/eliasdb( on the Apple Silicon Mac works as expected ("EQL error in Main query: Unknown node kind (line) (Line:1 Pos:5)").

oderwat commented 3 years ago

Creating the Docker image locally also gives the expected result. So it may not be a Problem with Rosetta2 (Intel to Arm translation) at all. It seems to be related to something with "upper / lower" case. Maybe the output of get line with that one column result gives a hint what happens? Can I test (delve) something?

oderwat commented 3 years ago

Running on a RaspberryPi 4B also works as expected (wanted to try that because of the ARM target but that probably does not matter anyway). I even got Docker installed and could run the data mining example on the RaspberryPi 4B.