You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@atlas.apache.org by "Ayub Khan (JIRA)" <ji...@apache.org> on 2016/01/19 10:28:40 UTC
[jira] [Updated] (ATLAS-445) Embedded Kafka mode: All kafka threads
are in indefinite wait state when an entity create message is sent to
ATLAS_ENTITIES topic
[ https://issues.apache.org/jira/browse/ATLAS-445?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ayub Khan updated ATLAS-445:
----------------------------
Attachment: atlas_full_thread_dump.txt
Attaching atlas full thred dump/
> Embedded Kafka mode: All kafka threads are in indefinite wait state when an entity create message is sent to ATLAS_ENTITIES topic
> ---------------------------------------------------------------------------------------------------------------------------------
>
> Key: ATLAS-445
> URL: https://issues.apache.org/jira/browse/ATLAS-445
> Project: Atlas
> Issue Type: Bug
> Affects Versions: trunk
> Reporter: Ayub Khan
> Fix For: trunk
>
> Attachments: atlas_full_thread_dump.txt
>
>
> When a create entity request is fired thru rest api, the request hangs indefinitely without any response.
> From the logs, looks like the entity is getting created, when the entity creation notification is sent to ATLAS_ENTITIES topic, somehow all kafka threads are moving to indefinite wait state. This can be resolved by adding a acceptable amount of timeout for the wait state.
> Log snapshot
> {noformat}
> } of DB to vertex v[7683072] (TypedInstanceToGraphMapper:175)
> 2016-01-19 14:28:36,479 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding/Updating typed instance DB (TypedInstanceToGraphMapper:149)
> 2016-01-19 14:28:36,480 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping instance {
> id : (type: DB, id: <unassigned>)
> name : Sales
> description : Sales Database
> locationUri : hdfs://host:8000/apps/warehouse/sales
> owner : John ETL
> createTime : 1453193717096
> } of DB to vertex v[7683072] (TypedInstanceToGraphMapper:175)
> 2016-01-19 14:28:36,480 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ mapping attribute name = Sales (TypedInstanceToGraphMapper:188)
> 2016-01-19 14:28:36,480 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property DB.name = "Sales" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,481 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ mapping attribute description = Sales Database (TypedInstanceToGraphMapper:188)
> 2016-01-19 14:28:36,481 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property DB.description = "Sales Database" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,481 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ mapping attribute locationUri = hdfs://host:8000/apps/warehouse/sales (TypedInstanceToGraphMapper:188)
> 2016-01-19 14:28:36,482 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property DB.locationUri = "hdfs://host:8000/apps/warehouse/sales" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,482 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ mapping attribute owner = John ETL (TypedInstanceToGraphMapper:188)
> 2016-01-19 14:28:36,482 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property DB.owner = "John ETL" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,483 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ mapping attribute createTime = 1453193717096 (TypedInstanceToGraphMapper:188)
> 2016-01-19 14:28:36,483 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property DB.createTime = "1453193717096" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,484 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping graph root vertex v[7683072] to typed instance for guid 8a20f8cb-a202-401f-9833-36d53c2c554a (GraphToTypedInstanceMapper:63)
> 2016-01-19 14:28:36,485 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Created id (type: DB, id: 8a20f8cb-a202-401f-9833-36d53c2c554a) for instance type DB (GraphToTypedInstanceMapper:68)
> 2016-01-19 14:28:36,485 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping vertex v[7683072] to instance DB for fields (GraphToTypedInstanceMapper:92)
> 2016-01-19 14:28:36,485 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo name (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,486 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='name', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,486 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo description (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,486 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='description', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,486 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo locationUri (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,487 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='locationUri', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,487 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo owner (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,487 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='owner', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,487 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo createTime (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,487 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='createTime', dataType=org.apache.atlas.typesystem.types.DataTypes$LongType@c2be72, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,488 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Setting property entityText = "DB name Sales description Sales Database locationUri hdfs://host:8000/apps/warehouse/sales owner John ETL createTime 1453193717096" to vertex v[7683072] (GraphHelper:152)
> 2016-01-19 14:28:36,528 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ graph commit (GraphTransactionInterceptor:44)
> 2016-01-19 14:28:36,529 INFO - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Retrieving entity with guid=8a20f8cb-a202-401f-9833-36d53c2c554a (GraphBackedMetadataRepository:136)
> 2016-01-19 14:28:36,529 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Finding vertex for __guid=8a20f8cb-a202-401f-9833-36d53c2c554a (GraphHelper:115)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Found a vertex v[7683072] with __guid=8a20f8cb-a202-401f-9833-36d53c2c554a (GraphHelper:196)
> :set nonu
> 2016-01-19 14:28:36,529 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Finding vertex for __guid=8a20f8cb-a202-401f-9833-36d53c2c554a (GraphHelper:115)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Found a vertex v[7683072] with __guid=8a20f8cb-a202-401f-9833-36d53c2c554a (GraphHelper:196)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping graph root vertex v[7683072] to typed instance for guid 8a20f8cb-a202-401f-9833-36d53c2c554a (GraphToTypedInstanceMapper:63)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Created id (type: DB, id: 8a20f8cb-a202-401f-9833-36d53c2c554a) for instance type DB (GraphToTypedInstanceMapper:68)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping vertex v[7683072] to instance DB for fields (GraphToTypedInstanceMapper:92)
> 2016-01-19 14:28:36,530 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo name (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,531 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='name', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,531 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo description (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,531 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='description', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,531 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo locationUri (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,531 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='locationUri', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,532 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo owner (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,532 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='owner', dataType=org.apache.atlas.typesystem.types.DataTypes$StringType@72a6e257, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,532 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Mapping attributeInfo createTime (GraphToTypedInstanceMapper:102)
> 2016-01-19 14:28:36,532 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Adding primitive AttributeInfo{name='createTime', dataType=org.apache.atlas.typesystem.types.DataTypes$LongType@c2be72, multiplicity=Multiplicity{lower=0, upper=1, isUnique=false}, isComposite=false, isUnique=false, isIndexable=true, reverseAttributeName='null'} from vertex v[7683072] (GraphToTypedInstanceMapper:357)
> 2016-01-19 14:28:36,533 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ graph commit (GraphTransactionInterceptor:44)
> 2016-01-19 14:28:36,534 DEBUG - [qtp161161313-962 - efd6fd5a-c1c0-4731-8ebd-66fa6d01fb37:] ~ Sending message for topic ATLAS_ENTITIES: {"entity":{"jsonClass":"org.apache.atlas.typesystem.json.InstanceSerialization$_Reference","id":{"jsonClass":"org.apache.atlas.typesystem.json.InstanceSerialization$_Id","id":"8a20f8cb-a202-401f-9833-36d53c2c554a","version":0,"typeName":"DB"},"typeName":"DB","values":{"name":"Sales","createTime":1453193717096,"description":"Sales Database","locationUri":"hdfs://host:8000/apps/warehouse/sales","owner":"John ETL"},"traitNames":[],"traits":{}},"operationType":"ENTITY_CREATE","traits":[]} (KafkaNotification:186)
> {noformat}
> Also attaching full thread dump of atlas and kafka.
> Note: This seems to be a corner case because restarting atlas would bring it back to normal state.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)