This smells like an bug to me. On Wed, Jun 22, 2016 at 6:54 PM, Lawrence Weikum <lwei...@pandora.com> wrote:
> Fascinating. > > We are seeing no errors or warning in the logs after restart. It appears > on this broker that the compaction thread is working: > > [2016-06-22 10:33:49,179] INFO Rolled new log segment for > '__consumer_offsets-28' in 1 ms. (kafka.log.Log) > [2016-06-22 10:34:00,968] INFO Deleting segment 0 from log > __consumer_offsets-28. (kafka.log.Log) > [2016-06-22 10:34:00,970] INFO Deleting index > /kafka/data/__consumer_offsets-28/00000000000000000000.index.deleted > (kafka.log.OffsetIndex) > [2016-06-22 10:34:00,992] INFO Deleting segment 2148144095 from log > __consumer_offsets-28. (kafka.log.Log) > [2016-06-22 10:34:00,994] INFO Deleting index > /kafka/data/__consumer_offsets-28/00000000002148144095.index.deleted > (kafka.log.OffsetIndex) > [2016-06-22 10:34:01,002] INFO Deleting segment 3189277822 from log > __consumer_offsets-28. (kafka.log.Log) > [2016-06-22 10:34:01,004] INFO Deleting index > /kafka/data/__consumer_offsets-28/00000000003189277822.index.deleted > (kafka.log.OffsetIndex) > [2016-06-22 10:34:02,019] INFO Deleting segment 3190205744 from log > __consumer_offsets-28. (kafka.log.Log) > [2016-06-22 10:34:02,039] INFO Deleting index > /kafka/data/__consumer_offsets-28/00000000003190205744.index.deleted > (kafka.log.OffsetIndex) > > We see the “kafka-log-cleaner-thread” in the JMX. It seems to run about > every 50 seconds. From the log-cleaner.log file, we see plenty of this > output regarding the partition that’s hogging the FDs: > > [2016-06-22 10:44:31,845] INFO Cleaner 0: Beginning cleaning of log > __consumer_offsets-28. (kafka.log.LogCleaner) > [2016-06-22 10:44:31,846] INFO Cleaner 0: Building offset map for > __consumer_offsets-28... (kafka.log.LogCleaner) > [2016-06-22 10:44:31,878] INFO Cleaner 0: Building offset map for log > __consumer_offsets-28 for 1 segments in offset range [3204124461, > 3205052375). (kafka.log.LogCleaner) > [2016-06-22 10:44:32,870] INFO Cleaner 0: Offset map for log > __consumer_offsets-28 complete. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,871] INFO Cleaner 0: Cleaning log > __consumer_offsets-28 (discarding tombstones prior to Tue Jun 21 10:43:19 > PDT 2016)... (kafka.log.LogCleaner) > [2016-06-22 10:44:32,871] INFO Cleaner 0: Cleaning segment 0 in log > __consumer_offsets-28 (last modified Tue Jun 21 22:39:18 PDT 2016) into 0, > retaining deletes. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,888] INFO Cleaner 0: Swapping in cleaned segment 0 > for segment(s) 0 in log __consumer_offsets-28. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,889] INFO Cleaner 0: Cleaning segment 2148144095 in > log __consumer_offsets-28 (last modified Wed Jun 22 10:42:31 PDT 2016) into > 2148144095, retaining deletes. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,889] INFO Cleaner 0: Cleaning segment 3203196540 in > log __consumer_offsets-28 (last modified Wed Jun 22 10:43:19 PDT 2016) into > 2148144095, retaining deletes. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,905] INFO Cleaner 0: Swapping in cleaned segment > 2148144095 for segment(s) 2148144095,3203196540 in log > __consumer_offsets-28. (kafka.log.LogCleaner) > [2016-06-22 10:44:32,905] INFO Cleaner 0: Cleaning segment 3204124461 in > log __consumer_offsets-28 (last modified Wed Jun 22 10:44:21 PDT 2016) into > 3204124461, retaining deletes. (kafka.log.LogCleaner) > [2016-06-22 10:44:33,834] INFO Cleaner 0: Swapping in cleaned segment > 3204124461 for segment(s) 3204124461 in log __consumer_offsets-28. > (kafka.log.LogCleaner) > [2016-06-22 10:44:33,836] INFO [kafka-log-cleaner-thread-0], > Log cleaner thread 0 cleaned log __consumer_offsets-28 (dirty > section = [3204124461, 3205052375]) > 100.0 MB of log processed in 2.0 seconds (50.3 MB/sec). > Indexed 100.0 MB in 1.0 seconds (97.6 Mb/sec, 51.5% of total time) > Buffer utilization: 0.0% > Cleaned 100.0 MB in 1.0 seconds (103.6 Mb/sec, 48.5% of total time) > Start size: 100.0 MB (928,011 messages) > End size: 0.0 MB (97 messages) > 100.0% size reduction (100.0% fewer messages) > (kafka.log.LogCleaner) > > But no actual delete messages like a properly-working broker is showing of > a different partition. > > Lawrence Weikum > > > On 6/22/16, 11:28 AM, "Tom Crayford" <tcrayf...@heroku.com> wrote: > > kafka-log-cleaner-thread-0 > >
