[
https://issues.apache.org/jira/browse/HIVE-13978?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Eugene Koifman updated HIVE-13978:
----------------------------------
Component/s: Transactions
> Exclusive lock for delete partition doesn't block subsequent read locks.
> ------------------------------------------------------------------------
>
> Key: HIVE-13978
> URL: https://issues.apache.org/jira/browse/HIVE-13978
> Project: Hive
> Issue Type: Bug
> Components: Locking, Transactions
> Affects Versions: 1.2.1
> Reporter: Igor Kuzmenko
>
> Bug based on this mail:
> http://mail-archives.apache.org/mod_mbox/hive-user/201606.mbox/%3CD37DAA17.5AB3F%25ekoifman%40hortonworks.com%3E
> I'm using Hive 1.2.1, Hive JDBC driver 1.2.1 and perform simple test on
> transactional table:
> {quote}
> asyncExecute("Select count(distinct in_info_msisdn) from mobile_connections
> where dt=20151124 and msisdn_last_digit=2", 1);
> Thread.sleep(3000);
> asyncExecute("alter table mobile_connections drop if exists partition
> (dt=20151124, msisdn_last_digit=2) purge", 2);
> Thread.sleep(3000);
> asyncExecute("Select count(distinct in_info_msisdn) from mobile_connections
> where dt=20151124 and msisdn_last_digit=2", 3);
> Thread.sleep(3000);
> asyncExecute("Select count(distinct in_info_msisdn) from mobile_connections
> where dt=20151124 and msisdn_last_digit=2", 4);
> {quote}
> Full code: http://pastebin.com/LsktC0sx
> I cretate several threads, each execute query async. First is querying
> partition. Second drop partition. Others are the same as first. First query
> takes about 10-15 seconds to complete, so "alter table" query starts before
> first query completes.
> As a result i get:
> First query - successfully completes
> Second query - successfully completes
> Third query - successfully completes
> Fourth query - throw exception.
> Here's output:
> {quote}
> Wed Jun 08 16:36:02 MSK 2016 Start thread 1
> Wed Jun 08 16:36:05 MSK 2016 Start thread 2
> Wed Jun 08 16:36:08 MSK 2016 Start thread 3
> Wed Jun 08 16:36:11 MSK 2016 Start thread 4
> Wed Jun 08 16:36:17 MSK 2016 Finish thread 1
> Wed Jun 08 16:36:17 MSK 2016 Thread 1 result: '344186'
> Wed Jun 08 16:36:17 MSK 2016 Thread 1 completed in 14443 ms
> Wed Jun 08 16:36:19 MSK 2016 Finished 2
> Wed Jun 08 16:36:19 MSK 2016 Thread 2 completed in 13967 ms
> Wed Jun 08 16:36:20 MSK 2016 Finish thread 3
> Wed Jun 08 16:36:20 MSK 2016 Thread 3 result: '344186'
> Wed Jun 08 16:36:20 MSK 2016 Thread 3 completed in 11737 ms
> java.sql.SQLException: Error while processing statement: FAILED: Execution
> Error, return code 2 from org.apache.hadoop.hive.ql.exec.tez.TezTask. Vertex
> failed, vertexName=Map 1, vertexId=vertex_1461923723503_0931_1_00,
> diagnostics=[Vertex vertex_1461923723503_0931_1_00 [Map 1] killed/failed due
> to:ROOT_INPUT_INIT_FAILURE, Vertex Input: mobile_connections initializer
> failed, vertex=vertex_1461923723503_0931_1_00 [Map 1],
> java.lang.RuntimeException: serious problem
> at
> org.apache.hadoop.hive.ql.io.orc.OrcInputFormat.generateSplitsInfo(OrcInputFormat.java:1059)
> {quote}
> HiveServer2 log contains this:
> {quote}
> Line 1043: 2016-06-08 16:36:04,546 INFO [HiveServer2-Background-Pool:
> Thread-42]: lockmgr.DbLockManager (DbLockManager.java:lock(101)) - Response
> to queryId=hive_20160608163602_542056d9-c524-4df4-af18-6aa5e906284f
> LockResponse(lockid:179728, state:ACQUIRED)
> Line 1349: 2016-06-08 16:36:05,214 INFO [HiveServer2-Background-Pool:
> Thread-50]: lockmgr.DbLockManager (DbLockManager.java:lock(98)) - Requesting:
> queryId=hive_20160608163604_832abbff-6199-497e-b969-fd8ac1465abc
> LockRequest(component:[LockComponent(type:EXCLUSIVE, level:PARTITION,
> dbname:default, tablename:mobile_connections,
> partitionname:dt=20151123/msisdn_last_digit=3)], txnid:0, user:hdfs,
> hostname:mercury)
> Line 1390: 2016-06-08 16:36:05,270 INFO [HiveServer2-Background-Pool:
> Thread-50]: lockmgr.DbLockManager (DbLockManager.java:lock(101)) - Response
> to queryId=hive_20160608163604_832abbff-6199-497e-b969-fd8ac1465abc
> LockResponse(lockid:179729, state:WAITING)
> Line 2346: 2016-06-08 16:36:08,028 INFO [HiveServer2-Background-Pool:
> Thread-68]: lockmgr.DbLockManager (DbLockManager.java:lock(98)) - Requesting:
> queryId=hive_20160608163607_7b18da12-6f86-41c9-b4b1-be45252c18c2
> LockRequest(component:[LockComponent(type:SHARED_READ, level:TABLE,
> dbname:default, tablename:mobile_connections),
> LockComponent(type:SHARED_READ, level:PARTITION, dbname:default,
> tablename:mobile_connections,
> partitionname:dt=20151123/msisdn_last_digit=3)], txnid:0, user:hdfs,
> hostname:mercury)
> Line 2370: 2016-06-08 16:36:08,069 INFO [HiveServer2-Background-Pool:
> Thread-68]: lockmgr.DbLockManager (DbLockManager.java:lock(101)) - Response
> to queryId=hive_20160608163607_7b18da12-6f86-41c9-b4b1-be45252c18c2
> LockResponse(lockid:179730, state:ACQUIRED)
> Line 3561: 2016-06-08 16:36:11,000 INFO [HiveServer2-Background-Pool:
> Thread-91]: lockmgr.DbLockManager (DbLockManager.java:lock(98)) - Requesting:
> queryId=hive_20160608163610_b78a201b-ae6d-4040-9115-f92118d5b629
> LockRequest(component:[LockComponent(type:SHARED_READ, level:TABLE,
> dbname:default, tablename:mobile_connections),
> LockComponent(type:SHARED_READ, level:PARTITION, dbname:default,
> tablename:mobile_connections,
> partitionname:dt=20151123/msisdn_last_digit=3)], txnid:0, user:hdfs,
> hostname:mercury)
> Line 3587: 2016-06-08 16:36:11,060 INFO [HiveServer2-Background-Pool:
> Thread-91]: lockmgr.DbLockManager (DbLockManager.java:lock(101)) - Response
> to queryId=hive_20160608163610_b78a201b-ae6d-4040-9115-f92118d5b629
> LockResponse(lockid:179731, state:ACQUIRED)
> Line 4468: 2016-06-08 16:36:16,481 DEBUG [HiveServer2-Background-Pool:
> Thread-42]: lockmgr.DbLockManager (DbLockManager.java:unlock(182)) -
> Unlocking lockid:179728
> Line 4473: 2016-06-08 16:36:16,522 DEBUG [HiveServer2-Background-Pool:
> Thread-42]: lockmgr.DbLockManager (DbLockManager.java:unlock(185)) - Removed
> a lock true
> Line 4880: 2016-06-08 16:36:18,676 DEBUG [HiveServer2-Background-Pool:
> Thread-50]: lockmgr.DbLockManager (DbLockManager.java:unlock(182)) -
> Unlocking lockid:179729
> Line 4889: 2016-06-08 16:36:18,829 DEBUG [HiveServer2-Background-Pool:
> Thread-50]: lockmgr.DbLockManager (DbLockManager.java:unlock(185)) - Removed
> a lock true
> Line 4976: 2016-06-08 16:36:19,439 DEBUG [HiveServer2-Background-Pool:
> Thread-68]: lockmgr.DbLockManager (DbLockManager.java:unlock(182)) -
> Unlocking lockid:179730
> Line 4979: 2016-06-08 16:36:19,486 DEBUG [HiveServer2-Background-Pool:
> Thread-68]: lockmgr.DbLockManager (DbLockManager.java:unlock(185)) - Removed
> a lock true
> Line 5467: 2016-06-08 16:36:28,090 DEBUG [HiveServer2-Background-Pool:
> Thread-91]: lockmgr.DbLockManager (DbLockManager.java:unlock(182)) -
> Unlocking lockid:179731
> Line 5470: 2016-06-08 16:36:28,131 DEBUG [HiveServer2-Background-Pool:
> Thread-91]: lockmgr.DbLockManager (DbLockManager.java:unlock(185)) - Removed
> a lock true
> {quote}
> Hive Server 2 log:
> https://drive.google.com/open?id=0ByB92PAoAkrKakhqYXhmdzlidkk
> The reads locks 179730 and 179731 should have been blocked by 179729.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
