[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Michael Andre Pearce (IG) updated KAFKA-4497:
-
Attachment: log-cleaner.log.1.zip
logcleaner log for error on 0.10.1.1 @2017-01-05 19:37:07,144
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Labels: reliability
> Fix For: 0.10.1.1
>
> Attachments: com_ig_trade_v1_order_event--demo--compacted-7.tar.bz2,
> com_ig_trade_v1_position_event--demo--compacted-14.tar.gz,
> log-cleaner.log.1.zip, vrtstokf005_4thJan
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
>
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Michael Andre Pearce (IG) updated KAFKA-4497:
-
Attachment: com_ig_trade_v1_position_event--demo--compacted-14.tar.gz
partiton/segment logs for issue on 0.10.1.1 - 2017-01-05 19:37:07,144
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Labels: reliability
> Fix For: 0.10.1.1
>
> Attachments: com_ig_trade_v1_order_event--demo--compacted-7.tar.bz2,
> com_ig_trade_v1_position_event--demo--compacted-14.tar.gz, vrtstokf005_4thJan
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
>
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Michael Andre Pearce (IG) updated KAFKA-4497:
-
Attachment: vrtstokf005_4thJan
[~becket_qin] we have managed to recover the log4j cleaner log from yesterdays,
from the same node we supplied the log segments.
We have now re rolled back forward that testing environment back onto 0.10.1.1
and waiting for it to re-occur. (bear in mind we had been running 6 weeks
before we saw the issue, we cannot tell how long we will have to wait)
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Labels: reliability
> Fix For: 0.10.1.1
>
> Attachments: com_ig_trade_v1_order_event--demo--compacted-7.tar.bz2,
> vrtstokf005_4thJan
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Michael Andre Pearce (IG) updated KAFKA-4497:
-
Attachment: com_ig_trade_v1_order_event--demo--compacted-7.tar.bz2
[~junrao] files (logs and everything) from the partition testing env, where we
had it occur at 15:52 today (4th Jan 2017) .
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Labels: reliability
> Fix For: 0.10.1.1
>
> Attachments: com_ig_trade_v1_order_event--demo--compacted-7.tar.bz2
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
>
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ismael Juma updated KAFKA-4497:
---
Labels: reliability (was: )
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Labels: reliability
> Fix For: 0.10.1.1
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:404)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:400)
> at scala.collection.immutable.List.foreach(List.scala:381)
> at kafka.log.Cleaner.cleanSegments(LogCleaner.scala:400)
>
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ismael Juma updated KAFKA-4497:
---
Fix Version/s: 0.10.1.1
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Assignee: Jiangjie Qin
>Priority: Critical
> Fix For: 0.10.1.1
>
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:404)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:400)
> at scala.collection.immutable.List.foreach(List.scala:381)
> at kafka.log.Cleaner.cleanSegments(LogCleaner.scala:400)
> at
[jira] [Updated] (KAFKA-4497) log cleaner breaks on timeindex
[
https://issues.apache.org/jira/browse/KAFKA-4497?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ismael Juma updated KAFKA-4497:
---
Priority: Critical (was: Major)
> log cleaner breaks on timeindex
> ---
>
> Key: KAFKA-4497
> URL: https://issues.apache.org/jira/browse/KAFKA-4497
> Project: Kafka
> Issue Type: Bug
> Components: log
>Affects Versions: 0.10.1.0
> Environment: Debian Jessie, Oracle Java 8u92, kafka_2.11-0.10.1.0
>Reporter: Robert Schumann
>Priority: Critical
>
> _created from ML entry by request of [~ijuma]_
> Hi all,
> we are facing an issue with latest kafka 0.10.1 and the log cleaner thread
> with regards to the timeindex files. From the log of the log-cleaner we see
> after startup that it tries to cleanup a topic called xdc_listing-status-v2
> [1]. The topic is setup with log compaction [2] and the kafka cluster
> configuration has log.cleaner enabled [3]. Looking at the log and the newly
> created file [4], the cleaner seems to refer to tombstones prior to
> epoch_time=0 - maybe because he finds messages, which don’t have a timestamp
> at all (?). All producers and consumers are using 0.10.1 and the topics have
> been created completely new, so I’m not sure, where this issue would come
> from. The original timeindex file [5] seems to show only valid timestamps for
> the mentioned offsets. I would also like to mention that the issue happened
> in two independent datacenters at the same time, so I would rather expect an
> application/producer issue instead of random disk failures. We didn’t have
> the problem with 0.10.0 for around half a year, it appeared shortly after the
> upgrade to 0.10.1.
> The puzzling message from the cleaner “cleaning prior to Fri Dec 02 16:35:50
> CET 2016, discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970” also
> confuses me a bit. Does that mean, it does not find any log segments which
> can be cleaned up or the last timestamp of the last log segment is somehow
> broken/missing?
> I’m also a bit wondering, why the log cleaner thread stops completely after
> an error with one topic. I would at least expect that it keeps on cleaning up
> other topics, but apparently it doesn’t do that, e.g. it’s not even cleaning
> the __consumer_offsets anymore.
> Does anybody have the same issues or can explain, what’s going on? Thanks for
> any help or suggestions.
> Cheers
> Robert
> [1]
> {noformat}
> [2016-12-06 12:49:17,885] INFO Starting the log cleaner (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,895] INFO [kafka-log-cleaner-thread-0], Starting
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,947] INFO Cleaner 0: Beginning cleaning of log
> xdc_listing-status-v2-1. (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,948] INFO Cleaner 0: Building offset map for
> xdc_listing-status-v2-1... (kafka.log.LogCleaner)
> [2016-12-06 12:49:17,989] INFO Cleaner 0: Building offset map for log
> xdc_listing-status-v2-1 for 1 segments in offset range [0, 194991).
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,572] INFO Cleaner 0: Offset map for log
> xdc_listing-status-v2-1 complete. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,577] INFO Cleaner 0: Cleaning log
> xdc_listing-status-v2-1 (cleaning prior to Fri Dec 02 16:35:50 CET 2016,
> discarding tombstones prior to Thu Jan 01 01:00:00 CET 1970)...
> (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,580] INFO Cleaner 0: Cleaning segment 0 in log
> xdc_listing-status-v2-1 (largest timestamp Fri Dec 02 16:35:50 CET 2016) into
> 0, retaining deletes. (kafka.log.LogCleaner)
> [2016-12-06 12:49:24,968] ERROR [kafka-log-cleaner-thread-0], Error due to
> (kafka.log.LogCleaner)
> kafka.common.InvalidOffsetException: Attempt to append an offset (-1) to slot
> 9 no larger than the last offset appended (11832) to
> /var/lib/kafka/xdc_listing-status-v2-1/.timeindex.cleaned.
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply$mcV$sp(TimeIndex.scala:117)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at
> kafka.log.TimeIndex$$anonfun$maybeAppend$1.apply(TimeIndex.scala:107)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:234)
> at kafka.log.TimeIndex.maybeAppend(TimeIndex.scala:107)
> at kafka.log.LogSegment.append(LogSegment.scala:106)
> at kafka.log.Cleaner.cleanInto(LogCleaner.scala:518)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:404)
> at
> kafka.log.Cleaner$$anonfun$cleanSegments$1.apply(LogCleaner.scala:400)
> at scala.collection.immutable.List.foreach(List.scala:381)
> at kafka.log.Cleaner.cleanSegments(LogCleaner.scala:400)
> at kafka.log.Cleaner$$anonfun$clean$4.apply(LogCleaner.scala:364)
> at
