apache / apache/bookkeeper

Failed to compact entry log due to entry corrupted

Open
#3,302 0 comments 0 reactions 0 assignees View on GitHub
type/bug
Dominant language
Java
Stars
2k
Forks
976
Avg merge
6d 15h
Merged PRs (30d)
7

Description

**BUG REPORT**
```
2022-05-31T02:17:59.782Z [GarbageCollectorThread-21-1] ERROR org.apache.bookkeeper.bookie.GarbageCollectorThread - Failed to compact entry log 168485 due to unexpected error
java.lang.IllegalArgumentException: Keys and values must be >= 0
at org.apache.bookkeeper.util.collections.ConcurrentLongLongHashMap.checkBiggerEqualZero(ConcurrentLongLongHashMap.java:731) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.util.collections.ConcurrentLongLongHashMap.get(ConcurrentLongLongHashMap.java:141) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.util.collections.ConcurrentLongLongHashMap.containsKey(ConcurrentLongLongHashMap.java:147) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.EntryLogMetadata.containsLedger(EntryLogMetadata.java:51) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.EntryLogCompactor$CompactionScannerFactory$1.accept(EntryLogCompactor.java:90) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:1006) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.EntryLogCompactor.compact(EntryLogCompactor.java:61) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.GarbageCollectorThread.compactEntryLog(GarbageCollectorThread.java:568) [org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.GarbageCollectorThread.doCompactEntryLogs(GarbageCollectorThread.java:487) [org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.GarbageCollectorThread.runWithFlags(GarbageCollectorThread.java:382) [org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.bookie.GarbageCollectorThread.safeRun(GarbageCollectorThread.java:329) [org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_181]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_181]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_181]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_181]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_181]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_181]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.66.Final.jar:4.1.66.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181]
```

bookkeeper shell readlog output
```shell
$ bin/bookkeeper shell readlog 168485 | grep -C 20 Lid=-
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115949451, Eid=33113, ByteOffset=373375423, EntrySize=69 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 33112
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115949451, Eid=33114, ByteOffset=373375496, EntrySize=93 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 33113
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115949451, Eid=33118, ByteOffset=373375593, EntrySize=141 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 33117
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115949451, Eid=33119, ByteOffset=373375738, EntrySize=141 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 33118
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115949451, Eid=33123, ByteOffset=373375883, EntrySize=93 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 33122
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=-4637262668357016223, Eid=8391660762646604388, ByteOffset=373375980, EntrySize=310 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 6875430249433430384
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115952027, Eid=320654, ByteOffset=373376294, EntrySize=311 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 320649
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115952027, Eid=320657, ByteOffset=373376609, EntrySize=348 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 320649
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115952027, Eid=320658, ByteOffset=373376961, EntrySize=333 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 320649
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115952027, Eid=320661, ByteOffset=373377298, EntrySize=310 ---------
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - Type: DATA
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - LastConfirmed: 320649
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil -
11:54:16.384 [main] INFO org.apache.bookkeeper.tools.cli.commands.bookie.FormatUtil - --------- Lid=115952027, Eid=320662, ByteOffset=373377612, EntrySize=1489 ---------
```

As we can see above, there is a negative ledger number `-4637262668357016223`, I think it is entry somehow **corrupted**.

I cannot reproduce yet, let me know if need any details.

***Additional context***

Related https://github.com/apache/bookkeeper/issues/2103#issuecomment-501576069

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.