You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by mostolog <mo...@gmail.com> on 2017/07/26 20:48:58 UTC
Re: Logs truncated hourly
still I haven't been able to figure out what's the problem...
> On 13/07/17 17:09, mostolog@gmail.com
> <javascript:_e(%7B%7D,'cvml','mostolog@gmail.com');> wrote:
>
> Hi
>
> With swiss precission, our kafka test environment seems to truncate topics
> at o'clock hours.
>
> This might be confirmed with the following trace, which states "Truncating
> log ... to offset 0"
>
> We are still using Kafka 0.10.2.1, but I was wondering if this is resolved
> in recent versions, it's a know bug or just a misconfiguration (I think it
> is shown below).
>
> Thanks
>
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,986] INFO
> [TopicChangeListener on Controller 1002]: New topics:
> [Set(mytopic.2017-07-13-16)], deleted topics: [Set()], new partition
> replica assignment [Map([mytopic.2017-07-13-16,0] -> List(1001, 1002),
> [mytopic.2017-07-13-16,2] -> List(1003, 1001), [mytopic.2017-07-13-16,1] ->
> List(1002, 1003))] (kafka.controller.PartitionStateMachine$
> TopicChangeListener)
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,987] INFO
> [Controller 1002]: New topic creation callback for
> [mytopic.2017-07-13-16,0],[mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1]
> (kafka.controller.KafkaController)
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> [Controller 1002]: New partition creation callback for
> [mytopic.2017-07-13-16,0],[mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1]
> (kafka.controller.KafkaController)
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> [Partition state machine on Controller 1002]: Invoking state change to
> NewPartition for partitions [mytopic.2017-07-13-16,0],[
> mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1] (kafka.controller.
> PartitionStateMachine)
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> [Replica state machine on controller 1002]: Invoking state change to
> NewReplica for replicas [Topic=mytopic.2017-07-13-16,
> Partition=1,Replica=1003],[Topic=mytopic.2017-07-13-16,
> Partition=0,Replica=1001],[Topic=mytopic.2017-07-13-16,
> Partition=2,Replica=1001],[Topic=mytopic.2017-07-13-16,
> Partition=1,Replica=1002],[Topic=mytopic.2017-07-13-16,
> Partition=2,Replica=1003],[Topic=mytopic.2017-07-13-16,Partition=0,Replica=1002]
> (kafka.controller.ReplicaStateMachine)
> Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,993] INFO
> [Partition state machine on Controller 1002]: Invoking state change to
> OnlinePartition for partitions [mytopic.2017-07-13-16,0],[
> mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1] (kafka.controller.
> PartitionStateMachine)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,036] INFO
> [Replica state machine on controller 1002]: Invoking state change to
> OnlineReplica for replicas [Topic=mytopic.2017-07-13-16,
> Partition=1,Replica=1003],[Topic=mytopic.2017-07-13-16,
> Partition=0,Replica=1001],[Topic=mytopic.2017-07-13-16,
> Partition=2,Replica=1001],[Topic=mytopic.2017-07-13-16,
> Partition=1,Replica=1002],[Topic=mytopic.2017-07-13-16,
> Partition=2,Replica=1003],[Topic=mytopic.2017-07-13-16,Partition=0,Replica=1002]
> (kafka.controller.ReplicaStateMachine)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,037] INFO
> [ReplicaFetcherManager on broker 1002] Removed fetcher for partitions
> mytopic.2017-07-13-16-1 (kafka.server.ReplicaFetcherManager)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,039] INFO
> Completed load of log mytopic.2017-07-13-16-1 with 1 log segments and log
> end offset 0 in 0 ms (kafka.log.Log)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,040] INFO
> Created log for partition [mytopic.2017-07-13-16,1] in /data/kafka-1 with
> properties {compression.type -> producer, message.format.version ->
> 0.10.2-IV0, file.delete.delay.ms -> 60000, max.message.bytes -> 1000012,
> min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime,
> min.insync.replicas -> 1, segment.jitter.ms -> 0, preallocate -> false,
> min.cleanable.dirty.ratio -> 0.5, index.interval.bytes -> 4096,
> unclean.leader.election.enable -> true, retention.bytes -> -1,
> delete.retention.ms -> 3600000, cleanup.policy -> [delete], flush.ms ->
> 300000, segment.ms -> 600000, segment.bytes -> 1073741824, retention.ms
> -> 14400000, message.timestamp.difference.max.ms -> 9223372036854775807,
> segment.index.bytes -> 10485760, flush.messages -> 10000}.
> (kafka.log.LogManager)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,045] INFO
> Partition [mytopic.2017-07-13-16,1] on broker 1002: No checkpointed
> highwatermark is found for partition mytopic.2017-07-13-16-1
> (kafka.cluster.Partition)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,047] INFO
> Completed load of log mytopic.2017-07-13-16-0 with 1 log segments and log
> end offset 0 in 1 ms (kafka.log.Log)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,047] INFO
> Created log for partition [mytopic.2017-07-13-16,0] in /data/kafka-1 with
> properties {compression.type -> producer, message.format.version ->
> 0.10.2-IV0, file.delete.delay.ms -> 60000, max.message.bytes -> 1000012,
> min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime,
> min.insync.replicas -> 1, segment.jitter.ms -> 0, preallocate -> false,
> min.cleanable.dirty.ratio -> 0.5, index.interval.bytes -> 4096,
> unclean.leader.election.enable -> true, retention.bytes -> -1,
> delete.retention.ms -> 3600000, cleanup.policy -> [delete], flush.ms ->
> 300000, segment.ms -> 600000, segment.bytes -> 1073741824, retention.ms
> -> 14400000, message.timestamp.difference.max.ms -> 9223372036854775807,
> segment.index.bytes -> 10485760, flush.messages -> 10000}.
> (kafka.log.LogManager)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> Partition [mytopic.2017-07-13-16,0] on broker 1002: No checkpointed
> highwatermark is found for partition mytopic.2017-07-13-16-0
> (kafka.cluster.Partition)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> [ReplicaFetcherManager on broker 1002] Removed fetcher for partitions
> mytopic.2017-07-13-16-0 (kafka.server.ReplicaFetcherManager)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> Truncating log mytopic.2017-07-13-16-0 to offset 0. (kafka.log.Log)
> Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,059] INFO
> [ReplicaFetcherManager on broker 1002] Added fetcher for partitions
> List([mytopic.2017-07-13-16-0, initOffset 0 to broker
> BrokerEndPoint(1001,10.0.0.24,9092)] ) (kafka.server.
> ReplicaFetcherManager)
> Jul 13 16:00:03 computer kafka[28511]: [2017-07-13 16:00:03,614] ERROR
> [ReplicaFetcherThread-0-1001], Error for partition
> [mytopic.2017-07-13-16,0] to broker 1001:org.apache.kafka.common.errors.
> UnknownTopicOrPartitionException: This server does not host this
> topic-partition. (kafka.server.ReplicaFetcherThread)
>
>
>
>
>
Re: Logs truncated hourly
Posted by Manikumar <ma...@gmail.com>.
logs look normal to me. It looks like you are creating a new topic for
every hour?
from logs:
16:00:01 : Created log for partition [mytopic.2017-07-13-16,0] (this is
replica log for partition 0)
16:00:01: Truncating log mytopic.2017-07-13-16-0 to offset 0 (This should
be harmless)
Not sure, Why are we seeing data loss here?
16:00:03: [mytopic.2017-07-13-16,0] to broker
1001:org.apache.kafka.common.errors. UnknownTopicOrPartitionException
This may transient error. Are you seeing this continusly?
Also, you are using replication factor =2 and min.insync.replicas = 1. To
avoid data loss,
we should configure at-least replication factor =3 and min.insync.replicas
=2.
On Thu, Jul 27, 2017 at 2:18 AM, mostolog <mo...@gmail.com> wrote:
> still I haven't been able to figure out what's the problem...
>
>
> > On 13/07/17 17:09, mostolog@gmail.com
> > <javascript:_e(%7B%7D,'cvml','mostolog@gmail.com');> wrote:
> >
> > Hi
> >
> > With swiss precission, our kafka test environment seems to truncate
> topics
> > at o'clock hours.
> >
> > This might be confirmed with the following trace, which states
> "Truncating
> > log ... to offset 0"
> >
> > We are still using Kafka 0.10.2.1, but I was wondering if this is
> resolved
> > in recent versions, it's a know bug or just a misconfiguration (I think
> it
> > is shown below).
> >
> > Thanks
> >
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,986] INFO
> > [TopicChangeListener on Controller 1002]: New topics:
> > [Set(mytopic.2017-07-13-16)], deleted topics: [Set()], new partition
> > replica assignment [Map([mytopic.2017-07-13-16,0] -> List(1001, 1002),
> > [mytopic.2017-07-13-16,2] -> List(1003, 1001), [mytopic.2017-07-13-16,1]
> ->
> > List(1002, 1003))] (kafka.controller.PartitionStateMachine$
> > TopicChangeListener)
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,987] INFO
> > [Controller 1002]: New topic creation callback for
> > [mytopic.2017-07-13-16,0],[mytopic.2017-07-13-16,2],[mytopic
> .2017-07-13-16,1]
> > (kafka.controller.KafkaController)
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> > [Controller 1002]: New partition creation callback for
> > [mytopic.2017-07-13-16,0],[mytopic.2017-07-13-16,2],[mytopic
> .2017-07-13-16,1]
> > (kafka.controller.KafkaController)
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> > [Partition state machine on Controller 1002]: Invoking state change to
> > NewPartition for partitions [mytopic.2017-07-13-16,0],[
> > mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1] (kafka.controller.
> > PartitionStateMachine)
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,988] INFO
> > [Replica state machine on controller 1002]: Invoking state change to
> > NewReplica for replicas [Topic=mytopic.2017-07-13-16,
> > Partition=1,Replica=1003],[Topic=mytopic.2017-07-13-16,
> > Partition=0,Replica=1001],[Topic=mytopic.2017-07-13-16,
> > Partition=2,Replica=1001],[Topic=mytopic.2017-07-13-16,
> > Partition=1,Replica=1002],[Topic=mytopic.2017-07-13-16,
> > Partition=2,Replica=1003],[Topic=mytopic.2017-07-13-16,Parti
> tion=0,Replica=1002]
> > (kafka.controller.ReplicaStateMachine)
> > Jul 13 16:00:00 computer kafka[28511]: [2017-07-13 16:00:00,993] INFO
> > [Partition state machine on Controller 1002]: Invoking state change to
> > OnlinePartition for partitions [mytopic.2017-07-13-16,0],[
> > mytopic.2017-07-13-16,2],[mytopic.2017-07-13-16,1] (kafka.controller.
> > PartitionStateMachine)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,036] INFO
> > [Replica state machine on controller 1002]: Invoking state change to
> > OnlineReplica for replicas [Topic=mytopic.2017-07-13-16,
> > Partition=1,Replica=1003],[Topic=mytopic.2017-07-13-16,
> > Partition=0,Replica=1001],[Topic=mytopic.2017-07-13-16,
> > Partition=2,Replica=1001],[Topic=mytopic.2017-07-13-16,
> > Partition=1,Replica=1002],[Topic=mytopic.2017-07-13-16,
> > Partition=2,Replica=1003],[Topic=mytopic.2017-07-13-16,Parti
> tion=0,Replica=1002]
> > (kafka.controller.ReplicaStateMachine)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,037] INFO
> > [ReplicaFetcherManager on broker 1002] Removed fetcher for partitions
> > mytopic.2017-07-13-16-1 (kafka.server.ReplicaFetcherManager)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,039] INFO
> > Completed load of log mytopic.2017-07-13-16-1 with 1 log segments and log
> > end offset 0 in 0 ms (kafka.log.Log)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,040] INFO
> > Created log for partition [mytopic.2017-07-13-16,1] in /data/kafka-1 with
> > properties {compression.type -> producer, message.format.version ->
> > 0.10.2-IV0, file.delete.delay.ms -> 60000, max.message.bytes -> 1000012,
> > min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime,
> > min.insync.replicas -> 1, segment.jitter.ms -> 0, preallocate -> false,
> > min.cleanable.dirty.ratio -> 0.5, index.interval.bytes -> 4096,
> > unclean.leader.election.enable -> true, retention.bytes -> -1,
> > delete.retention.ms -> 3600000, cleanup.policy -> [delete], flush.ms ->
> > 300000, segment.ms -> 600000, segment.bytes -> 1073741824, retention.ms
> > -> 14400000, message.timestamp.difference.max.ms -> 9223372036854775807,
> > segment.index.bytes -> 10485760, flush.messages -> 10000}.
> > (kafka.log.LogManager)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,045] INFO
> > Partition [mytopic.2017-07-13-16,1] on broker 1002: No checkpointed
> > highwatermark is found for partition mytopic.2017-07-13-16-1
> > (kafka.cluster.Partition)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,047] INFO
> > Completed load of log mytopic.2017-07-13-16-0 with 1 log segments and log
> > end offset 0 in 1 ms (kafka.log.Log)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,047] INFO
> > Created log for partition [mytopic.2017-07-13-16,0] in /data/kafka-1 with
> > properties {compression.type -> producer, message.format.version ->
> > 0.10.2-IV0, file.delete.delay.ms -> 60000, max.message.bytes -> 1000012,
> > min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime,
> > min.insync.replicas -> 1, segment.jitter.ms -> 0, preallocate -> false,
> > min.cleanable.dirty.ratio -> 0.5, index.interval.bytes -> 4096,
> > unclean.leader.election.enable -> true, retention.bytes -> -1,
> > delete.retention.ms -> 3600000, cleanup.policy -> [delete], flush.ms ->
> > 300000, segment.ms -> 600000, segment.bytes -> 1073741824, retention.ms
> > -> 14400000, message.timestamp.difference.max.ms -> 9223372036854775807,
> > segment.index.bytes -> 10485760, flush.messages -> 10000}.
> > (kafka.log.LogManager)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> > Partition [mytopic.2017-07-13-16,0] on broker 1002: No checkpointed
> > highwatermark is found for partition mytopic.2017-07-13-16-0
> > (kafka.cluster.Partition)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> > [ReplicaFetcherManager on broker 1002] Removed fetcher for partitions
> > mytopic.2017-07-13-16-0 (kafka.server.ReplicaFetcherManager)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,052] INFO
> > Truncating log mytopic.2017-07-13-16-0 to offset 0. (kafka.log.Log)
> > Jul 13 16:00:01 computer kafka[28511]: [2017-07-13 16:00:01,059] INFO
> > [ReplicaFetcherManager on broker 1002] Added fetcher for partitions
> > List([mytopic.2017-07-13-16-0, initOffset 0 to broker
> > BrokerEndPoint(1001,10.0.0.24,9092)] ) (kafka.server.
> > ReplicaFetcherManager)
> > Jul 13 16:00:03 computer kafka[28511]: [2017-07-13 16:00:03,614] ERROR
> > [ReplicaFetcherThread-0-1001], Error for partition
> > [mytopic.2017-07-13-16,0] to broker 1001:org.apache.kafka.common.errors.
> > UnknownTopicOrPartitionException: This server does not host this
> > topic-partition. (kafka.server.ReplicaFetcherThread)
> >
> >
> >
> >
> >
>