You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hive.apache.org by "Igor Kuzmenko (JIRA)" <ji...@apache.org> on 2016/06/09 10:43:20 UTC

[jira] [Created] (HIVE-13978) Exclusive lock for delete partition doesn't block subsequent read locks.

Igor Kuzmenko created HIVE-13978:
------------------------------------

             Summary: 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
    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)