Ayub Khan created ATLAS-1153:
--------------------------------
Summary: When ATLAS_HOOK topic is not created by Atlas, it is not
reading messages from the beginning
Key: ATLAS-1153
URL: https://issues.apache.org/jira/browse/ATLAS-1153
Project: Atlas
Issue Type: Bug
Affects Versions: trunk
Reporter: Ayub Khan
Fix For: trunk
When ATLAS_HOOK topic is not created by Atlas, it is not reading messages from
the beginning
Steps to repro:
1. Stop atlas.
2. Delete ATLAS_HOOK Topic and check it is actually deleted.
3. Create some hive tables(more than 3, preferrable) from hive client.
4. Now check that ATLAS_HOOK topic is created and also has messages for above
hive tables.
5. Now restart Atlas. Ideally Atlas should start consuming messages from offset
'0' but looks like it is consuming the latest one.
I have also verified that 'auto.offset.reset' is set to 'smallest', which
should ideally force the consumer to read messages from offset '0'.
{noformat}
2016-09-01 10:46:41,378 INFO - [main:] ~ Property auto.commit.enable is
overridden to false (VerifiableProperties:68)
2016-09-01 10:46:41,379 INFO - [main:] ~ Property auto.offset.reset is
overridden to smallest (VerifiableProperties:68)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property bootstrap.servers is not
valid (VerifiableProperties:83)
2016-09-01 10:46:41,379 INFO - [main:] ~ Property group.id is overridden to
atlas (VerifiableProperties:68)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property hook.group.id is not valid
(VerifiableProperties:83)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property key.deserializer is not
valid (VerifiableProperties:83)
2016-09-01 10:46:41,380 WARN - [main:] ~ Property key.serializer is not valid
(VerifiableProperties:83)
{noformat}
Kafka commands
{noformat}
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --list
ATLAS_ENTITIES
ATLAS_HOOK
__consumer_offsets
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --topic ATLAS_HOOK --delete
Topic ATLAS_HOOK is marked for deletion.
Note: This will have no impact if delete.topic.enable is not set to true.
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --list
ATLAS_ENTITIES
__consumer_offsets
{noformat}
Atlas logs showing initOffset set to 3, ideally this should be set to zero.
{noformat}
2016-09-01 10:46:41,590 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], begin
rebalancing consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,841 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] Stopping leader finder thread
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,841 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] Stopping all fetchers
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,842 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] All connections stopped
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,843 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared all
relevant queues for this fetcher (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,845 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared the
data chunks in all the consumer message iterators
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,849 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Releasing
partition ownership (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,900 INFO - [main:] ~ Starting round-robin assignment with
consumers
ArrayBuffer(atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c)
(RoundRobinAssignor:68)
2016-09-01 10:46:41,901 INFO - [main:] ~ Consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c rebalancing the
following partitions for topic ATLAS_HOOK: ArrayBuffer(0)
(RoundRobinAssignor:68)
2016-09-01 10:46:41,955 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c],
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0 successfully
owned partition 0 for topic ATLAS_HOOK (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,985 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c selected
partitions : ATLAS_HOOK:0: fetched offset = 3: consumed offset = 3
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,994 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], end
rebalancing consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,997 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread],
Starting (ConsumerFetcherManager$LeaderFinderThread:68)
2016-09-01 10:46:42,013 INFO - [main:] ~ Initializing Spring root
WebApplicationContext (/:2052)
2016-09-01 10:46:42,014 INFO - [NotificationHookConsumer thread-0:] ~ Atlas
Server is ready, can start reading Kafka events. (NotificationHookConsumer:305)
2016-09-01 10:46:42,022 INFO - [main:] ~ Root WebApplicationContext:
initialization started (ContextLoader:272)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Verifying properties (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property client.id is overridden to atlas (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property metadata.broker.list is overridden to
atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667,atlas-pixie-dust-test-7-unsecure-3.openstacklocal:6667
(VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property request.timeout.ms is overridden to 30000 (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property security.protocol is overridden to PLAINTEXT
(VerifiableProperties:68)
2016-09-01 10:46:42,092 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Fetching metadata from broker
BrokerEndPoint(1001,atlas-pixie-dust-test-7-unsecure-1.openstacklocal,6667)
with correlation id 0 for 1 topic(s) Set(ATLAS_HOOK) (ClientUtils$:68)
2016-09-01 10:46:42,098 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Connected to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 for
producing (SyncProducer:68)
2016-09-01 10:46:42,135 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Disconnecting from atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667
(SyncProducer:68)
2016-09-01 10:46:42,145 INFO - [main:] ~ Refreshing Root
WebApplicationContext: startup date [Thu Sep 01 10:46:42 UTC 2016]; root of
context hierarchy (XmlWebApplicationContext:503)
2016-09-01 10:46:42,181 INFO -
[ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002:]
~
[ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002],
Starting (ConsumerFetcherThread:68)
2016-09-01 10:46:42,190 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ [ConsumerFetcherManager-1472726801467] Added fetcher for partitions
ArrayBuffer([[ATLAS_HOOK,0], initOffset 3 to broker
BrokerEndPoint(1002,atlas-pixie-dust-test-7-unsecure-3.openstacklocal,6667)] )
(ConsumerFetcherManager:68)
{noformat}
Steps to repro:
1. Stop atlas.
2. Delete ATLAS_HOOK Topic and check it is actually deleted.
3. Create some hive tables(more than 3, preferrable) from hive client.
4. Now check that ATLAS_HOOK topic is created and also has messages for above
hive tables.
5. Now restart Atlas. Ideally Atlas should start consuming messages from offset
'0' but looks like it is consuming the latest one.
I have also verified that 'auto.offset.reset' is set to 'smallest', which
should ideally force the consumer to read messages from offset '0'.
{noformat}
2016-09-01 10:46:41,378 INFO - [main:] ~ Property auto.commit.enable is
overridden to false (VerifiableProperties:68)
2016-09-01 10:46:41,379 INFO - [main:] ~ Property auto.offset.reset is
overridden to smallest (VerifiableProperties:68)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property bootstrap.servers is not
valid (VerifiableProperties:83)
2016-09-01 10:46:41,379 INFO - [main:] ~ Property group.id is overridden to
atlas (VerifiableProperties:68)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property hook.group.id is not valid
(VerifiableProperties:83)
2016-09-01 10:46:41,379 WARN - [main:] ~ Property key.deserializer is not
valid (VerifiableProperties:83)
2016-09-01 10:46:41,380 WARN - [main:] ~ Property key.serializer is not valid
(VerifiableProperties:83)
{noformat}
Kafka commands
{noformat}
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --list
ATLAS_ENTITIES
ATLAS_HOOK
__consumer_offsets
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --topic ATLAS_HOOK --delete
Topic ATLAS_HOOK is marked for deletion.
Note: This will have no impact if delete.topic.enable is not set to true.
[root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper
172.22.74.193:2181,172.22.74.192:2181 --list
ATLAS_ENTITIES
__consumer_offsets
{noformat}
Atlas logs showing initOffset set to 3, ideally this should be set to zero.
{noformat}
2016-09-01 10:46:41,590 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], begin
rebalancing consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,841 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] Stopping leader finder thread
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,841 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] Stopping all fetchers
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,842 INFO - [main:] ~
[ConsumerFetcherManager-1472726801467] All connections stopped
(ConsumerFetcherManager:68)
2016-09-01 10:46:41,843 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared all
relevant queues for this fetcher (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,845 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared the
data chunks in all the consumer message iterators
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,849 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Releasing
partition ownership (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,900 INFO - [main:] ~ Starting round-robin assignment with
consumers
ArrayBuffer(atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c)
(RoundRobinAssignor:68)
2016-09-01 10:46:41,901 INFO - [main:] ~ Consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c rebalancing the
following partitions for topic ATLAS_HOOK: ArrayBuffer(0)
(RoundRobinAssignor:68)
2016-09-01 10:46:41,955 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c],
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0 successfully
owned partition 0 for topic ATLAS_HOOK (ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,985 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c selected
partitions : ATLAS_HOOK:0: fetched offset = 3: consumed offset = 3
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,994 INFO - [main:] ~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], end
rebalancing consumer
atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0
(ZookeeperConsumerConnector:68)
2016-09-01 10:46:41,997 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread],
Starting (ConsumerFetcherManager$LeaderFinderThread:68)
2016-09-01 10:46:42,013 INFO - [main:] ~ Initializing Spring root
WebApplicationContext (/:2052)
2016-09-01 10:46:42,014 INFO - [NotificationHookConsumer thread-0:] ~ Atlas
Server is ready, can start reading Kafka events. (NotificationHookConsumer:305)
2016-09-01 10:46:42,022 INFO - [main:] ~ Root WebApplicationContext:
initialization started (ContextLoader:272)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Verifying properties (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property client.id is overridden to atlas (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property metadata.broker.list is overridden to
atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667,atlas-pixie-dust-test-7-unsecure-3.openstacklocal:6667
(VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property request.timeout.ms is overridden to 30000 (VerifiableProperties:68)
2016-09-01 10:46:42,058 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Property security.protocol is overridden to PLAINTEXT
(VerifiableProperties:68)
2016-09-01 10:46:42,092 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Fetching metadata from broker
BrokerEndPoint(1001,atlas-pixie-dust-test-7-unsecure-1.openstacklocal,6667)
with correlation id 0 for 1 topic(s) Set(ATLAS_HOOK) (ClientUtils$:68)
2016-09-01 10:46:42,098 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Connected to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 for
producing (SyncProducer:68)
2016-09-01 10:46:42,135 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ Disconnecting from atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667
(SyncProducer:68)
2016-09-01 10:46:42,145 INFO - [main:] ~ Refreshing Root
WebApplicationContext: startup date [Thu Sep 01 10:46:42 UTC 2016]; root of
context hierarchy (XmlWebApplicationContext:503)
2016-09-01 10:46:42,181 INFO -
[ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002:]
~
[ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002],
Starting (ConsumerFetcherThread:68)
2016-09-01 10:46:42,190 INFO -
[atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:]
~ [ConsumerFetcherManager-1472726801467] Added fetcher for partitions
ArrayBuffer([[ATLAS_HOOK,0], initOffset 3 to broker
BrokerEndPoint(1002,atlas-pixie-dust-test-7-unsecure-3.openstacklocal,6667)] )
(ConsumerFetcherManager:68)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
