Badger: ARMv7 segmentation fault in oracle.readTs when calling loadUint64

[gq0]

I am facing an issue running badger on an ARMv7 architecture. The minimal test case below works quite fine on an amd64 machine but, unfortunately, not on ARMv7 32bit.

The trace below shows that the issue originates in atomic.loadUint64() but I also run basic atomic operations tests against the golang runtime, and they work fine on this architecture.

It looks to me that the underlying memory of oracle.curRead somehow vanishes but I am not sure.

Below you find also a strace trace. There the segmentation fault happens after the madvise, but I am not sure if this is related.

Badger version: 1.0.1 (89689ef36cae26ae094cb5ea79b7400d839f2d68)
golang version: 1.8.5 and 1.9.2

Test case:

func TestPersistentCache_DirectBadger(t *testing.T) {
    dir, err := ioutil.TempDir("", "")
    if err != nil {
        t.Fatal(err)
    }
    defer os.RemoveAll(dir)

    config := badger.DefaultOptions
    config.TableLoadingMode = options.MemoryMap
    config.ValueLogFileSize = 16 << 20
    config.LevelOneSize = 8 << 20
    config.MaxTableSize = 2 << 20
    config.Dir = dir
    config.ValueDir = dir
    config.SyncWrites = false

    db, err := badger.Open(config)
    if err != nil {
        t.Fatalf("cannot open db at location %s: %v", dir, err)
    }

    err = db.View(func(txn *badger.Txn) error { return nil })

    if err != nil {
        t.Fatal(err)
    }

    if err = db.Close(); err != nil {
        t.Fatal(err)
    }
}

=== RUN   TestPersistentCache_DirectBadger
--- FAIL: TestPersistentCache_DirectBadger (0.01s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x1150c]

goroutine 5 [running]:
testing.tRunner.func1(0x10a793b0)
        /usr/lib/go/src/testing/testing.go:711 +0x2a0
panic(0x3e4bd8, 0x6bb478)
        /usr/lib/go/src/runtime/panic.go:491 +0x204
sync/atomic.loadUint64(0x10a483cc, 0x200000, 0x0)
        /usr/lib/go/src/sync/atomic/64bit_arm.go:10 +0x3c
github.com/grid-x/client/vendor/github.com/dgraph-io/badger.(*oracle).readTs(0x10a483c0, 0x14, 0x5)
        /home/robert/Projects/gridx/client/src/github.com/grid-x/client/vendor/github.com/dgraph-io/badger/transaction.go:87 +0x3c
github.com/grid-x/client/vendor/github.com/dgraph-io/badger.(*DB).NewTransaction(0x10b06000, 0x0, 0x4cccc)
        /home/robert/Projects/gridx/client/src/github.com/grid-x/client/vendor/github.com/dgraph-io/badger/transaction.go:440 +0x20
github.com/grid-x/client/vendor/github.com/dgraph-io/badger.(*DB).View(0x10b06000, 0x464e20, 0x0, 0x0)
        /home/robert/Projects/gridx/client/src/github.com/grid-x/client/vendor/github.com/dgraph-io/badger/transaction.go:457 +0x3c
command-line-arguments.TestPersistentCache_DirectBadger(0x10a793b0)
        /home/robert/Projects/gridx/client/src/github.com/grid-x/client/pkg/cache/persistent_cache_test.go:64 +0x1e8
testing.tRunner(0x10a793b0, 0x464e24)
        /usr/lib/go/src/testing/testing.go:746 +0xb0
created by testing.(*T).Run
        /usr/lib/go/src/testing/testing.go:789 +0x258

strace:

[pid 15075] mmap2(NULL, 33554432, PROT_READ, MAP_SHARED, 6, 0) = 0xb4dff000                                   
[pid 15075] madvise(0xb4dff000, 33554432, MADV_RANDOM) = 0                     
[pid 15075] clock_gettime(CLOCK_MONOTONIC, {tv_sec=69709, tv_nsec=217038306}) = 0                            
[pid 15075] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x4} ---
[pid 15075] rt_sigreturn()              = 0                                       

[deepakjois]

What is the amount of memory on your system?

Badger tries to mmap a 2Gb segment of memory for the value log. We haven’t really done a lot of testing on 32-bit systems, but it is likely that on 32-bit systems the address space may run out leading to these kinds of errors.

[gq0]

One setup has 512Mb and the other 1024Mb, both show the same error.

From this line [0] I understood that twice the vlog file size is mmap-ed. In our setup the vlog size is set to 16Mb. I experimented with less and more, but this shows the same error.

[0] https://github.com/dgraph-io/badger/blob/master/db.go#L291

[deepakjois]

I am not really sure what is going here. It looks unlikely that calling return atomic.LoadUint64(&o.curRead) is causing the nil pointer dereference. All the times that we have seen the nil pointer dereference in the past, it has always happened due to mmap related issues. So that’s what I am suspecting this time as well.

I don’t have hardware that can replicate this, but here are a few things that might be worth checking to understand what is going on:

• Did you post the full dump? Maybe there is some other goroutine present whose trace is not shown in the log you posted above?

• What happens if you remove the following lines:

err = db.View(func(txn *badger.Txn) error { return nil })

if err != nil {
    t.Fatal(err)
}

Does the error still happen? Maybe try sleeping for a couple of seconds instead of calling db.View().

[gq0]

If I remove the lines then everything looks good. Open and closing the DB works a couple of times on the same folder. I also tried open and closing and then open again the DB before launching any transaction, but the issue remains. As soon as the first transaction, write or readonly, is committed the error comes.

The go trace is the complete one, I reduces GOMAXPROCS to 1. I can prepare a full strace in couple of minutes.

[deepakjois]

I have created a branch with the test above included in the badger sources: https://github.com/dgraph-io/badger/tree/issue-311

If you are able to do it, please checkout that branch and confirm that this fails:

go test -v -run ^TestPersistentCache_DirectBadger$

I could add more trace output etc in the code to nail this down further, and you could try that on your ARMv7 32bit hardware.

[manishrjain]

@deepakjois You could try emulating arm via https://www.qemu.org/

[jhedev]

Could also be possible to reproduce via Scaleway's ARMv7 Cloud Servers

[deepakjois]

@jhedev cloud servers is an interesting idea. I don’t know much about arm versions, but does the C1 plan here give a Arm v7 32-bit server?

[jhedev]

@deepakjois AFAIK ARMv7 is always 32-bit. 64-bit was introduced with v8

From the scaleway C1 instance:

root@scw-546b0d:~# uname -a
Linux scw-546b0d 4.4.96-mainline-rev1 #1 SMP Thu Nov 2 11:27:34 UTC 2017 armv7l GNU/Linu

We are currently testing if this can be reproduced on this machine as well.

[gq0]

The issue can be reproduced there.

@deepakjois I tried using a sleep in between, the same error is shown after the sleep. I will checkout your branch now.

[deepakjois]

The issue can be reproduced there.

We will look into getting a setup going there. I assume once we sign up, we can just install Ubuntu or something and just install the Go toolchain right after.

It would be nice to have something that will run tests on Arm every build, but that may have to wait for later.

@deepakjois I tried using a sleep in between, the same error is shown after the sleep. I will checkout your branch now.

Can you share the exact code. Just to be clear, did you replace the db.View invocation with time.Sleep and still got the error?

[gq0]

Ah, no with just the sleep: open, sleep, close; everything works. With a sleep in front of the db.View the same error comes.

func TestPersistentCache_DirectBadger(t *testing.T) {
    dir, err := ioutil.TempDir("", "")
    if err != nil {
        t.Fatal(err)
    }
    defer os.RemoveAll(dir)

    config := badger.DefaultOptions
    config.TableLoadingMode = options.MemoryMap
    config.ValueLogFileSize = 16 << 20
    config.LevelOneSize = 8 << 20
    config.MaxTableSize = 2 << 20
    config.Dir = dir
    config.ValueDir = dir
    config.SyncWrites = false

    db, err := badger.Open(config)
    if err != nil {
        t.Fatalf("cannot open db at location %s: %v", dir, err)
    }

    time.Sleep(10 * time.Second)

    err = db.View(func(txn *badger.Txn) error { return nil })

    if err != nil {
        t.Fatal(err)
    }

    if err = db.Close(); err != nil {
        t.Fatal(err)
    }
}

[gq0]

Here a clean build from your https://github.com/dgraph-io/badger/tree/issue-311 branch. I will attach a full strace in a couple of minutes

root@scw-546b0d:~# ./badger_tests.arm -test.v -test.run ^TestPersistentCache_DirectBadger$
=== RUN   TestPersistentCache_DirectBadger
All good. about to load o.curRead
--- FAIL: TestPersistentCache_DirectBadger (0.02s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x1150c]

goroutine 5 [running]:
testing.tRunner.func1(0x10896c60)
        /usr/lib/go/src/testing/testing.go:711 +0x2a0
panic(0x35f358, 0x58dff0)
        /usr/lib/go/src/runtime/panic.go:491 +0x204
sync/atomic.loadUint64(0x1084a84c, 0x22, 0x0)
        /usr/lib/go/src/sync/atomic/64bit_arm.go:10 +0x3c
github.com/dgraph-io/badger.(*oracle).readTs(0x1084a840, 0x14, 0x5)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/transaction.go:88 +0x68
github.com/dgraph-io/badger.(*DB).NewTransaction(0x10b0e000, 0x0, 0x4cccc)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/transaction.go:443 +0x20
github.com/dgraph-io/badger.(*DB).View(0x10b0e000, 0x3c14e8, 0x0, 0x0)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/transaction.go:460 +0x3c
github.com/dgraph-io/badger.TestPersistentCache_DirectBadger(0x10896c60)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/issue311_test.go:32 +0x1e8
testing.tRunner(0x10896c60, 0x3c14ec)
        /usr/lib/go/src/testing/testing.go:746 +0xb0
created by testing.(*T).Run
        /usr/lib/go/src/testing/testing.go:789 +0x258

[deepakjois]

I just setup a scaleway instance, ran the test and it worked (output below). Please check the uname output. Am I on the right Arm version?

$ uname -a
Linux badger-armv7 4.9.23-std-1 #1 SMP Mon Apr 24 13:18:14 UTC 2017 aarch64 aarch64 aarch64 GNU/Linux


$ go test -v -run ^TestPersistentCache_DirectBadger$
=== RUN   TestPersistentCache_DirectBadger
All good. about to load o.curRead
Entered Txn.Discard()
Exit Txn.Discard()
--- PASS: TestPersistentCache_DirectBadger (0.75s)
PASS
ok      github.com/dgraph-io/badger     0.790s

EDIT:

cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=17.04
DISTRIB_CODENAME=zesty
DISTRIB_DESCRIPTION="Ubuntu 17.04"

[jhedev]

@deepakjois I think that's the wrong one. You need to select the Baremetal C1 instance (only available in Paris). I get the following uname output:

root@scw-546b0d:~# uname -a
Linux scw-546b0d 4.4.96-mainline-rev1 #1 SMP Thu Nov 2 11:27:34 UTC 2017 armv7l GNU/Linux

[gq0]

Yes its an arm64 (aarch64) and a newer kernel 4.9, I use 4.4 and armv7

Strace log:
badger_tests.arm.strace.log

[deepakjois]

Ok, I will try the Baremetal C1 to replicate.

[gq0]

@deepakjois thanks a lot for your support

[deepakjois]

Ok I can replicate the failure on the Baremetal C1. However, I am not sure if this has something to do with Badger. Please check the latest code I pushed to the branch.

This test which does not exercise any Badger code, fails as well:

type orc struct {
    isManaged bool // Does not change value, so no locking required.

    sync.Mutex
    curRead    uint64
    nextCommit uint64

    // These two structures are used to figure out when a commit is done. The minimum done commit is
    // used to update curRead.
    commitMark     uint64Heap
    pendingCommits map[uint64]struct{}

    // commits stores a key fingerprint and latest commit counter for it.
    // refCount is used to clear out commits map to avoid a memory blowup.
    commits  map[uint64]uint64
    refCount int64
}

func TestAtomicLoadArm(t *testing.T) {
    o := &orc{}
    atomic.LoadUint64(&o.curRead)
}

Test output:

 $ go test -v  -run ^TestAtomic
=== RUN   TestAtomicLoadArm
--- FAIL: TestAtomicLoadArm (0.00s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x11d64]

goroutine 5 [running]:
testing.tRunner.func1(0x10812ab0)
        /usr/lib/go-1.9/src/testing/testing.go:711 +0x2a0
panic(0x35fb70, 0x58e160)
        /usr/lib/go-1.9/src/runtime/panic.go:491 +0x204
sync/atomic.loadUint64(0x1085484c, 0x10854840, 0xe9630)
        /usr/lib/go-1.9/src/sync/atomic/64bit_arm.go:10 +0x3c
github.com/dgraph-io/badger.TestAtomicLoadArm(0x10812ab0)
        /root/go/src/github.com/dgraph-io/badger/issue311_test.go:61 +0x2c
testing.tRunner(0x10812ab0, 0x3c20ac)
        /usr/lib/go-1.9/src/testing/testing.go:746 +0xb0
created by testing.(*T).Run
        /usr/lib/go-1.9/src/testing/testing.go:789 +0x258
exit status 2
FAIL    github.com/dgraph-io/badger     0.071s

I would suspect there is an issue with the Go runtime, or the kernel which is causing this. I don’t think we can do much here. Maybe file a bug upstream?

[deepakjois]

I was able to simplify the case down to this, and still get it to fail:

type orc struct {
    isManaged bool
    curRead uint64
}

func TestAtomicLoadArm(t *testing.T) {
    o := &orc{}
    atomic.LoadUint64(&o.curRead)
}

[manishrjain]

As per https://golang.org/pkg/sync/atomic/

Bugs
☞
On x86-32, the 64-bit functions use instructions unavailable before the Pentium MMX.

On non-Linux ARM, the 64-bit functions use instructions unavailable before the ARMv6k core.

On both ARM and x86-32, it is the caller's responsibility to arrange for 64-bit alignment of 64-bit words accessed atomically. The first word in a variable or in an allocated struct, array, or slice can be relied upon to be 64-bit aligned.

[deepakjois]

On both ARM and x86-32, it is the caller's responsibility to arrange for 64-bit alignment of 64-bit words accessed atomically. The first word in a variable or in an allocated struct, array, or slice can be relied upon to be 64-bit aligned.

So if I change the test above to (i.e. reorder the members to have curRead on top):

type orc struct {
    curRead uint64
    isManaged bool
}

func TestAtomicLoadArm(t *testing.T) {
    o := &orc{}
    atomic.LoadUint64(&o.curRead)
}

It passes.

I have pushed a potential fix to this branch, which passes the original TestPersistentCache_DirectBadger above: https://github.com/dgraph-io/badger/tree/dj/atomic-load-arm

Running this on the fix branch:

$ go test -v  -run ^TestArm
=== RUN   TestArmV7Issue311Fix
--- PASS: TestArmV7Issue311Fix (1.02s)
PASS

@gq0, @jhedev Could you please test that branch and let me know if it works for you. There may be other places in the code where we might have to re-order struct members to ensure 64-bit alignment.

[gq0]

Good morning @manishrjain and @deepakjois. It looks like this is the root cause. The test runs through successfully; thanks :+1:

The 64bit alignment in structs is an issue in other places as well. Another test case fails here:
https://github.com/dgraph-io/badger/blob/master/skl/skl.go#L138

[deepakjois]

Ok, I think I have moved all struct members that were being accessed using the sync/atomic package to the top, to ensure 64-bit alignment. Let me know if these changes work for you, and I will create a pull request.

[gq0]

:thinking: value is the first field in node but it fails with the same panic. This happens if I extend your test with a write transaction.

diff --git a/transaction_test.go b/transaction_test.go
index c234f65..5b2a9b6 100644
--- a/transaction_test.go
+++ b/transaction_test.go
@@ -641,7 +641,13 @@ func TestArmV7Issue311Fix(t *testing.T) {
        }

        err = db.View(func(txn *Txn) error { return nil })
+       if err != nil {
+               t.Fatal(err)
+       }

+       err = db.Update(func(txn *Txn) error {
+               return txn.Set([]byte{ 0x11 }, []byte{ 0x22 })
+       })
        if err != nil {
                t.Fatal(err)
        }

root@gridBox-B313-200-000-000-021-P-X:/data# ./badger_tests.arm -test.v -test.run ^TestArmV7Issue311Fix$
=== RUN   TestArmV7Issue311Fix
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x1150c]

goroutine 10 [running]:
sync/atomic.loadUint64(0x10af008c, 0xffff, 0x10af007e)
        /usr/lib/go/src/sync/atomic/64bit_arm.go:10 +0x3c
github.com/dgraph-io/badger/skl.(*node).getValueOffset(0x10af008c, 0x108561e8, 0x2ce8a0)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/skl/skl.go:138 +0x20
github.com/dgraph-io/badger/skl.(*Iterator).Value(0x1080c808, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/skl/skl.go:425 +0x2c
github.com/dgraph-io/badger.writeLevel0Table(0x108a1520, 0x1080c7f8, 0x0, 0x0)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/db.go:735 +0xec
github.com/dgraph-io/badger.(*DB).flushMemtable(0x10aee000, 0x1080f0c0, 0x0, 0x0)
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/db.go:778 +0x1cc
created by github.com/dgraph-io/badger.Open
        /home/robert/Projects/gridx/badger/src/github.com/dgraph-io/badger/db.go:257 +0x928

Update:
If I start the test couple of times, occasionally it works.

[deepakjois]

Yes, it happens if you just run go test in the skl package. I am not really sure what else we need to do here. I could try asking the go-nuts mailing list. In the meanwhile if you know somebody has more experience with these sort of alignment issues, it might help asking them.

[gq0]

All right, let's do this. In the meantime, I will read through the code, and maybe we find something.

[gq0]

After reading through the go stdlib's sync package, I came across this:
https://github.com/golang/go/blob/master/src/sync/waitgroup.go#L23

This also fixes our issue with the value in the skip list. I am preparing a patch.

Update: The following patch, plus your previous changes in this branches fixes this issue.

From 76fed29c3ebd7b47991283c40a11084c41800e71 Mon Sep 17 00:00:00 2001
From: Robert Fritzsche <[email protected]>
Date: Fri, 10 Nov 2017 19:02:12 +0100
Subject: [PATCH] Fix value 64bit alignment on 32bit systems.

Signed-off-by: Robert Fritzsche <[email protected]>
---
 skl/skl.go          | 17 +++++++++++++----
 transaction_test.go |  6 ++++++
 2 files changed, 19 insertions(+), 4 deletions(-)

diff --git a/skl/skl.go b/skl/skl.go
index b465b09..790c4eb 100644
--- a/skl/skl.go
+++ b/skl/skl.go
@@ -54,7 +54,8 @@ type node struct {
    // can be atomically loaded and stored:
    //   value offset: uint32 (bits 0-31)
    //   value size  : uint16 (bits 32-47)
-   value uint64
+   // 12 bytes are allocated to ensure 8 byte alignment also on 32bit systems.
+   value1 [12]byte

    // A byte slice is 24 bytes. We are trying to save space here.
    keyOffset uint32 // Immutable. No need to lock to access key.
@@ -108,7 +109,7 @@ func newNode(arena *Arena, key []byte, v y.ValueStruct, height int) *node {
    node.keyOffset = arena.putKey(key)
    node.keySize = uint16(len(key))
    node.height = uint16(height)
-   node.value = encodeValue(arena.putVal(v), v.EncodedSize())
+   *node.value64BitAlignedPtr() = encodeValue(arena.putVal(v), v.EncodedSize())
    return node
 }

@@ -134,8 +135,16 @@ func NewSkiplist(arenaSize int64) *Skiplist {
    }
 }

+func (s *node) value64BitAlignedPtr() *uint64 {
+   if uintptr(unsafe.Pointer(&s.value1))%8 == 0 {
+       return (*uint64)(unsafe.Pointer(&s.value1))
+   } else {
+       return (*uint64)(unsafe.Pointer(&s.value1[4]))
+   }
+}
+
 func (s *node) getValueOffset() (uint32, uint16) {
-   value := atomic.LoadUint64(&s.value)
+   value := atomic.LoadUint64(s.value64BitAlignedPtr())
    return decodeValue(value)
 }

@@ -146,7 +155,7 @@ func (s *node) key(arena *Arena) []byte {
 func (s *node) setValue(arena *Arena, v y.ValueStruct) {
    valOffset := arena.putVal(v)
    value := encodeValue(valOffset, v.EncodedSize())
-   atomic.StoreUint64(&s.value, value)
+   atomic.StoreUint64(s.value64BitAlignedPtr(), value)
 }

 func (s *node) getNextOffset(h int) uint32 {
diff --git a/transaction_test.go b/transaction_test.go
index c234f65..9556d02 100644
--- a/transaction_test.go
+++ b/transaction_test.go
@@ -641,7 +641,13 @@ func TestArmV7Issue311Fix(t *testing.T) {
    }

    err = db.View(func(txn *Txn) error { return nil })
+   if err != nil {
+       t.Fatal(err)
+   }

+   err = db.Update(func(txn *Txn) error {
+       return txn.Set([]byte{0x11}, []byte{0x22})
+   })
    if err != nil {
        t.Fatal(err)
    }
-- 
2.15.0

[manishrjain]

Just a note, this would increase the size of each node. It's alright given the fact that this change would allow ARM servers to run Badger. We should probably have a list of architectures on which Badger can run, in the README. @deepakjois .

[gq0]

If the increased node size blocks use-cases, then we could use platform-dependent builds just for the 32bit architectures. On the other hand, this would increase code maintains efforts.

[deepakjois]

@manishrjain what do you think about extracting the node struct in skl package to a different build-specific file and using // +build 386 or similar annotation. This would increase the node size only for 32-bit builds.

[manishrjain]

Might add more complexity unnecessarily. We're adding 4 extra bytes per node, right? Should be alright. Plus, once Go fixes this issue, we can revert back to doing things normally.

[deepakjois]

Ok applied the last patch. PR #318 is now open.

[gq0]

Thanks so much for the quick reaction :+1:

[brunoamancio]

I have the same issue when badger calls atomic.StoreUint64 in watermark.go

func (w *WaterMark) Begin(index uint64) {
    atomic.StoreUint64(&w.lastIndex, index)
    w.markCh <- mark{index: index, done: false}
}