[ATLAS-1119] Add retries for edge label creation

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.8-incubating
• Fix Version/s: 0.8-incubating, 0.7.1-incubating
• Assignee: Suma Shivaprasad
• Reporter: Suma Shivaprasad
• Created: 15/Aug/16 22:37
• Updated: 04/Jan/17 06:59
• Resolved: 16/Aug/16 09:53

Description

Concurrent operations will fail when trying to create edge label which tries to define a new property key for the edge label if it doesnt exist.

2016-08-15 04:08:28,475 DEBUG - [pool-8-thread-1:] ~ Adding a new trait=PII for entity=b1630277-e8dc-4fcf-94af-c0c8b0b51c09 (GraphBackedMetadataRepository:222)
2016-08-15 04:08:28,476 DEBUG - [pool-8-thread-2:] ~ Adding a new trait=PII for entity=5e335fed-4a74-496d-8521-1678caf85813 (GraphBackedMetadataRepository:222)
2016-08-15 04:08:28,477 DEBUG - [pool-8-thread-1:] ~ Finding vertex with __guid = b1630277-e8dc-4fcf-94af-c0c8b0b51c09,  (GraphHelper:182)
2016-08-15 04:08:28,477 DEBUG - [pool-8-thread-2:] ~ Finding vertex with __guid = 5e335fed-4a74-496d-8521-1678caf85813,  (GraphHelper:182)
2016-08-15 04:08:28,477 DEBUG - [pool-8-thread-3:] ~ Executing dsl query=hive_table (GraphBackedDiscoveryService:133)
2016-08-15 04:08:28,483 DEBUG - [pool-8-thread-2:] ~ Found a vertex vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] with __guid = 5e335fed-4a74-496d-8521-1678caf85813,  (GraphHelper:192)
2016-08-15 04:08:28,484 DEBUG - [pool-8-thread-2:] ~ Creating vertex for type PII id null (GraphHelper:97)
2016-08-15 04:08:28,485 DEBUG - [pool-8-thread-2:] ~ Setting property __typeName = "PII" to vertex[id=8960 type=null guid=null] (GraphHelper:290)
2016-08-15 04:08:28,487 DEBUG - [pool-8-thread-2:] ~ Set property __typeName = "PII" to vertex[id=8960 type=null guid=null] (GraphHelper:300)
2016-08-15 04:08:28,487 DEBUG - [pool-8-thread-2:] ~ Setting property __state = "ACTIVE" to vertex[id=8960 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,488 DEBUG - [pool-8-thread-2:] ~ Set property __state = "ACTIVE" to vertex[id=8960 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,488 DEBUG - [pool-8-thread-1:] ~ Found a vertex vertex[id=8448 type=hive_database guid=b1630277-e8dc-4fcf-94af-c0c8b0b51c09] with __guid = b1630277-e8dc-4fcf-94af-c0c8b0b51c09,  (GraphHelper:192)
2016-08-15 04:08:28,488 DEBUG - [pool-8-thread-2:] ~ Setting property __timestamp = "1471234108488" to vertex[id=8960 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,489 DEBUG - [pool-8-thread-1:] ~ Creating vertex for type PII id null (GraphHelper:97)
2016-08-15 04:08:28,490 DEBUG - [pool-8-thread-2:] ~ Set property __timestamp = "1471234108488" to vertex[id=8960 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,490 DEBUG - [pool-8-thread-2:] ~ Setting property __modificationTimestamp = "1471234108488" to vertex[id=8960 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,490 DEBUG - [pool-8-thread-1:] ~ Setting property __typeName = "PII" to vertex[id=9216 type=null guid=null] (GraphHelper:290)
2016-08-15 04:08:28,490 DEBUG - [pool-8-thread-2:] ~ Set property __modificationTimestamp = "1471234108488" to vertex[id=8960 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,491 DEBUG - [pool-8-thread-2:] ~ created vertex vertex[id=8960 type=PII guid=null] for trait PII (TypedInstanceToGraphMapper:665)
2016-08-15 04:08:28,492 DEBUG - [pool-8-thread-2:] ~ Mapping instance struct[type=PII] to vertex vertex[id=8960 type=PII guid=null] (TypedInstanceToGraphMapper:181)
2016-08-15 04:08:28,492 DEBUG - [pool-8-thread-2:] ~ Setting property __modificationTimestamp = "1471234108488" to vertex[id=8960 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,492 DEBUG - [pool-8-thread-2:] ~ Finding edges for vertex[id=8960 type=PII guid=null] with label hive_database.PII (GraphHelper:201)
2016-08-15 04:08:28,493 DEBUG - [pool-8-thread-2:] ~ Adding edge for vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> label hive_database.PII -> vertex[id=8960 type=PII guid=null] (GraphHelper:122)
2016-08-15 04:08:28,493 DEBUG - [pool-8-thread-1:] ~ Set property __typeName = "PII" to vertex[id=9216 type=null guid=null] (GraphHelper:300)
2016-08-15 04:08:28,494 DEBUG - [pool-8-thread-1:] ~ Setting property __state = "ACTIVE" to vertex[id=9216 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,495 DEBUG - [pool-8-thread-3:] ~ Query = hive_table limit 10 offset 0  (GraphBackedDiscoveryService:158)
2016-08-15 04:08:28,495 DEBUG - [pool-8-thread-3:] ~ Expression Tree = LimitExpression 10, 0
 ClassExpression hive_table
 (GraphBackedDiscoveryService:159)
2016-08-15 04:08:28,496 DEBUG - [pool-8-thread-3:] ~ Gremlin Query = L:{_var_0 = [] as Set;g.V().has("__typeName", "hive_table").fill(_var_0);g.V().has("__superTypeNames", "hive_table").fill(_var_0);_var_0._() [0..<10].toList()} (GraphBackedDiscoveryService:160)
2016-08-15 04:08:28,495 DEBUG - [pool-8-thread-1:] ~ Set property __state = "ACTIVE" to vertex[id=9216 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,497 DEBUG - [pool-8-thread-1:] ~ Setting property __timestamp = "1471234108497" to vertex[id=9216 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,499 DEBUG - [pool-8-thread-2:] ~ Setting property __state = "ACTIVE" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:290)
2016-08-15 04:08:28,500 DEBUG - [pool-8-thread-2:] ~ Set property __state = "ACTIVE" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:300)
2016-08-15 04:08:28,500 DEBUG - [pool-8-thread-1:] ~ Set property __timestamp = "1471234108497" to vertex[id=9216 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,500 DEBUG - [pool-8-thread-2:] ~ Setting property __timestamp = "1471234108488" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:290)
2016-08-15 04:08:28,501 DEBUG - [pool-8-thread-2:] ~ Set property __timestamp = "1471234108488" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:300)
2016-08-15 04:08:28,501 DEBUG - [pool-8-thread-1:] ~ Setting property __modificationTimestamp = "1471234108497" to vertex[id=9216 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,501 DEBUG - [pool-8-thread-2:] ~ Setting property __modificationTimestamp = "1471234108488" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:290)
2016-08-15 04:08:28,501 DEBUG - [pool-8-thread-2:] ~ Set property __modificationTimestamp = "1471234108488" to edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:300)
2016-08-15 04:08:28,502 DEBUG - [pool-8-thread-1:] ~ Set property __modificationTimestamp = "1471234108497" to vertex[id=9216 type=PII guid=null] (GraphHelper:300)
2016-08-15 04:08:28,502 DEBUG - [pool-8-thread-2:] ~ Added edge[id=1f0g-6ps-5slx-6ww label=hive_database.PII from vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] -> to vertex[id=8960 type=PII guid=null]] (GraphHelper:129)
2016-08-15 04:08:28,502 DEBUG - [pool-8-thread-1:] ~ created vertex vertex[id=9216 type=PII guid=null] for trait PII (TypedInstanceToGraphMapper:665)
2016-08-15 04:08:28,503 DEBUG - [pool-8-thread-2:] ~ Adding property __traitNames = "PII" to vertex vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] (GraphHelper:329)
2016-08-15 04:08:28,503 DEBUG - [pool-8-thread-1:] ~ Mapping instance struct[type=PII] to vertex vertex[id=9216 type=PII guid=null] (TypedInstanceToGraphMapper:181)
2016-08-15 04:08:28,504 DEBUG - [pool-8-thread-2:] ~ Setting property __modificationTimestamp = "1471234108488" to vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] (GraphHelper:290)
2016-08-15 04:08:28,504 DEBUG - [pool-8-thread-1:] ~ Setting property __modificationTimestamp = "1471234108497" to vertex[id=9216 type=PII guid=null] (GraphHelper:290)
2016-08-15 04:08:28,505 DEBUG - [pool-8-thread-2:] ~ Set property __modificationTimestamp = "1471234108488" to vertex[id=8704 type=hive_database guid=5e335fed-4a74-496d-8521-1678caf85813] (GraphHelper:300)
2016-08-15 04:08:28,505 DEBUG - [pool-8-thread-1:] ~ Finding edges for vertex[id=9216 type=PII guid=null] with label hive_database.PII (GraphHelper:201)
2016-08-15 04:08:28,506 DEBUG - [pool-8-thread-1:] ~ Adding edge for vertex[id=8448 type=hive_database guid=b1630277-e8dc-4fcf-94af-c0c8b0b51c09] -> label hive_database.PII -> vertex[id=9216 type=PII guid=null] (GraphHelper:122)
2016-08-15 04:08:28,532 ERROR - [pool-8-thread-1:] ~ graph rollback due to exception  (GraphTransactionInterceptor:48)
org.apache.atlas.repository.RepositoryException: com.thinkaurelius.titan.core.SchemaViolationException: Adding this property for key [system%&%SchemaName] and value [rt%hive_database.PII] violates a uniqueness constraint [SystemIndex#system%&%SchemaName]
	at org.apache.atlas.repository.graph.GraphBackedMetadataRepository.addTrait(GraphBackedMetadataRepository.java:243)
	at org.apache.atlas.GraphTransactionInterceptor.invoke(GraphTransactionInterceptor.java:42)
	at org.apache.atlas.repository.graph.GraphBackedMetadataRepositoryTest$1.call(GraphBackedMetadataRepositoryTest.java:155)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:722)
Caused by: com.thinkaurelius.titan.core.SchemaViolationException: Adding this property for key [system%&%SchemaName] and value [rt%hive_database.PII] violates a uniqueness constraint [SystemIndex#system%&%SchemaName]
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.addPropertyInternal(StandardTitanTx.java:740)
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.setProperty(StandardTitanTx.java:778)
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.addProperty(StandardTitanTx.java:696)
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.makeSchemaVertex(StandardTitanTx.java:815)
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.makeEdgeLabel(StandardTitanTx.java:839)
	at com.thinkaurelius.titan.graphdb.types.StandardEdgeLabelMaker.make(StandardEdgeLabelMaker.java:88)
	at com.thinkaurelius.titan.graphdb.blueprints.BlueprintsDefaultSchemaMaker.makeEdgeLabel(BlueprintsDefaultSchemaMaker.java:23)
	at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.getOrCreateEdgeLabel(StandardTitanTx.java:920)
	at com.thinkaurelius.titan.graphdb.blueprints.TitanBlueprintsTransaction.addEdge(TitanBlueprintsTransaction.java:132)
	at com.thinkaurelius.titan.graphdb.blueprints.TitanBlueprintsTransaction.addEdge(TitanBlueprintsTransaction.java:124)
	at com.thinkaurelius.titan.graphdb.blueprints.TitanBlueprintsGraph.addEdge(TitanBlueprintsGraph.java:250)
	at com.thinkaurelius.titan.graphdb.blueprints.TitanBlueprintsGraph.addEdge(TitanBlueprintsGraph.java:27)
	at org.apache.atlas.repository.graph.GraphHelper.addEdge(GraphHelper.java:123)
	at org.apache.atlas.repository.graph.GraphHelper.getOrCreateEdge(GraphHelper.java:145)
	at org.apache.atlas.repository.graph.TypedInstanceToGraphMapper.mapTraitInstanceToVertex(TypedInstanceToGraphMapper.java:672)
	at org.apache.atlas.repository.graph.GraphBackedMetadataRepository.addTrait(GraphBackedMetadataRepository.java:231)
	... 7 more
2016-08-15 04:08:28,536 INFO  - [pool-8-thread-2:] ~ graph commit (GraphTransactionInterceptor:44)