Panic: leveldb/table: corruption on data-block

Tom · April 24, 2015, 10:09am

can’t start ST + SyncTrayzor, i keep getting the above panic. Partial log : http://pastebin.com/424ykBpL

help?

thx, Tom.

AudriusButkevicius · April 24, 2015, 10:20am

Remove the index directory from syncthings home directory and let it reindex.

Tom · April 24, 2015, 10:26am

would removing the corrupt file do the trick? I’m asking bc I just moved to .11 and a full reindex will take days, if not a week.

AudriusButkevicius · April 24, 2015, 10:32am

I don’t think you can do that.

Tom · April 24, 2015, 11:46am

for the sake of science, i tried it anyway. Everything looks normal. Here’s an excerpt from syncthing.log after removing the bad .ldb :

SyncThingProcessRunner.Start called
Starting syncthing: C:\Users\Tom\AppData\Roaming\SyncTrayzor\syncthing.exe
[XC2UK] 2015/04/24 12:11:45.907696 main.go:399: INFO: syncthing v0.11.0 (go1.4.2 windows-amd64 default) unknown-user@syncthing-builder 2015-04-22 00:37:18 UTC
[XC2UK] 2015/04/24 12:11:45.908693 main.go:400: INFO: My ID: XC2UKT2
[XC2UK] 2015/04/24 12:12:33.533149 main.go:673: INFO: Starting web GUI on https://127.0.0.1:8384/
[XC2UK] 2015/04/24 12:12:35.125200 leveldb.go:1043: INFO: db repair: rewriting global version list for 6d6f7669657300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 412054686f7573616e6420576f72647320283230313229
[XC2UK] 2015/04/24 12:12:35.127203 leveldb.go:1043: INFO: db repair: rewriting global version list for 6d6f7669657300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 412054686f7573616e6420576f726473202832303132292f4e6f7720596f7520536565204d6520283230313329
[XC2UK] 2015/04/24 12:12:35.133206 leveldb.go:1043: INFO: db repair: rewriting global version list for 6d6f7669657300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 412054686f7573616e6420576f726473202832303132292f4e6f7720596f7520536565204d65202832303133292f4e6f7720596f7520536565204d652028323031332920373230702e52455249502e50524f5045522e424c555241592e73634f72702e7372742e2173796e63
[XC2UK] 2015/04/24 12:12:35.133206 leveldb.go:1043: INFO: db repair: rewriting global version list for 6d6f7669657300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 412054686f7573616e6420576f726473202832303132292f612e74686f7573616e642e776f7264732e323031322e31303830702e626c757261792e783236342e6474732d77696b692e524f2e737274
[XC2UK] 2015/04/24 12:12:35.137210 leveldb.go:1043: INFO: db repair: rewriting global version list for 6d6f7669657300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 412054686f7573616e6420576f726473202832303132292f612e74686f7573616e642e776f7264732e323031322e31303830702e626c757261792e783236342e6474732d77696b692e6d6b76
[XC2UK] 2015/04/24 12:13:07.251420 set.go:66: DEBUG: loaded localVersion for "movies": map[protocol.DeviceID]int64{7LQ62GR:20478, 7777777:21702}
[XC2UK] 2015/04/24 12:13:07.258424 set.go:75: DEBUG: movies Replace(7LQ62GR, [0])
[XC2UK] 2015/04/24 12:13:40.452349 set.go:66: DEBUG: loaded localVersion for "music": map[protocol.DeviceID]int64{7LQ62GR:18710, 7777777:21645}
[XC2UK] 2015/04/24 12:13:49.124078 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:13:49.125077 set.go:75: DEBUG: music Replace(7LQ62GR, [0])
[XC2UK] 2015/04/24 12:13:49.172109 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:13:49.193126 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:14:17.525836 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:14:17.548854 set.go:169: DEBUG: music WithGlobalTruncated()
[XC2UK] 2015/04/24 12:14:17.560860 set.go:155: DEBUG: movies WithHaveTruncated(7777777)
[XC2UK] 2015/04/24 12:14:17.561860 set.go:155: DEBUG: movies WithHaveTruncated(7777777)
[XC2UK] 2015/04/24 12:14:36.049071 set.go:141: DEBUG: movies WithNeedTruncated(7LQ62GR)
[XC2UK] 2015/04/24 12:14:37.355935 set.go:169: DEBUG: music WithGlobalTruncated()
[XC2UK] 2015/04/24 12:14:37.399963 set.go:141: DEBUG: movies WithNeedTruncated(7777777)
[XC2UK] 2015/04/24 12:14:37.413972 set.go:141: DEBUG: movies WithNeedTruncated(7777777)
[XC2UK] 2015/04/24 12:14:42.583387 set.go:169: DEBUG: music WithGlobalTruncated()
[XC2UK] 2015/04/24 12:14:42.623414 set.go:155: DEBUG: music WithHaveTruncated(7777777)
[XC2UK] 2015/04/24 12:14:49.307828 set.go:141: DEBUG: music WithNeedTruncated(7777777)
[XC2UK] 2015/04/24 12:14:50.934905 set.go:141: DEBUG: music WithNeedTruncated(7LQ62GR)
Killing Syncthing process
Syncthing process stopped with exit status Success
SyncThingProcessRunner.Start called
Starting syncthing: C:\Users\Tom\AppData\Roaming\SyncTrayzor\syncthing.exe
[XC2UK] 2015/04/24 12:26:21.880271 main.go:399: INFO: syncthing v0.11.0 (go1.4.2 windows-amd64 default) unknown-user@syncthing-builder 2015-04-22 00:37:18 UTC
[XC2UK] 2015/04/24 12:26:21.881270 main.go:400: INFO: My ID: XC2UKT2
[XC2UK] 2015/04/24 12:26:28.569690 main.go:673: INFO: Starting web GUI on https://127.0.0.1:8384/
[XC2UK] 2015/04/24 12:26:49.069231 set.go:66: DEBUG: loaded localVersion for "movies": map[protocol.DeviceID]int64{7777777:21702}
[XC2UK] 2015/04/24 12:26:49.075232 set.go:75: DEBUG: movies Replace(7LQ62GR, [0])
[XC2UK] 2015/04/24 12:27:19.989652 set.go:66: DEBUG: loaded localVersion for "music": map[protocol.DeviceID]int64{7LQ62GR:18710, 7777777:21645}
[XC2UK] 2015/04/24 12:27:20.127743 set.go:75: DEBUG: music Replace(7LQ62GR, [0])
[XC2UK] 2015/04/24 12:27:20.164773 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:27:20.174778 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:27:20.188787 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:27:40.130954 set.go:155: DEBUG: movies WithHaveTruncated(7777777)
[XC2UK] 2015/04/24 12:27:40.130954 set.go:169: DEBUG: movies WithGlobalTruncated()
[XC2UK] 2015/04/24 12:27:40.163980 set.go:169: DEBUG: music WithGlobalTruncated()

AudriusButkevicius · April 24, 2015, 12:29pm

I guess that might purely be based on luck, or if the file was the last file in the index. I tried to delete a file from the middle of the sequence and it cried about not finding the file.

Tom · April 24, 2015, 12:39pm

most likely the last file in the index, since it had only just finished re-indexing after moving to 0.11

calmh · April 24, 2015, 10:55pm

Cool. If it starts, it’s all good. Syncthing tries to repair the database on startup, and will then rescan any files that are unknown or changed.

Tom · May 1, 2015, 2:25pm

This is now a recurring issue I have a particular folder which will always cause the panic ! Can we troubleshoot this please?

edit : just wanted to add that i did do a full re-index, still get the panic.

calmh · May 1, 2015, 6:17pm

Can you describe the steps that get you into this situation, from a clean setup, and post the resulting panic log?

Tom · May 1, 2015, 8:44pm

Where can i find the panic logs ? I looked in %localappdata%\Syncthing , but nothing there…

I have 1 host that has successfully indexed the folder, I am sharing this folder to another host. The folder is pre-seeded on the 2nd host, meaning most (if not all) files are present. The 2nd host’s webif is asking me if I want to accept the share, which i confirm and this gets added to the config :

<folder id="movies" path="V:\video\movies" ro="true" rescanIntervalS="3600" ignorePerms="false" autoNormalize="true">
    <device id="7LQ62GR-sanitized"></device>
    <device id="XC2UKT2-sanitized"></device>
    <versioning type="simple">
        <param key="keep" val="2"></param>
    </versioning>
    <lenientMtimes>false</lenientMtimes>
    <copiers>0</copiers>
    <pullers>0</pullers>
    <hashers>0</hashers>
    <order>random</order>
</folder>

Indexing begins on the 2nd host, and eventually throws the panic.

calmh · May 1, 2015, 8:52pm

The panic log is wherever you see the panic.

Tom · May 2, 2015, 8:37am

well, there’s a panic log in the 1st post of this thread.

Meanwhile I have wiped the index & config, and added only the 1 share. It is being indexed. Gonna take a while, it’s 3.4 Tb of data across approx 500 files. Waiting for the point where it’ll panic…

Tom · May 3, 2015, 7:53am

it took the better part of 23 hours, but it panicked.

panic log: http://pastebin.com/t9TjXyWr

Also, the resulting index files are numerous, as in >2000 ldb files, which is similar to a bug i reported here : >2k .ldb files in %localappdata%/syncthing/index/ · Issue #1480 · syncthing/syncthing · GitHub

calmh · May 3, 2015, 7:56am

Certainly looks like we’re running into some kind of database bug, perhaps related to the amount of data. I’ll whip something up to simulate an index for that amount data / files…

calmh · May 3, 2015, 2:12pm

For what it’s wort, I can’t reproduce this by writing indexes for 500 x 7 GB files, and changing / listing them from the database. The database also doesn’t grow beyond about 50 ldb files when doing this…

Tom · May 3, 2015, 3:18pm

can i send you the ldb files? Or is there some tool that i can use to see what’s going on in the ldb’s ?

calmh · May 3, 2015, 3:46pm

There’s a tool to list the indexes, but it kind of assumes that the database is not corrupt. This is a library we use, so I’m not really sure how to troubleshoot it without being able to reproduce… You could pack up the index directory and send a link to me in PM, perhaps something is extractable from it that may point to the root cause, or let me make a more accurate simulation of it so I can reproduce it myself perhaps…

Tom · May 4, 2015, 8:06am

PM sent

= 20 chars.

Tom · May 12, 2015, 8:32am

guys… this keeps happening. Here’s the latest panic log : http://pastebin.com/3dgDHhEL Please help ?