panic in fillTablesL0

[vrischmann]

Hi,

I just encountered this panic:

panic: runtime error: makeslice: len out of range

goroutine 26016 [running]:
github.com/dgraph-io/badger.(*levelsController).fillTablesL0(0xc00014e000, 0xc00005dd08, 0x0)
        /home/vincent/dev/go/pkg/mod/github.com/dgraph-io/badger@v1.5.5-0.20190104015325-f796303af5fc/levels.go:546 +0x237
github.com/dgraph-io/badger.(*levelsController).doCompact(0xc00014e000, 0x0, 0x3ff0000000000000, 0x0, 0x0)
        /home/vincent/dev/go/pkg/mod/github.com/dgraph-io/badger@v1.5.5-0.20190104015325-f796303af5fc/levels.go:677 +0x2fc
github.com/dgraph-io/badger.(*levelsController).runWorker(0xc00014e000, 0xc000132280)
        /home/vincent/dev/go/pkg/mod/github.com/dgraph-io/badger@v1.5.5-0.20190104015325-f796303af5fc/levels.go:241 +0x24a
created by github.com/dgraph-io/badger.(*levelsController).startCompact
        /home/vincent/dev/go/pkg/mod/github.com/dgraph-io/badger@v1.5.5-0.20190104015325-f796303af5fc/levels.go:217 +0x82

I'll attach my badger info result if that helps.

badger_info.txt

[vrischmann]

I logged some more information inside the fillTablesL0 function:

time="2019-01-04T20:45:56Z" level=info msg=table filename=/data/logs/011518.sst id=11518 size=220155029
time="2019-01-04T20:45:56Z" level=info msg=table filename=/data/logs/011519.sst id=11519 size=220158688
time="2019-01-04T20:45:56Z" level=info msg=table filename=/data/logs/011520.sst id=11520 size=220160680
time="2019-01-04T20:45:56Z" level=info msg=table filename=/data/logs/011521.sst id=11521 size=220151587
time="2019-01-04T20:45:56Z" level=info msg=table filename=/data/logs/011522.sst id=11522 size=220158188
time="2019-01-04T20:45:56Z" level=info msg=fillTablesLo diff=-1 kr-left="[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]" kr-right="[0 0 0 0 0 0 0 0 0 0 0 0 255 255 255 255 255 255 255 255]" left=1 right=0

I should also note that it's always reproducible. I worked with the database all day but somehow in the last couple hours something went wrong somewhere.

[vrischmann]

I think this table is the problem:

time="2019-01-07T18:54:47Z" level=info msg=table biggest="[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]" filename=/data/logs/011517.sst id=11517 size=416 smallest="[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]

and its hexdump

00000000  00 00 00 19 00 0f ff ff  ff ff 00 00 00 00 00 00  |................|
00000010  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00000020  00 00 00 42 00 00 00 00  00 1e 00 00 00 e5 12 42  |...B...........B|
00000030  1a 89 00 14 00 00 00 0f  00 00 00 00 00 00 00 00  |................|
00000040  00 00 00 00 00 00 00 00  00 00 00 00 19 00 00 00  |................|
00000050  0f 00 00 00 32 42 00 00  00 00 00 17 00 00 00 e4  |....2B..........|
00000060  04 18 24 14 00 14 00 00  00 0f 00 00 00 4b 00 00  |..$..........K..|
00000070  00 00 00 00 00 00 00 00  00 00 00 00 00 00 19 00  |................|
00000080  00 00 0f 00 00 00 64 42  00 00 00 00 00 0f 00 00  |......dB........|
00000090  02 36 0b 8e 54 fc 00 14  00 00 00 0f 00 00 00 7d  |.6..T..........}|
000000a0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
000000b0  19 00 00 00 0f 00 00 00  96 42 00 00 00 00 00 07  |.........B......|
000000c0  00 00 00 9e 0d fe a9 62  00 14 00 00 00 0f 00 00  |.......b........|
000000d0  00 af 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
000000e0  00 00 19 00 00 00 0f 00  00 00 c8 42 00 00 00 00  |...........B....|
000000f0  00 00 00 00 02 00 00 00  00 00 00 14 00 00 00 0f  |................|
00000100  00 00 00 e1 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00000110  00 00 00 00 00 00 00 00  03 00 00 00 fa 00 00 00  |................|
00000120  00 00 01 20 00 00 00 01  7b 22 46 69 6c 74 65 72  |... ....{"Filter|
00000130  53 65 74 22 3a 22 41 41  41 42 41 41 45 45 41 41  |Set":"AAABAAEEAA|
00000140  41 51 41 41 42 67 41 41  41 41 41 51 41 41 41 41  |AQAABgAAAAAQAAAA|
00000150  41 41 41 41 41 41 41 41  41 41 41 41 43 41 41 41  |AAAAAAAAAAAACAAA|
00000160  41 41 41 41 41 41 41 42  41 41 41 41 41 41 41 41  |AAAAAAABAAAAAAAA|
00000170  41 41 41 67 41 41 41 41  41 41 41 45 41 41 41 41  |AAAgAAAAAAAEAAAA|
00000180  41 41 41 41 41 51 43 41  42 41 41 41 3d 3d 22 2c  |AAAAAQCABAAA==",|
00000190  22 53 65 74 4c 6f 63 73  22 3a 37 7d 00 00 00 74  |"SetLocs":7}...t|
000001a0

If I'm not misunderstanding the code overlappingTables seems to produce something wrong because of this table.

[manishrjain]

It's really bizarre that your table boundaries are nil arrays. Do you reckon something external to Badger might have modified these files?

For that matter, we should checksum these tables and store them in MANIFEST -- or as the last few bytes of the tables, so we can ensure they haven't been accidentally modified.

[vrischmann]

I'm not sure what external process would have modified the files because the database lives on its own server which does nothing else, but maybe I did something somewhere which messed it up.

What I know is that I killed my program while the database was being opened a number of times (I'm testing my program on this database) and after sometime I got this.

However, right now I'm unable to reproduce this error. After testing your branch regarding loading times, somehow this panic disappeared, so I'm not sure what to make of it.

[manishrjain]

There was a bug in my branch which could have triggered this. I fixed those bugs in the branch and merged to master. If you still see this issue in master, feel free to reopen, or create a new issue.