Slice bounds out of range error during compaction about goleveldb HOT 21 CLOSED

LOG contents:

2013/05/0004 14:47:45.575207 JournalRecovery: started, min=0
2013/05/0004 14:47:48.382394 MemCompaction: started, size=4196501 entries=4444
2013/05/0004 14:47:48.446656 Compaction: table created, source=mem level=2 num=3 size=1519000 entries=4444 min="\x00\x00\x00\x00\x00:v:4442" max="k_IND...L_MAP:v:1"
2013/05/0004 14:47:48.489791 MemCompaction: started, size=4194385 entries=1788
2013/05/0004 14:47:48.559822 Compaction: table created, source=mem level=1 num=5 size=2113365 entries=1788 min="\x00\x00\x00\x00\x00:v:6230" max="febb2...1cd99:v:4449"
2013/05/0004 14:47:48.580500 Compaction: compacting, level=1 tables=1, level=2 tables=1
2013/05/0004 14:47:48.586488 MemCompaction: started, size=4199846 entries=1382
2013/05/0004 14:47:48.651842 Compaction: table created, source=mem level=0 num=8 size=2253693 entries=1382 min="\x00\x00\x00\x00\x00:v:7558" max="fd2e4...fe305:v:7125"

from goleveldb.

Can you try again using latest commit?
It will still panic though, but it should produce better panic message.

from goleveldb.

panic: invalid iKey "\xc7\x00", len=2 [recovered]
panic: invalid iKey "\xc7\x00", len=2

goroutine 52 [running]:
github.com/syndtr/goleveldb/leveldb.func·015()
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db_compaction.go:392 +0x172
github.com/syndtr/goleveldb/leveldb.iKey.assert(0xc200b548c8, 0x2, 0x2)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/key.go:74 +0x17b
github.com/syndtr/goleveldb/leveldb.iKey.parseNum(0xc200b548c8, 0x2, 0x2, 0x2, 0xc200c1b800, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/key.go:89 +0x39
github.com/syndtr/goleveldb/leveldb.func·013(0x0, 0x0)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db_compaction.go:300 +0x473
github.com/syndtr/goleveldb/leveldb.(_DB).transact(0xc2001cf000, 0x6b1a50)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db_compaction.go:136 +0xaa
github.com/syndtr/goleveldb/leveldb.(_DB).doCompaction(0xc2001cf000, 0xc2000e3b60, 0x6b1f00)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db_compaction.go:365 +0x7e0
github.com/syndtr/goleveldb/leveldb.(*DB).compaction(0xc2001cf000)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db_compaction.go:463 +0x1cb
created by github.com/syndtr/goleveldb/leveldb.open
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db.go:70 +0x1ec

from goleveldb.

I think I found the bug in my code which triggers this. Through this bug I have lot's of keys that look like this:

[0 0 0 0 10]

With the last byte always being something between 1 - 15.

from goleveldb.

Also can you please run go test for leveldb package, i.e. go test github.com/syndtr/goleveldb/leveldb

from goleveldb.

go test github.com/syndtr/goleveldb/leveldb
ok github.com/syndtr/goleveldb/leveldb 16.750s

from goleveldb.

Please try again using the latest commit and set opt.OFParanoidCheck flag.

from goleveldb.

I added the flag, but no change.

from goleveldb.

Should I send you the database directory (roughly 6 MByte)?

from goleveldb.

I see. I still cannot understand why the sstable contains invalid key.

What version of Go and OS do you use?

from goleveldb.

Should I send you the database directory (roughly 6 MByte)?

That would be great

from goleveldb.

OS: Mac OS X 10.8.3
Go: changeset 16735:3478ecc801f6

from goleveldb.

What happen if you do compact range? i.e. db.CompactRange(leveldb.Range{})

from goleveldb.

Nothing... At least nothing bad...

2013/05/0004 17:08:30.816970 JournalRecovery: started, min=28
2013/05/0004 17:08:30.817210 JournalRecovery: recovering, num=28
2013/05/0004 17:08:30.852537 CompactRange: ordered, level=-1
2013/05/0004 17:08:30.852558 Compaction: compacting, level=0 tables=1, level=1 tables=0
2013/05/0004 17:08:30.991699 Compaction: table created, source=file level=1 num=32 size=1298318 entries=46704 min="\x00\x02\x18\x03\x01:v:282887" max="\xff\xf5\xe4\f\x14:v:317609"
2013/05/0004 17:08:30.991714 Compaction: done
2013/05/0004 17:08:30.991969 Compaction: compacting, level=1 tables=1, level=2 tables=3
2013/05/0004 17:08:31.204093 Compaction: table created, source=file level=2 num=33 size=2211342 entries=73249 min="\x00\x01\x17\x03\x01:v:245687" max="50ace...81081:v:150344"
2013/05/0004 17:08:31.419793 Compaction: table created, source=file level=2 num=34 size=2202213 entries=66445 min="50ace...42666:v:150866" max="aaba7...4cc7b:v:204856"
2013/05/0004 17:08:31.665576 Compaction: table created, source=file level=2 num=35 size=2206843 entries=69748 min="aabb1...a60a7:v:123101" max="\x91\xe8\xfb\b\x1a:v:310185"
2013/05/0004 17:08:31.781931 Compaction: table created, source=file level=2 num=36 size=1174113 entries=68007 min="\x91\xe93\b\x00:v:53027" max="\xff\xff\xf0\f\x00:v:30887"
2013/05/0004 17:08:31.781946 Compaction: done
2013/05/0004 17:08:31.782304 CompactRange: done

But when I start adding entries I eventually get an iKey panic:

panic: invalid iKey "", len=0

from goleveldb.

Here's a short program to reproduce the error:

package main

import (
    "fmt"
    "github.com/syndtr/goleveldb/leveldb"
    "github.com/syndtr/goleveldb/leveldb/filter"
    "github.com/syndtr/goleveldb/leveldb/opt"
    "github.com/syndtr/goleveldb/leveldb/storage"
    "io"
    "math/rand"
    "os"
)

var kGlobalReadOptions *opt.ReadOptions = &opt.ReadOptions{}
var kGlobalWriteOptions *opt.WriteOptions = &opt.WriteOptions{}

func Uuid() (string, error) {
    f, ferr := os.Open("/dev/urandom")
    if ferr != nil {
        return "", ferr
    }
    defer f.Close()
    b := make([]byte, 16)
    _, rerr := io.ReadFull(f, b)
    if rerr != nil {
        return "", rerr
    }
    return fmt.Sprintf("%x-%x-%x-%x-%x", b[0:4], b[4:6], b[6:8], b[8:10], b[10:]), nil
}

func main() {

    stor, _ := storage.OpenFile("/tmp/testdb.ldb")
    oFlag := opt.OFCreateIfMissing | opt.OFParanoidCheck
    db, _ := leveldb.Open(stor, &opt.Options{Flag: oFlag, Filter: filter.NewBloomFilter(10)})

    for {
        uuid, _ := Uuid()
        for i := 0; i < 4; i++ {
            id := rand.Intn(15)
            val := *(&[]byte{0, 0, 0, 0, byte(id)})

            oVal, err1 := db.Get([]byte(uuid), kGlobalReadOptions)

            if err1 != nil && err1.Error() != "not found" {
                fmt.Println(err1, oVal)
            }

            if len(oVal) > 0 {
                val = append(oVal, val...)
            }
            perr1 := db.Put([]byte(uuid), val, kGlobalWriteOptions)

            if perr1 == nil {

                for level := 0; level < 4; level++ {
                    c := rand.Int63()
                    val2 := *(&[]byte{byte(level), byte(c >> 0), byte(c >> 8), byte(c >> 16), byte(c >> 24), byte(c >> 32), byte(c >> 40), byte(c >> 48), byte(c >> 56)})
                    oVal2, err2 := db.Get(val, kGlobalReadOptions)

                    if err2 != nil && err2.Error() != "not found" {
                        fmt.Println(err2, oVal2)
                    }

                    if len(oVal2) > 0 {
                        val2 = append(oVal2, val2...)
                    }
                    perr2 := db.Put(val, val2, kGlobalWriteOptions)
                    if perr2 != nil {
                        fmt.Println(perr2)
                    }
                }

            } else {
                fmt.Println(perr1)
            }
        }
    }

}

from goleveldb.

panic: invalid iKey "\x1fʊ\x16\x91", len=5

goroutine 1 [running]:
github.com/syndtr/goleveldb/leveldb.iKey.assert(0x2118b43fb, 0x5, 0xc1f)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/key.go:74 +0x17b
github.com/syndtr/goleveldb/leveldb.iKey.ukey(0x2118b43fb, 0x5, 0xc1f, 0x5, 0x210fe6760, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/key.go:79 +0x39
github.com/syndtr/goleveldb/leveldb.(_iComparer).Compare(0x2102ae230, 0x2118b43fb, 0x5, 0xc1f, 0x210fe6760, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/comparer.go:21 +0x85
github.com/syndtr/goleveldb/leveldb/block.(_Iterator).Seek(0x21145ea80, 0x210fe6760, 0x17, 0x17, 0x21145ea80, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/block/reader.go:339 +0x1bc
github.com/syndtr/goleveldb/leveldb/table.(_Reader).Get(0x211c82370, 0x210fe6760, 0x17, 0x17, 0x21127b510, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/table/reader.go:140 +0x34b
github.com/syndtr/goleveldb/leveldb.(_tOps).get(0x2102cb2d0, 0x2119df9b0, 0x210fe6760, 0x17, 0x17, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/table.go:363 +0x1bf
github.com/syndtr/goleveldb/leveldb.(_version).get(0x210c70680, 0x210fe6760, 0x17, 0x17, 0x1fca30, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/version.go:142 +0x5fc
github.com/syndtr/goleveldb/leveldb.(_DB).get(0x2102fd000, 0x210374763, 0xf, 0x12, 0x94cb, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db.go:329 +0x20b
github.com/syndtr/goleveldb/leveldb.(*DB).Get(0x2102fd000, 0x210374763, 0xf, 0x12, 0x1fca30, ...)
/Users/sascha/Development/Go/projects/src/github.com/syndtr/goleveldb/leveldb/db.go:349 +0xe1
main.main()
/Users/sascha/Development/Go/gsb-logserver/src/ikeyfail/ikeyfail.go:52 +0x59e

from goleveldb.

I've added some logging output to the sample program to display the errors on db.Get() that happen before the panic.

from goleveldb.

Look like for some reason the block got corrupted. Will report back tomorrow.

from goleveldb.

I think the block cache got corrupted when you trying to append to the buffer returned by db.Get(), since it is just a slice of a larger buffer (the block) appending to it would led to overwriting the rest of the block.

So the problem is I forgot to state that in the documentation. I'll fix this tomorrow.

from goleveldb.

Ok, so I made value copied before returned. So it is safe now to modify buffer returned by db.Get().

from goleveldb.

Now it works perfectly.

from goleveldb.