Mark Figura created KAFKA-4496:
----------------------------------
Summary: LogCleaner thread exits with NoSuchElementException
Key: KAFKA-4496
URL: https://issues.apache.org/jira/browse/KAFKA-4496
Project: Kafka
Issue Type: Bug
Components: core, offset manager
Affects Versions: 0.8.2.1
Environment: SLES 11.3, 20 node cluster
Reporter: Mark Figura
After running for some time (about 60 hours in this case), we are seeing the
LogCleaner thread exit with the messages below. Because of this, the
consumer_offsets topic grows very large over time.
[2016-12-01 20:00:44,050] INFO Cleaner 0: Building offset map for
__consumer_offsets-19... (kafka.log.LogCleaner)
[2016-12-01 20:00:44,183] INFO Cleaner 0: Building offset map for log
__consumer_offsets-19 for 0 segments in offset range [15698821, 0).
(kafka.log.LogCleaner)
[2016-12-01 20:00:44,220] ERROR [kafka-log-cleaner-thread-0], Error due to
(kafka.log.LogCleaner)
java.util.NoSuchElementException: head of empty stream
at scala.collection.immutable.Stream$Empty$.head(Stream.scala:1028)
at scala.collection.immutable.Stream$Empty$.head(Stream.scala:1026)
at kafka.log.Cleaner.buildOffsetMap(LogCleaner.scala:508)
at kafka.log.Cleaner.clean(LogCleaner.scala:307)
at kafka.log.LogCleaner$CleanerThread.cleanOrSleep(LogCleaner.scala:221)
at kafka.log.LogCleaner$CleanerThread.doWork(LogCleaner.scala:199)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:60)
[2016-12-01 20:00:44,221] INFO [kafka-log-cleaner-thread-0], Stopped
(kafka.log.LogCleaner)
This looks similar to some other issues (KAFKA-1641, KAFKA-2235, etc.) but does
not match exactly.
Here is the server.properties:
delete.topic.enable=true
socket.send.buffer.bytes=102400
socket.request.max.bytes=104857600
log.cleaner.enable=true
log.retention.check.interval.ms=300000
zookeeper.session.timeout.ms=30000
num.io.threads=8
broker.id=0
port=9092
log.dirs=/kafka/broker_0
auto.create.topics.enable=false
num.network.threads=3
socket.receive.buffer.bytes=102400
log.retention.minutes=10
log.cleaner.delete.retention.ms=1800000
log.segment.bytes=1073741824
num.recovery.threads.per.data.dir=1
num.partitions=1
zookeeper.connection.timeout.ms=30000
zookeeper.connect=<zk servers>
...and here's what one of the consumer-offsets data directories looks like:
kafka1:/kafka/broker_0/__consumer_offsets-19 # ls -lrt
total 2611332
-rw-r--r-- 1 yarn yarn 104857433 Dec 1 23:17 00000000000000000000.log
-rw-r--r-- 1 yarn yarn 182272 Dec 1 23:17 00000000000000000000.index
-rw-r--r-- 1 yarn yarn 104857592 Dec 2 05:44 00000000000016820302.log
-rw-r--r-- 1 yarn yarn 201880 Dec 2 05:44 00000000000016820302.index
-rw-r--r-- 1 yarn yarn 104857497 Dec 2 10:18 00000000000017939487.log
-rw-r--r-- 1 yarn yarn 201464 Dec 2 10:18 00000000000017939487.index
-rw-r--r-- 1 yarn yarn 104857302 Dec 2 14:04 00000000000019061235.log
-rw-r--r-- 1 yarn yarn 201176 Dec 2 14:04 00000000000019061235.index
-rw-r--r-- 1 yarn yarn 104857594 Dec 2 17:43 00000000000020184726.log
-rw-r--r-- 1 yarn yarn 201120 Dec 2 17:43 00000000000020184726.index
-rw-r--r-- 1 yarn yarn 104857523 Dec 2 21:51 00000000000021308472.log
-rw-r--r-- 1 yarn yarn 201288 Dec 2 21:51 00000000000021308472.index
-rw-r--r-- 1 yarn yarn 104857509 Dec 3 03:20 00000000000022430910.log
-rw-r--r-- 1 yarn yarn 201600 Dec 3 03:20 00000000000022430910.index
-rw-r--r-- 1 yarn yarn 104857562 Dec 3 09:14 00000000000023551782.log
-rw-r--r-- 1 yarn yarn 201696 Dec 3 09:14 00000000000023551782.index
-rw-r--r-- 1 yarn yarn 104857526 Dec 3 13:12 00000000000024671856.log
-rw-r--r-- 1 yarn yarn 201216 Dec 3 13:12 00000000000024671856.index
-rw-r--r-- 1 yarn yarn 104857591 Dec 3 17:03 00000000000025794239.log
-rw-r--r-- 1 yarn yarn 201152 Dec 3 17:03 00000000000025794239.index
-rw-r--r-- 1 yarn yarn 104857522 Dec 3 21:17 00000000000026917212.log
-rw-r--r-- 1 yarn yarn 201336 Dec 3 21:17 00000000000026917212.index
-rw-r--r-- 1 yarn yarn 104857160 Dec 4 02:31 00000000000028039274.log
-rw-r--r-- 1 yarn yarn 201624 Dec 4 02:31 00000000000028039274.index
-rw-r--r-- 1 yarn yarn 104857524 Dec 4 08:49 00000000000029160221.log
-rw-r--r-- 1 yarn yarn 201728 Dec 4 08:49 00000000000029160221.index
-rw-r--r-- 1 yarn yarn 104857579 Dec 4 13:09 00000000000030279870.log
-rw-r--r-- 1 yarn yarn 201344 Dec 4 13:09 00000000000030279870.index
-rw-r--r-- 1 yarn yarn 104857581 Dec 4 17:10 00000000000031401545.log
-rw-r--r-- 1 yarn yarn 201320 Dec 4 17:10 00000000000031401545.index
-rw-r--r-- 1 yarn yarn 104857338 Dec 4 21:36 00000000000032523747.log
-rw-r--r-- 1 yarn yarn 201456 Dec 4 21:36 00000000000032523747.index
-rw-r--r-- 1 yarn yarn 104857579 Dec 5 03:38 00000000000033645679.log
-rw-r--r-- 1 yarn yarn 201744 Dec 5 03:38 00000000000033645679.index
-rw-r--r-- 1 yarn yarn 104857511 Dec 5 09:07 00000000000034765482.log
-rw-r--r-- 1 yarn yarn 201656 Dec 5 09:07 00000000000034765482.index
-rw-r--r-- 1 yarn yarn 104857537 Dec 5 13:00 00000000000035885509.log
-rw-r--r-- 1 yarn yarn 201224 Dec 5 13:00 00000000000035885509.index
-rw-r--r-- 1 yarn yarn 104857594 Dec 5 16:43 00000000000037008566.log
-rw-r--r-- 1 yarn yarn 201056 Dec 5 16:43 00000000000037008566.index
-rw-r--r-- 1 yarn yarn 104857407 Dec 5 20:49 00000000000038132175.log
-rw-r--r-- 1 yarn yarn 201192 Dec 5 20:49 00000000000038132175.index
-rw-r--r-- 1 yarn yarn 104857598 Dec 6 02:34 00000000000039255111.log
-rw-r--r-- 1 yarn yarn 201568 Dec 6 02:34 00000000000039255111.index
-rw-r--r-- 1 yarn yarn 104857531 Dec 6 08:30 00000000000040375848.log
-rw-r--r-- 1 yarn yarn 201736 Dec 6 08:30 00000000000040375848.index
-rw-r--r-- 1 yarn yarn 104857567 Dec 6 12:23 00000000000041495389.log
-rw-r--r-- 1 yarn yarn 201288 Dec 6 12:23 00000000000041495389.index
-rw-r--r-- 1 yarn yarn 104857542 Dec 6 16:07 00000000000042618234.log
-rw-r--r-- 1 yarn yarn 201088 Dec 6 16:07 00000000000042618234.index
-rw-r--r-- 1 yarn yarn 10485760 Dec 6 17:40 00000000000043741475.index
-rw-r--r-- 1 yarn yarn 44560223 Dec 6 17:40 00000000000043741475.log
Prior to the thread exiting, we see the compacted directories containing only
about 6 files or 100MB max (as expected).
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
