You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@bookkeeper.apache.org by GitBox <gi...@apache.org> on 2021/07/23 08:20:34 UTC
[GitHub] [bookkeeper] Vanlightly commented on issue #2528: Broken Bookie
Vanlightly commented on issue #2528:
URL: https://github.com/apache/bookkeeper/issues/2528#issuecomment-885479682
Hi,
This is an issue with entry log corruption, I was planning on posting this
very problem this week.
I was investigating an entry log corruption we had in production and ran
long running system tests to try and reproduce. I hit this issue on every
test within a few hours or a couple of days.
Normally you would use the DbLedgerStorage with Pulsar but I had
accidentally set BookKeeper to use SortedLedgerStorage for my tests. When I
switched to DbLedgerStorage I could no longer trigger issues related to
entry log corruption.
I have not nailed down the cause of why SortedLedgerStorage is corrupting
entry log files. I don't have the free capacity to devote to this issue,
given that we only use DbLedgerStorage. But this issue needs fixing
urgently for anyone using SortedLedgerStorage.
To reproduce simply run a test on a real deployed BookKeeper cluster with
SortedLedgerStorage and you will see errors in the garbage collector
related to:
- negative position in buffer
- bad ledger ids
- OutOfMemory exceptions because the entry length is bad (attempts to
allocate buffers as large as 2GB).
Jack
On Fri, Jul 23, 2021 at 5:07 AM choi se ***@***.***> wrote:
> One pulsar-2.8.0 Bookies node was a problem.
> pulsar-2.7.2 downgrade
>
> 18:00:37.715 [SortedLedgerStorage-0] INFO org.apache.bookkeeper.bookie.EntryLogManagerForSingleEntryLog - Rolling entry logger since it reached size limitation
> 18:00:37.715 [SortedLedgerStorage-0] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file due to reaching log limit after flushing memtable : logIdBeforeFlush = 12784, logIdAfterFlush = 12784
> 18:00:37.716 [SortedLedgerStorage-0] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Flushing entry logger 12784 back to filesystem, pending for syncing entry loggers : [BufferedChannel{logId=12784, logFile=/data/bookkeeper/ledgers/current/31f0.log, ledgerIdAssigned=-1}].
> 18:00:37.716 [SyncThread-7-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file due to preparing checkpoint : numBytesFlushed = 119500
> 18:00:37.716 [pool-5-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /data/bookkeeper/ledgers/current/31f2.log for logId 12786.
> 18:00:37.717 [SyncThread-7-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Flushing entry logger 12785 back to filesystem, pending for syncing entry loggers : [BufferedChannel{logId=12784, logFile=/data/bookkeeper/ledgers/current/31f0.log, ledgerIdAssigned=-1}, BufferedChannel{logId=12785, logFile=/data/bookkeeper/ledgers/current/31f1.log, ledgerIdAssigned=-1}].
> 18:00:37.717 [pool-5-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /data/bookkeeper/ledgers/current/31f3.log for logId 12787.
> 18:00:37.757 [SyncThread-7-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerForSingleEntryLog - Synced entry logger 12784 to disk.
> 18:00:37.766 [SyncThread-7-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerForSingleEntryLog - Synced entry logger 12785 to disk.
> 18:01:02.256 [GarbageCollectorThread-8-1] INFO org.apache.bookkeeper.bookie.GarbageCollectorThread - Extracting entry log meta from entryLogId: 11410
> 18:01:02.256 [GarbageCollectorThread-8-1] INFO org.apache.bookkeeper.bookie.EntryLogger - Failed to get ledgers map index from: 11410.log : Cannot deserialize ledgers map from ledger 433791696895
> 18:01:02.271 [GarbageCollectorThread-8-1] ERROR org.apache.bookkeeper.common.util.SafeRunnable - Unexpected throwable caught
> java.lang.IllegalArgumentException: Negative position
> at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:785) ~[?:?]
> at org.apache.bookkeeper.bookie.BufferedReadChannel.read(BufferedReadChannel.java:93) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.BufferedReadChannel.read(BufferedReadChannel.java:65) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.EntryLogger.readFromLogChannel(EntryLogger.java:418) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:996) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.EntryLogger.extractEntryLogMetadataByScanning(EntryLogger.java:1136) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.EntryLogger.getEntryLogMetadata(EntryLogger.java:1045) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLogs(GarbageCollectorThread.java:607) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.GarbageCollectorThread.runWithFlags(GarbageCollectorThread.java:348) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.bookie.GarbageCollectorThread.safeRun(GarbageCollectorThread.java:329) ~[org.apache.bookkeeper-bookkeeper-server-4.14.1.jar:4.14.1]
> at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.14.1.jar:4.14.1]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at java.lang.Thread.run(Thread.java:830) [?:?]
>
> —
> You are receiving this because you are subscribed to this thread.
> Reply to this email directly, view it on GitHub
> <https://github.com/apache/bookkeeper/issues/2528#issuecomment-885367602>,
> or unsubscribe
> <https://github.com/notifications/unsubscribe-auth/ABG3JYHAZJJSBEPMSVRHJSLTZDMFVANCNFSM4VYJQB3Q>
> .
>
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@bookkeeper.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org