From 71336645ddc340487ca2dc0053e46a6387b4e542 Mon Sep 17 00:00:00 2001 From: Mohammad Salehe Date: Tue, 27 Nov 2018 19:07:34 -0500 Subject: Add primary time measurements to MusicCore Add time measurements to MusicCore.atomicPut and dependent Cassandra execute path Change-Id: I44455d7232e12d29a648c3d59d9aa102bf1ab232 Issue-ID: MUSIC-148 Signed-off-by: Mohammad Salehe --- .../org/onap/music/datastore/MusicDataStore.java | 109 ++++---- .../lockingservice/cassandra/CassaLockStore.java | 148 +++++----- .../onap/music/service/impl/MusicCassaCore.java | 308 ++++++++++++--------- .../org/onap/music/testruns/ComparisonPoints1.java | 2 +- 4 files changed, 324 insertions(+), 243 deletions(-) diff --git a/src/main/java/org/onap/music/datastore/MusicDataStore.java b/src/main/java/org/onap/music/datastore/MusicDataStore.java index 72385d17..a10f31e3 100644 --- a/src/main/java/org/onap/music/datastore/MusicDataStore.java +++ b/src/main/java/org/onap/music/datastore/MusicDataStore.java @@ -42,6 +42,7 @@ import com.datastax.driver.core.ColumnDefinitions.Definition; import com.datastax.driver.core.exceptions.AlreadyExistsException; import com.datastax.driver.core.exceptions.InvalidQueryException; import com.datastax.driver.core.exceptions.NoHostAvailableException; +import org.onap.music.util.TimeMeasureInstance; /** * @author nelson24 @@ -308,58 +309,60 @@ public class MusicDataStore { */ public boolean executePut(PreparedQueryObject queryObject, String consistencyLevel, long timeSlot) throws MusicServiceException, MusicQueryException { - - boolean result = false; - long timeOfWrite = System.currentTimeMillis(); - - if (!MusicUtil.isValidQueryObject(!queryObject.getValues().isEmpty(), queryObject)) { - logger.error(EELFLoggerDelegate.errorLogger, queryObject.getQuery(),AppMessages.QUERYERROR, ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); - throw new MusicQueryException("Ill formed queryObject for the request = " + "[" - + queryObject.getQuery() + "]"); - } - logger.info(EELFLoggerDelegate.applicationLogger, - "In preprared Execute Put: the actual insert query:" - + queryObject.getQuery() + "; the values" - + queryObject.getValues()); - SimpleStatement statement; + TimeMeasureInstance.instance().enter("executePut"); try { + boolean result; + long timeOfWrite = System.currentTimeMillis(); - statement = new SimpleStatement(queryObject.getQuery(), queryObject.getValues().toArray()); - } catch(InvalidQueryException iqe) { - logger.error(EELFLoggerDelegate.errorLogger, iqe.getMessage(),AppMessages.QUERYERROR, ErrorSeverity.CRITICAL, ErrorTypes.QUERYERROR); - throw new MusicQueryException(iqe.getMessage()); - }catch(Exception e) { - logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(),AppMessages.QUERYERROR, ErrorSeverity.CRITICAL, ErrorTypes.QUERYERROR); - throw new MusicQueryException(e.getMessage()); - } - - try { - if (consistencyLevel.equalsIgnoreCase(MusicUtil.CRITICAL)) { - logger.info(EELFLoggerDelegate.applicationLogger, "Executing critical put query"); - statement.setConsistencyLevel(ConsistencyLevel.QUORUM); - } else if (consistencyLevel.equalsIgnoreCase(MusicUtil.EVENTUAL)) { - logger.info(EELFLoggerDelegate.applicationLogger, "Executing simple put query"); - statement.setConsistencyLevel(ConsistencyLevel.ONE); + if (!MusicUtil.isValidQueryObject(!queryObject.getValues().isEmpty(), queryObject)) { + logger.error(EELFLoggerDelegate.errorLogger, queryObject.getQuery(), AppMessages.QUERYERROR, ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); + throw new MusicQueryException("Ill formed queryObject for the request = " + "[" + + queryObject.getQuery() + "]"); } + logger.info(EELFLoggerDelegate.applicationLogger, + "In preprared Execute Put: the actual insert query:" + + queryObject.getQuery() + "; the values" + + queryObject.getValues()); + SimpleStatement statement; + try { - long timestamp = MusicUtil.v2sTimeStampInMicroseconds(timeSlot, timeOfWrite); - statement.setDefaultTimestamp(timestamp); + statement = new SimpleStatement(queryObject.getQuery(), queryObject.getValues().toArray()); + } catch (InvalidQueryException iqe) { + logger.error(EELFLoggerDelegate.errorLogger, iqe.getMessage(), AppMessages.QUERYERROR, ErrorSeverity.CRITICAL, ErrorTypes.QUERYERROR); + throw new MusicQueryException(iqe.getMessage()); + } catch (Exception e) { + logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(), AppMessages.QUERYERROR, ErrorSeverity.CRITICAL, ErrorTypes.QUERYERROR); + throw new MusicQueryException(e.getMessage()); + } - ResultSet rs = session.execute(statement); - result = rs.wasApplied(); - } - catch (AlreadyExistsException ae) { - logger.error(EELFLoggerDelegate.errorLogger, ae.getMessage(),AppMessages.SESSIONFAILED+ " [" + queryObject.getQuery() + "]", ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); - throw new MusicServiceException(ae.getMessage()); - } - catch (Exception e) { - logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(),AppMessages.SESSIONFAILED+ " [" + queryObject.getQuery() + "]", ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); - throw new MusicQueryException("Executing Session Failure for Request = " + "[" - + queryObject.getQuery() + "]" + " Reason = " + e.getMessage()); - } + try { + if (consistencyLevel.equalsIgnoreCase(MusicUtil.CRITICAL)) { + logger.info(EELFLoggerDelegate.applicationLogger, "Executing critical put query"); + statement.setConsistencyLevel(ConsistencyLevel.QUORUM); + } else if (consistencyLevel.equalsIgnoreCase(MusicUtil.EVENTUAL)) { + logger.info(EELFLoggerDelegate.applicationLogger, "Executing simple put query"); + statement.setConsistencyLevel(ConsistencyLevel.ONE); + } + long timestamp = MusicUtil.v2sTimeStampInMicroseconds(timeSlot, timeOfWrite); + statement.setDefaultTimestamp(timestamp); + + ResultSet rs = session.execute(statement); + result = rs.wasApplied(); + } catch (AlreadyExistsException ae) { + logger.error(EELFLoggerDelegate.errorLogger, ae.getMessage(), AppMessages.SESSIONFAILED + " [" + queryObject.getQuery() + "]", ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); + throw new MusicServiceException(ae.getMessage()); + } catch (Exception e) { + logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(), AppMessages.SESSIONFAILED + " [" + queryObject.getQuery() + "]", ErrorSeverity.ERROR, ErrorTypes.QUERYERROR); + throw new MusicQueryException("Executing Session Failure for Request = " + "[" + + queryObject.getQuery() + "]" + " Reason = " + e.getMessage()); + } - return result; + return result; + } + finally { + TimeMeasureInstance.instance().exit(); + } } /** @@ -405,7 +408,13 @@ public class MusicDataStore { */ public ResultSet executeOneConsistencyGet(PreparedQueryObject queryObject) throws MusicServiceException, MusicQueryException { - return executeGet(queryObject, CONSISTENCY_LEVEL_ONE); + TimeMeasureInstance.instance().enter("executeOneConsistencyGet"); + try { + return executeGet(queryObject, CONSISTENCY_LEVEL_ONE); + } + finally { + TimeMeasureInstance.instance().exit(); + } } /** @@ -416,7 +425,13 @@ public class MusicDataStore { */ public ResultSet executeQuorumConsistencyGet(PreparedQueryObject queryObject) throws MusicServiceException, MusicQueryException { - return executeGet(queryObject, CONSISTENCY_LEVEL_QUORUM); + TimeMeasureInstance.instance().enter("executeQuorumConsistencyGet"); + try { + return executeGet(queryObject, CONSISTENCY_LEVEL_QUORUM); + } + finally { + TimeMeasureInstance.instance().exit(); + } } } diff --git a/src/main/java/org/onap/music/lockingservice/cassandra/CassaLockStore.java b/src/main/java/org/onap/music/lockingservice/cassandra/CassaLockStore.java index 8065bf61..51a78264 100644 --- a/src/main/java/org/onap/music/lockingservice/cassandra/CassaLockStore.java +++ b/src/main/java/org/onap/music/lockingservice/cassandra/CassaLockStore.java @@ -11,6 +11,7 @@ import org.onap.music.exceptions.MusicServiceException; import com.datastax.driver.core.ResultSet; import com.datastax.driver.core.Row; +import org.onap.music.util.TimeMeasureInstance; /* * This is the lock store that is built on top of Cassandra that is used by MUSIC to maintain lock state. @@ -92,53 +93,59 @@ public class CassaLockStore { * @throws MusicQueryException */ public String genLockRefandEnQueue(String keyspace, String table, String lockName, boolean isWriteLock) - throws MusicServiceException, MusicQueryException { - logger.info(EELFLoggerDelegate.applicationLogger, - "Create lock reference for " + keyspace + "." + table + "." + lockName); - table = table_prepend_name+table; + throws MusicServiceException, MusicQueryException { + TimeMeasureInstance.instance().enter("genLockRefandEnQueue"); + try { + logger.info(EELFLoggerDelegate.applicationLogger, + "Create lock reference for " + keyspace + "." + table + "." + lockName); + table = table_prepend_name+table; - PreparedQueryObject queryObject = new PreparedQueryObject(); - String selectQuery = "SELECT guard FROM " + keyspace + "." + table + " WHERE key=?;"; + PreparedQueryObject queryObject = new PreparedQueryObject(); + String selectQuery = "SELECT guard FROM " + keyspace + "." + table + " WHERE key=?;"; - queryObject.addValue(lockName); - queryObject.appendQueryString(selectQuery); - ResultSet gqResult = dsHandle.executeOneConsistencyGet(queryObject); - List latestGuardRow = gqResult.all(); + queryObject.addValue(lockName); + queryObject.appendQueryString(selectQuery); + ResultSet gqResult = dsHandle.executeOneConsistencyGet(queryObject); + List latestGuardRow = gqResult.all(); - long prevGuard = 0; - long lockRef = 1; - if (latestGuardRow.size() > 0) { - prevGuard = latestGuardRow.get(0).getLong(0); - lockRef = prevGuard + 1; - } + long prevGuard = 0; + long lockRef = 1; + if (latestGuardRow.size() > 0) { + prevGuard = latestGuardRow.get(0).getLong(0); + lockRef = prevGuard + 1; + } - long lockEpochMillis = System.currentTimeMillis(); + long lockEpochMillis = System.currentTimeMillis(); // System.out.println("guard(" + lockName + "): " + prevGuard + "->" + lockRef); - logger.info(EELFLoggerDelegate.applicationLogger, - "Created lock reference for " + keyspace + "." + table + "." + lockName + ":" + lockRef); + logger.info(EELFLoggerDelegate.applicationLogger, + "Created lock reference for " + keyspace + "." + table + "." + lockName + ":" + lockRef); - queryObject = new PreparedQueryObject(); - String insQuery = "BEGIN BATCH" + - " UPDATE " + keyspace + "." + table + - " SET guard=? WHERE key=? IF guard = " + (prevGuard == 0 ? "NULL" : "?") +";" + - " INSERT INTO " + keyspace + "." + table + - "(key, lockReference, createTime, acquireTime, writeLock) VALUES (?,?,?,?,?) IF NOT EXISTS; APPLY BATCH;"; + queryObject = new PreparedQueryObject(); + String insQuery = "BEGIN BATCH" + + " UPDATE " + keyspace + "." + table + + " SET guard=? WHERE key=? IF guard = " + (prevGuard == 0 ? "NULL" : "?") + ";" + + " INSERT INTO " + keyspace + "." + table + + "(key, lockReference, createTime, acquireTime, writeLock) VALUES (?,?,?,?,?) IF NOT EXISTS; APPLY BATCH;"; - queryObject.addValue(lockRef); - queryObject.addValue(lockName); - if (prevGuard != 0) - queryObject.addValue(prevGuard); + queryObject.addValue(lockRef); + queryObject.addValue(lockName); + if (prevGuard != 0) + queryObject.addValue(prevGuard); - queryObject.addValue(lockName); - queryObject.addValue(lockRef); - queryObject.addValue(String.valueOf(lockEpochMillis)); - queryObject.addValue("0"); - queryObject.addValue(isWriteLock); - queryObject.appendQueryString(insQuery); - boolean pResult = dsHandle.executePut(queryObject, "critical"); - return String.valueOf(lockRef); + queryObject.addValue(lockName); + queryObject.addValue(lockRef); + queryObject.addValue(String.valueOf(lockEpochMillis)); + queryObject.addValue("0"); + queryObject.addValue(isWriteLock); + queryObject.appendQueryString(insQuery); + boolean pResult = dsHandle.executePut(queryObject, "critical"); + return String.valueOf(lockRef); + } + finally { + TimeMeasureInstance.instance().exit(); + } } /** @@ -200,19 +207,25 @@ public class CassaLockStore { */ public LockObject peekLockQueue(String keyspace, String table, String key) throws MusicServiceException, MusicQueryException { - logger.info(EELFLoggerDelegate.applicationLogger, - "Peek in lock table for " + keyspace+"."+table+"."+key); - table = table_prepend_name+table; - String selectQuery = "select * from "+keyspace+"."+table+" where key='"+key+"' LIMIT 1;"; - PreparedQueryObject queryObject = new PreparedQueryObject(); - queryObject.appendQueryString(selectQuery); - ResultSet results = dsHandle.executeOneConsistencyGet(queryObject); - Row row = results.one(); - String lockReference = "" + row.getLong("lockReference"); - String createTime = row.getString("createTime"); - String acquireTime = row.getString("acquireTime"); + TimeMeasureInstance.instance().enter("peekLockQueue"); + try { + logger.info(EELFLoggerDelegate.applicationLogger, + "Peek in lock table for " + keyspace+"."+table+"."+key); + table = table_prepend_name+table; + String selectQuery = "select * from "+keyspace+"."+table+" where key='"+key+"' LIMIT 1;"; + PreparedQueryObject queryObject = new PreparedQueryObject(); + queryObject.appendQueryString(selectQuery); + ResultSet results = dsHandle.executeOneConsistencyGet(queryObject); + Row row = results.one(); + String lockReference = "" + row.getLong("lockReference"); + String createTime = row.getString("createTime"); + String acquireTime = row.getString("acquireTime"); - return new LockObject(lockReference, createTime,acquireTime); + return new LockObject(lockReference, createTime,acquireTime); + } + finally { + TimeMeasureInstance.instance().exit(); + } } public boolean isTopOfLockQueue(String keyspace, String table, String key, String lockRef) @@ -255,23 +268,34 @@ public class CassaLockStore { * @throws MusicQueryException */ public void deQueueLockRef(String keyspace, String table, String key, String lockReference) throws MusicServiceException, MusicQueryException{ - table = table_prepend_name+table; - PreparedQueryObject queryObject = new PreparedQueryObject(); - Long lockReferenceL = Long.parseLong(lockReference); - String deleteQuery = "delete from "+keyspace+"."+table+" where key='"+key+"' AND lockReference ="+lockReferenceL+" IF EXISTS;"; - queryObject.appendQueryString(deleteQuery); - dsHandle.executePut(queryObject, "critical"); + TimeMeasureInstance.instance().enter("deQueueLockRef"); + try { + table = table_prepend_name+table; + PreparedQueryObject queryObject = new PreparedQueryObject(); + Long lockReferenceL = Long.parseLong(lockReference); + String deleteQuery = "delete from "+keyspace+"."+table+" where key='"+key+"' AND lockReference ="+lockReferenceL+" IF EXISTS;"; + queryObject.appendQueryString(deleteQuery); + dsHandle.executePut(queryObject, "critical"); + } + finally { + TimeMeasureInstance.instance().exit(); + } } public void updateLockAcquireTime(String keyspace, String table, String key, String lockReference) throws MusicServiceException, MusicQueryException{ - table = table_prepend_name+table; - PreparedQueryObject queryObject = new PreparedQueryObject(); - Long lockReferenceL = Long.parseLong(lockReference); - String updateQuery = "update "+keyspace+"."+table+" set acquireTime='"+ System.currentTimeMillis()+"' where key='"+key+"' AND lockReference = "+lockReferenceL+" IF EXISTS;"; - queryObject.appendQueryString(updateQuery); - dsHandle.executePut(queryObject, "eventual"); - + TimeMeasureInstance.instance().enter("updateLockAcquireTime"); + try { + table = table_prepend_name+table; + PreparedQueryObject queryObject = new PreparedQueryObject(); + Long lockReferenceL = Long.parseLong(lockReference); + String updateQuery = "update "+keyspace+"."+table+" set acquireTime='"+ System.currentTimeMillis()+"' where key='"+key+"' AND lockReference = "+lockReferenceL+";"; + queryObject.appendQueryString(updateQuery); + dsHandle.executePut(queryObject, "eventual"); + } + finally { + TimeMeasureInstance.instance().exit(); + } } diff --git a/src/main/java/org/onap/music/service/impl/MusicCassaCore.java b/src/main/java/org/onap/music/service/impl/MusicCassaCore.java index f897c181..79662822 100644 --- a/src/main/java/org/onap/music/service/impl/MusicCassaCore.java +++ b/src/main/java/org/onap/music/service/impl/MusicCassaCore.java @@ -54,6 +54,7 @@ import com.datastax.driver.core.DataType; import com.datastax.driver.core.ResultSet; import com.datastax.driver.core.Row; import com.datastax.driver.core.TableMetadata; +import org.onap.music.util.TimeMeasureInstance; /** @@ -102,22 +103,28 @@ public class MusicCassaCore implements MusicCoreService { } public String createLockReference(String fullyQualifiedKey, boolean isWriteLock) { - String[] splitString = fullyQualifiedKey.split("\\."); - String keyspace = splitString[0]; - String table = splitString[1]; - String lockName = splitString[2]; - - logger.info(EELFLoggerDelegate.applicationLogger,"Creating lock reference for lock name:" + lockName); - long start = System.currentTimeMillis(); - String lockReference = null; + TimeMeasureInstance.instance().enter("createLockReference"); try { - lockReference = "" + getLockingServiceHandle().genLockRefandEnQueue(keyspace, table, lockName, isWriteLock); - } catch (MusicLockingException | MusicServiceException | MusicQueryException e) { - e.printStackTrace(); - } - long end = System.currentTimeMillis(); - logger.info(EELFLoggerDelegate.applicationLogger,"Time taken to create lock reference:" + (end - start) + " ms"); - return lockReference; + String[] splitString = fullyQualifiedKey.split("\\."); + String keyspace = splitString[0]; + String table = splitString[1]; + String lockName = splitString[2]; + + logger.info(EELFLoggerDelegate.applicationLogger, "Creating lock reference for lock name:" + lockName); + long start = System.currentTimeMillis(); + String lockReference = null; + try { + lockReference = "" + getLockingServiceHandle().genLockRefandEnQueue(keyspace, table, lockName, isWriteLock); + } catch (MusicLockingException | MusicServiceException | MusicQueryException e) { + e.printStackTrace(); + } + long end = System.currentTimeMillis(); + logger.info(EELFLoggerDelegate.applicationLogger, "Time taken to create lock reference:" + (end - start) + " ms"); + return lockReference; + } + finally { + TimeMeasureInstance.instance().exit(); + } } @@ -146,16 +153,17 @@ public class MusicCassaCore implements MusicCoreService { } private static ReturnType isTopOfLockStore(String keyspace, String table, - String primaryKeyValue, String lockReference) - throws MusicLockingException, MusicQueryException, MusicServiceException { - - // return failure to lock holders too early or already evicted from the lock store - String topOfLockStoreS = - getLockingServiceHandle().peekLockQueue(keyspace, table, primaryKeyValue).lockRef; - long topOfLockStoreL = Long.parseLong(topOfLockStoreS); - long lockReferenceL = Long.parseLong(lockReference); + String primaryKeyValue, String lockReference) + throws MusicLockingException, MusicQueryException, MusicServiceException { + TimeMeasureInstance.instance().enter("isTopOfLockStore"); + try { + // return failure to lock holders too early or already evicted from the lock store + String topOfLockStoreS = + getLockingServiceHandle().peekLockQueue(keyspace, table, primaryKeyValue).lockRef; + long topOfLockStoreL = Long.parseLong(topOfLockStoreS); + long lockReferenceL = Long.parseLong(lockReference); - if (lockReferenceL > topOfLockStoreL) { + if (lockReferenceL > topOfLockStoreL) { // only need to check if this is a read lock.... if (getLockingServiceHandle().isTopOfLockQueue(keyspace, table, primaryKeyValue, lockReference)) { @@ -165,55 +173,65 @@ public class MusicCassaCore implements MusicCoreService { lockReference + " is not the lock holder yet"); return new ReturnType(ResultType.FAILURE, lockReference + " is not the lock holder yet"); - } + } - if (lockReferenceL < topOfLockStoreL) { + if (lockReferenceL < topOfLockStoreL) { logger.info(EELFLoggerDelegate.applicationLogger, lockReference + " is no longer/or was never in the lock store queue"); return new ReturnType(ResultType.FAILURE, lockReference + " is no longer/or was never in the lock store queue"); - } + } - return new ReturnType(ResultType.SUCCESS, lockReference + " is top of lock store"); + return new ReturnType(ResultType.SUCCESS, lockReference + " is top of lock store"); + } + finally { + TimeMeasureInstance.instance().exit(); + } } - + public ReturnType acquireLock(String fullyQualifiedKey, String lockReference) throws MusicLockingException, MusicQueryException, MusicServiceException { - String[] splitString = fullyQualifiedKey.split("\\."); - String keyspace = splitString[0]; - String table = splitString[1]; - String primaryKeyValue = splitString[2]; + TimeMeasureInstance.instance().enter("acquireLock"); + try { + String[] splitString = fullyQualifiedKey.split("\\."); + String keyspace = splitString[0]; + String table = splitString[1]; + String primaryKeyValue = splitString[2]; - ReturnType result = isTopOfLockStore(keyspace, table, primaryKeyValue, lockReference); - - if(result.getResult().equals(ResultType.FAILURE)) - return result;//not top of the lock store q - - //check to see if the value of the key has to be synced in case there was a forceful release - String syncTable = keyspace+".unsyncedKeys_"+table; - String query = "select * from "+syncTable+" where key='"+fullyQualifiedKey+"';"; - PreparedQueryObject readQueryObject = new PreparedQueryObject(); - readQueryObject.appendQueryString(query); - ResultSet results = MusicDataStoreHandle.getDSHandle().executeQuorumConsistencyGet(readQueryObject); - if (results.all().size() != 0) { - logger.info("In acquire lock: Since there was a forcible release, need to sync quorum!"); - try { - syncQuorum(keyspace, table, primaryKeyValue); - } catch (Exception e) { - StringWriter sw = new StringWriter(); - logger.error(EELFLoggerDelegate.errorLogger,e.getMessage(), "[ERR506E] Failed to aquire lock ",ErrorSeverity.CRITICAL, ErrorTypes.LOCKINGERROR); - String exceptionAsString = sw.toString(); - return new ReturnType(ResultType.FAILURE, "Exception thrown while syncing key:\n" + exceptionAsString); - } - String cleanQuery = "delete from music_internal.unsynced_keys where key='"+fullyQualifiedKey+"';"; - PreparedQueryObject deleteQueryObject = new PreparedQueryObject(); - deleteQueryObject.appendQueryString(cleanQuery); - MusicDataStoreHandle.getDSHandle().executePut(deleteQueryObject, "critical"); - } - - getLockingServiceHandle().updateLockAcquireTime(keyspace, table, primaryKeyValue, lockReference); - - return new ReturnType(ResultType.SUCCESS, lockReference+" is the lock holder for the key"); + ReturnType result = isTopOfLockStore(keyspace, table, primaryKeyValue, lockReference); + + if (result.getResult().equals(ResultType.FAILURE)) + return result;//not top of the lock store q + + //check to see if the value of the key has to be synced in case there was a forceful release + String syncTable = keyspace + ".unsyncedKeys_" + table; + String query = "select * from " + syncTable + " where key='" + fullyQualifiedKey + "';"; + PreparedQueryObject readQueryObject = new PreparedQueryObject(); + readQueryObject.appendQueryString(query); + ResultSet results = MusicDataStoreHandle.getDSHandle().executeQuorumConsistencyGet(readQueryObject); + if (results.all().size() != 0) { + logger.info("In acquire lock: Since there was a forcible release, need to sync quorum!"); + try { + syncQuorum(keyspace, table, primaryKeyValue); + } catch (Exception e) { + StringWriter sw = new StringWriter(); + logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(), "[ERR506E] Failed to aquire lock ", ErrorSeverity.CRITICAL, ErrorTypes.LOCKINGERROR); + String exceptionAsString = sw.toString(); + return new ReturnType(ResultType.FAILURE, "Exception thrown while syncing key:\n" + exceptionAsString); + } + String cleanQuery = "delete from music_internal.unsynced_keys where key='" + fullyQualifiedKey + "';"; + PreparedQueryObject deleteQueryObject = new PreparedQueryObject(); + deleteQueryObject.appendQueryString(cleanQuery); + MusicDataStoreHandle.getDSHandle().executePut(deleteQueryObject, "critical"); + } + + getLockingServiceHandle().updateLockAcquireTime(keyspace, table, primaryKeyValue, lockReference); + + return new ReturnType(ResultType.SUCCESS, lockReference + " is the lock holder for the key"); + } + finally { + TimeMeasureInstance.instance().exit(); + } } @@ -359,23 +377,35 @@ public class MusicCassaCore implements MusicCoreService { } public MusicLockState destroyLockRef(String fullyQualifiedKey, String lockReference) { - long start = System.currentTimeMillis(); - String[] splitString = fullyQualifiedKey.split("\\."); - String keyspace = splitString[0]; - String table = splitString[1]; - String primaryKeyValue = splitString[2]; + TimeMeasureInstance.instance().enter("destroyLockRef"); try { - getLockingServiceHandle().deQueueLockRef(keyspace, table, primaryKeyValue, lockReference); - } catch (MusicLockingException | MusicServiceException | MusicQueryException e) { - logger.error(EELFLoggerDelegate.errorLogger,e.getMessage(), AppMessages.DESTROYLOCK+lockReference ,ErrorSeverity.CRITICAL, ErrorTypes.LOCKINGERROR); - } - long end = System.currentTimeMillis(); - logger.info(EELFLoggerDelegate.applicationLogger,"Time taken to destroy lock reference:" + (end - start) + " ms"); - return getMusicLockState(fullyQualifiedKey); + long start = System.currentTimeMillis(); + String[] splitString = fullyQualifiedKey.split("\\."); + String keyspace = splitString[0]; + String table = splitString[1]; + String primaryKeyValue = splitString[2]; + try { + getLockingServiceHandle().deQueueLockRef(keyspace, table, primaryKeyValue, lockReference); + } catch (MusicLockingException | MusicServiceException | MusicQueryException e) { + logger.error(EELFLoggerDelegate.errorLogger, e.getMessage(), AppMessages.DESTROYLOCK + lockReference, ErrorSeverity.CRITICAL, ErrorTypes.LOCKINGERROR); + } + long end = System.currentTimeMillis(); + logger.info(EELFLoggerDelegate.applicationLogger, "Time taken to destroy lock reference:" + (end - start) + " ms"); + return getMusicLockState(fullyQualifiedKey); + } + finally { + TimeMeasureInstance.instance().exit(); + } } public MusicLockState voluntaryReleaseLock(String fullyQualifiedKey, String lockReference) throws MusicLockingException{ - return destroyLockRef(fullyQualifiedKey, lockReference); + TimeMeasureInstance.instance().enter("voluntaryReleaseLock"); + try { + return destroyLockRef(fullyQualifiedKey, lockReference); + } + finally { + TimeMeasureInstance.instance().exit(); + } } public MusicLockState forciblyReleaseLock(String fullyQualifiedKey, String lockReference) throws MusicLockingException, MusicServiceException, MusicQueryException{ @@ -384,14 +414,14 @@ public class MusicCassaCore implements MusicCoreService { String table = splitString[1]; //leave a signal that this key could potentially be unsynchronized - String syncTable = keyspace+".unsyncedKeys_"+table; + String syncTable = keyspace+".unsyncedKeys_"+table; PreparedQueryObject queryObject = new PreparedQueryObject(); String values = "(?)"; queryObject.addValue(fullyQualifiedKey); String insQuery = "insert into "+syncTable+" (key) values "+values+";"; queryObject.appendQueryString(insQuery); - MusicDataStoreHandle.getDSHandle().executePut(queryObject, "critical"); - + MusicDataStoreHandle.getDSHandle().executePut(queryObject, "critical"); + //now release the lock return destroyLockRef(fullyQualifiedKey, lockReference); } @@ -440,41 +470,47 @@ public class MusicCassaCore implements MusicCoreService { */ public ReturnType criticalPut(String keyspace, String table, String primaryKeyValue, PreparedQueryObject queryObject, String lockReference, Condition conditionInfo) { - long start = System.currentTimeMillis(); + TimeMeasureInstance.instance().enter("executePut"); try { - ReturnType result = isTopOfLockStore(keyspace, table, primaryKeyValue, lockReference); - if(result.getResult().equals(ResultType.FAILURE)) - return result;//not top of the lock store q - - if (conditionInfo != null) + long start = System.currentTimeMillis(); try { - if (conditionInfo.testCondition() == false) - return new ReturnType(ResultType.FAILURE, - "Lock acquired but the condition is not true"); - } catch (Exception e) { - return new ReturnType(ResultType.FAILURE, - "Exception thrown while checking the condition, check its sanctity:\n" - + e.getMessage()); + ReturnType result = isTopOfLockStore(keyspace, table, primaryKeyValue, lockReference); + if (result.getResult().equals(ResultType.FAILURE)) + return result;//not top of the lock store q + + if (conditionInfo != null) + try { + if (conditionInfo.testCondition() == false) + return new ReturnType(ResultType.FAILURE, + "Lock acquired but the condition is not true"); + } catch (Exception e) { + return new ReturnType(ResultType.FAILURE, + "Exception thrown while checking the condition, check its sanctity:\n" + + e.getMessage()); + } + + String query = queryObject.getQuery(); + long timeOfWrite = System.currentTimeMillis(); + long lockOrdinal = Long.parseLong(lockReference); + long ts = MusicUtil.v2sTimeStampInMicroseconds(lockOrdinal, timeOfWrite); + // TODO: use Statement instead of modifying query + query = query.replaceFirst("SET", "USING TIMESTAMP " + ts + " SET"); + queryObject.replaceQueryString(query); + MusicDataStore dsHandle = MusicDataStoreHandle.getDSHandle(); + dsHandle.executePut(queryObject, MusicUtil.CRITICAL); + long end = System.currentTimeMillis(); + logger.info(EELFLoggerDelegate.applicationLogger, "Time taken for the critical put:" + (end - start) + " ms"); + } catch (MusicQueryException | MusicServiceException | MusicLockingException e) { + logger.error(EELFLoggerDelegate.errorLogger, e.getMessage()); + return new ReturnType(ResultType.FAILURE, + "Exception thrown while doing the critical put\n" + + e.getMessage()); } - - String query = queryObject.getQuery(); - long timeOfWrite = System.currentTimeMillis(); - long lockOrdinal = Long.parseLong(lockReference); - long ts = MusicUtil.v2sTimeStampInMicroseconds(lockOrdinal, timeOfWrite); - // TODO: use Statement instead of modifying query - query = query.replaceFirst("SET", "USING TIMESTAMP "+ ts + " SET"); - queryObject.replaceQueryString(query); - MusicDataStore dsHandle = MusicDataStoreHandle.getDSHandle(); - dsHandle.executePut(queryObject, MusicUtil.CRITICAL); - long end = System.currentTimeMillis(); - logger.info(EELFLoggerDelegate.applicationLogger,"Time taken for the critical put:" + (end - start) + " ms"); - }catch (MusicQueryException | MusicServiceException | MusicLockingException e) { - logger.error(EELFLoggerDelegate.errorLogger,e.getMessage()); - return new ReturnType(ResultType.FAILURE, - "Exception thrown while doing the critical put\n" - + e.getMessage()); + return new ReturnType(ResultType.SUCCESS, "Update performed"); + } + finally { + TimeMeasureInstance.instance().exit(); } - return new ReturnType(ResultType.SUCCESS, "Update performed"); } @@ -559,31 +595,37 @@ public class MusicCassaCore implements MusicCoreService { */ public ReturnType atomicPut(String keyspaceName, String tableName, String primaryKey, PreparedQueryObject queryObject, Condition conditionInfo) throws MusicLockingException, MusicQueryException, MusicServiceException { - long start = System.currentTimeMillis(); - String fullyQualifiedKey = keyspaceName + "." + tableName + "." + primaryKey; - String lockReference = createLockReference(fullyQualifiedKey); - long lockCreationTime = System.currentTimeMillis(); - ReturnType lockAcqResult = acquireLock(fullyQualifiedKey, lockReference); - long lockAcqTime = System.currentTimeMillis(); + TimeMeasureInstance.instance().enter("atomicPut"); + try { + long start = System.currentTimeMillis(); + String fullyQualifiedKey = keyspaceName + "." + tableName + "." + primaryKey; + String lockReference = createLockReference(fullyQualifiedKey); + long lockCreationTime = System.currentTimeMillis(); + ReturnType lockAcqResult = acquireLock(fullyQualifiedKey, lockReference); + long lockAcqTime = System.currentTimeMillis(); + + if (!lockAcqResult.getResult().equals(ResultType.SUCCESS)) { + logger.info(EELFLoggerDelegate.applicationLogger, "unable to acquire lock, id " + lockReference); + voluntaryReleaseLock(fullyQualifiedKey, lockReference); + return lockAcqResult; + } - if (!lockAcqResult.getResult().equals(ResultType.SUCCESS)) { - logger.info(EELFLoggerDelegate.applicationLogger,"unable to acquire lock, id " + lockReference); - voluntaryReleaseLock(fullyQualifiedKey,lockReference); - return lockAcqResult; + logger.info(EELFLoggerDelegate.applicationLogger, "acquired lock with id " + lockReference); + ReturnType criticalPutResult = criticalPut(keyspaceName, tableName, primaryKey, + queryObject, lockReference, conditionInfo); + long criticalPutTime = System.currentTimeMillis(); + voluntaryReleaseLock(fullyQualifiedKey, lockReference); + long lockDeleteTime = System.currentTimeMillis(); + String timingInfo = "|lock creation time:" + (lockCreationTime - start) + + "|lock accquire time:" + (lockAcqTime - lockCreationTime) + + "|critical put time:" + (criticalPutTime - lockAcqTime) + + "|lock delete time:" + (lockDeleteTime - criticalPutTime) + "|"; + criticalPutResult.setTimingInfo(timingInfo); + return criticalPutResult; + } + finally { + TimeMeasureInstance.instance().exit(); } - - logger.info(EELFLoggerDelegate.applicationLogger,"acquired lock with id " + lockReference); - ReturnType criticalPutResult = criticalPut(keyspaceName, tableName, primaryKey, - queryObject, lockReference, conditionInfo); - long criticalPutTime = System.currentTimeMillis(); - voluntaryReleaseLock(fullyQualifiedKey,lockReference); - long lockDeleteTime = System.currentTimeMillis(); - String timingInfo = "|lock creation time:" + (lockCreationTime - start) - + "|lock accquire time:" + (lockAcqTime - lockCreationTime) - + "|critical put time:" + (criticalPutTime - lockAcqTime) - + "|lock delete time:" + (lockDeleteTime - criticalPutTime) + "|"; - criticalPutResult.setTimingInfo(timingInfo); - return criticalPutResult; } diff --git a/src/main/java/org/onap/music/testruns/ComparisonPoints1.java b/src/main/java/org/onap/music/testruns/ComparisonPoints1.java index 5b6c81d8..6773d137 100644 --- a/src/main/java/org/onap/music/testruns/ComparisonPoints1.java +++ b/src/main/java/org/onap/music/testruns/ComparisonPoints1.java @@ -268,7 +268,7 @@ public class ComparisonPoints1 Map> e = tm.percentiles(); Map> m = tm.stats(); DecimalFormat df = new DecimalFormat("000.000000"); - e.forEach((k,v) -> System.out.println("" + k + "\t\t: " + Arrays.toString(v.stream().map(w -> "" + df.format(w)).toArray()))); +// e.forEach((k,v) -> System.out.println("" + k + "\t\t: " + Arrays.toString(v.stream().map(w -> "" + df.format(w)).toArray()))); m.forEach((k,v) -> System.out.println("" + k + "\t\t: " + df.format(v.getLeft()) + " (" + df.format(v.getRight()) + ")")); System.exit(0); -- cgit 1.2.3-korg