VOL-1616 / VOL-1611 : Fix device state issue and memory discrepencies

- Applied mutex on node object to resolve in-memory data conflicts
- Introduced a refresh period for in-memory data

Amendments:

- Fixed node.go file format
- Bumped VERSION to 2.1.0-dev
- Use a RLock for GetLastUpdate

Change-Id: I57e88fe3ec5cceed0d4fcdb240ae9191b49ebe33
diff --git a/VERSION b/VERSION
index 227cea2..c10edc3 100644
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-2.0.0
+2.1.0-dev
diff --git a/db/model/node.go b/db/model/node.go
index 1621b6f..9c450af 100644
--- a/db/model/node.go
+++ b/db/model/node.go
@@ -26,11 +26,16 @@
 	"reflect"
 	"strings"
 	"sync"
+	"time"
 )
 
 // When a branch has no transaction id, everything gets stored in NONE
 const (
 	NONE string = "none"
+
+	// period to determine when data requires a refresh (in seconds)
+	// TODO: make this configurable?
+	DATA_REFRESH_PERIOD int64 = 5000
 )
 
 // Node interface is an abstraction of the node data structure
@@ -56,7 +61,7 @@
 }
 
 type node struct {
-	sync.RWMutex
+	mutex     sync.RWMutex
 	Root      *root
 	Type      interface{}
 	Branches  map[string]*Branch
@@ -113,9 +118,6 @@
 
 // makeLatest will mark the revision of a node as being the latest
 func (n *node) makeLatest(branch *Branch, revision Revision, changeAnnouncement []ChangeTuple) {
-	n.Lock()
-	defer n.Unlock()
-
 	// Keep a reference to the current revision
 	var previous string
 	if branch.GetLatest() != nil {
@@ -127,6 +129,9 @@
 	// If anything is new, then set the revision as the latest
 	if branch.GetLatest() == nil || revision.GetHash() != branch.GetLatest().GetHash() {
 		if revision.GetName() != "" {
+			log.Debugw("saving-latest-data", log.Fields{"hash": revision.GetHash(), "data": revision.GetData()})
+			// Tag a timestamp to that revision
+			revision.SetLastUpdate()
 			GetRevCache().Cache.Store(revision.GetName(), revision)
 		}
 		branch.SetLatest(revision)
@@ -174,7 +179,6 @@
 
 // initialize prepares the content of a node along with its possible ramifications
 func (n *node) initialize(data interface{}, txid string) {
-	n.Lock()
 	children := make(map[string][]Revision)
 	for fieldName, field := range ChildrenFields(n.Type) {
 		_, fieldValue := GetAttributeValue(data, fieldName, 0)
@@ -217,7 +221,6 @@
 			log.Errorf("field is invalid - %+v", fieldValue)
 		}
 	}
-	n.Unlock()
 
 	branch := NewBranch(n, "", nil, n.AutoPrune)
 	rev := n.MakeRevision(branch, data, children)
@@ -232,9 +235,6 @@
 
 // findRevByKey retrieves a specific revision from a node tree
 func (n *node) findRevByKey(revs []Revision, keyName string, value interface{}) (int, Revision) {
-	n.Lock()
-	defer n.Unlock()
-
 	for i, rev := range revs {
 		dataValue := reflect.ValueOf(rev.GetData())
 		dataStruct := GetAttributeStructure(rev.GetData(), keyName, 0)
@@ -253,6 +253,9 @@
 
 // Get retrieves the data from a node tree that resides at the specified path
 func (n *node) List(path string, hash string, depth int, deep bool, txid string) interface{} {
+	n.mutex.Lock()
+	defer n.mutex.Unlock()
+
 	log.Debugw("node-list-request", log.Fields{"path": path, "hash": hash, "depth": depth, "deep": deep, "txid": txid})
 	if deep {
 		depth = -1
@@ -289,6 +292,9 @@
 
 // Get retrieves the data from a node tree that resides at the specified path
 func (n *node) Get(path string, hash string, depth int, reconcile bool, txid string) interface{} {
+	n.mutex.Lock()
+	defer n.mutex.Unlock()
+
 	log.Debugw("node-get-request", log.Fields{"path": path, "hash": hash, "depth": depth, "reconcile": reconcile, "txid": txid})
 
 	for strings.HasPrefix(path, "/") {
@@ -315,15 +321,35 @@
 		// Try to find an entry matching the path value from one of these sources
 		// 1.  Start with the cache which stores revisions by watch names
 		// 2.  Then look in the revision tree, especially if it's a sub-path such as /devices/1234/flows
-		// 3.  As a last effort, move on to the KV store
+		// 3.  Move on to the KV store if that path cannot be found or if the entry has expired
 		if entry, exists := GetRevCache().Cache.Load(path); exists && entry.(Revision) != nil {
-			return proto.Clone(entry.(Revision).GetData().(proto.Message))
+			entryAge := time.Now().Sub(entry.(Revision).GetLastUpdate()).Nanoseconds() / int64(time.Millisecond)
+			if entryAge < DATA_REFRESH_PERIOD {
+				log.Debugw("using-cache-entry", log.Fields{"path": path, "hash": hash, "age": entryAge})
+				return proto.Clone(entry.(Revision).GetData().(proto.Message))
+			} else {
+				log.Debugw("cache-entry-expired", log.Fields{"path": path, "hash": hash, "age": entryAge})
+			}
 		} else if result = n.getPath(rev.GetBranch().GetLatest(), path, depth); result != nil && reflect.ValueOf(result).IsValid() && !reflect.ValueOf(result).IsNil() {
+			log.Debugw("using-rev-tree-entry", log.Fields{"path": path, "hash": hash, "depth": depth, "reconcile": reconcile, "txid": txid})
 			return result
+		} else {
+			log.Debugw("not-using-cache-entry", log.Fields{
+				"path": path,
+				"hash": hash, "depth": depth,
+				"reconcile": reconcile,
+				"txid":      txid,
+			})
 		}
+	} else {
+		log.Debugw("reconcile-requested", log.Fields{
+			"path":      path,
+			"hash":      hash,
+			"reconcile": reconcile,
+		})
 	}
 
-	// If we got to this point, we are either trying to reconcile with the db or
+	// If we got to this point, we are either trying to reconcile with the db
 	// or we simply failed at getting information from memory
 	if n.Root.KvStore != nil {
 		if pr := rev.LoadFromPersistence(path, txid, nil); pr != nil && len(pr) > 0 {
@@ -424,6 +450,9 @@
 
 // Update changes the content of a node at the specified path with the provided data
 func (n *node) Update(path string, data interface{}, strict bool, txid string, makeBranch MakeBranchFunction) Revision {
+	n.mutex.Lock()
+	defer n.mutex.Unlock()
+
 	log.Debugw("node-update-request", log.Fields{"path": path, "strict": strict, "txid": txid, "makeBranch": makeBranch})
 
 	for strings.HasPrefix(path, "/") {
@@ -590,6 +619,9 @@
 
 // Add inserts a new node at the specified path with the provided data
 func (n *node) Add(path string, data interface{}, txid string, makeBranch MakeBranchFunction) Revision {
+	n.mutex.Lock()
+	defer n.mutex.Unlock()
+
 	log.Debugw("node-add-request", log.Fields{"path": path, "txid": txid, "makeBranch": makeBranch})
 
 	for strings.HasPrefix(path, "/") {
@@ -653,6 +685,7 @@
 
 				updatedRev := rev.UpdateChildren(name, children, branch)
 				changes := []ChangeTuple{{POST_ADD, nil, childRev.GetData()}}
+				childRev.GetNode().SetProxy(n.GetProxy())
 				childRev.SetupWatch(childRev.GetName())
 
 				n.makeLatest(branch, updatedRev, changes)
@@ -713,6 +746,9 @@
 
 // Remove eliminates a node at the specified path
 func (n *node) Remove(path string, txid string, makeBranch MakeBranchFunction) Revision {
+	n.mutex.Lock()
+	defer n.mutex.Unlock()
+
 	log.Debugw("node-remove-request", log.Fields{"path": path, "txid": txid, "makeBranch": makeBranch})
 
 	for strings.HasPrefix(path, "/") {
@@ -833,8 +869,6 @@
 
 // DeleteBranch removes a branch with the specified id
 func (n *node) DeleteBranch(txid string) {
-	n.Lock()
-	defer n.Unlock()
 	delete(n.Branches, txid)
 }
 
@@ -969,8 +1003,6 @@
 }
 
 func (n *node) makeProxy(path string, fullPath string, parentNode *node, exclusive bool) *Proxy {
-	n.Lock()
-	defer n.Unlock()
 	r := &root{
 		node:                  n,
 		Callbacks:             n.Root.GetCallbacks(),
@@ -993,8 +1025,6 @@
 }
 
 func (n *node) makeEventBus() *EventBus {
-	n.Lock()
-	defer n.Unlock()
 	if n.EventBus == nil {
 		n.EventBus = NewEventBus()
 	}
@@ -1002,21 +1032,14 @@
 }
 
 func (n *node) SetProxy(proxy *Proxy) {
-	n.Lock()
-	defer n.Unlock()
 	n.Proxy = proxy
 }
 
 func (n *node) GetProxy() *Proxy {
-	n.Lock()
-	defer n.Unlock()
 	return n.Proxy
 }
 
 func (n *node) GetBranch(key string) *Branch {
-	n.Lock()
-	defer n.Unlock()
-
 	if n.Branches != nil {
 		if branch, exists := n.Branches[key]; exists {
 			return branch
@@ -1026,13 +1049,9 @@
 }
 
 func (n *node) SetBranch(key string, branch *Branch) {
-	n.Lock()
-	defer n.Unlock()
 	n.Branches[key] = branch
 }
 
 func (n *node) GetRoot() *root {
-	n.Lock()
-	defer n.Unlock()
 	return n.Root
 }
diff --git a/db/model/non_persisted_revision.go b/db/model/non_persisted_revision.go
index d7b0b58..6075b3f 100644
--- a/db/model/non_persisted_revision.go
+++ b/db/model/non_persisted_revision.go
@@ -25,6 +25,7 @@
 	"reflect"
 	"sort"
 	"sync"
+	"time"
 )
 
 // TODO: Cache logic will have to be revisited to cleanup unused entries in memory (disabled for now)
@@ -55,6 +56,7 @@
 	WeakRef      string
 	Name         string
 	discarded    bool
+	lastUpdate   time.Time
 }
 
 func NewNonPersistedRevision(root *root, branch *Branch, data interface{}, children map[string][]Revision) Revision {
@@ -290,6 +292,7 @@
 	newRev.Root = npr.Root
 	newRev.Name = npr.Name
 	newRev.Branch = branch
+	newRev.lastUpdate = npr.lastUpdate
 
 	newRev.Children = make(map[string][]Revision)
 	for entryName, childrenEntry := range branch.GetLatest().GetAllChildren() {
@@ -313,6 +316,7 @@
 	updatedRev.Hash = npr.Hash
 	updatedRev.Branch = branch
 	updatedRev.Name = npr.Name
+	updatedRev.lastUpdate = npr.lastUpdate
 
 	updatedRev.Children = make(map[string][]Revision)
 	for entryName, childrenEntry := range branch.GetLatest().GetAllChildren() {
@@ -395,6 +399,7 @@
 	newRev.Hash = npr.Hash
 	newRev.Branch = branch
 	newRev.Name = npr.Name
+	newRev.lastUpdate = npr.lastUpdate
 
 	newRev.Children = make(map[string][]Revision)
 	for entryName, childrenEntry := range children {
@@ -426,6 +431,24 @@
 	}
 }
 
+func (npr *NonPersistedRevision) SetLastUpdate(ts ...time.Time) {
+	npr.mutex.Lock()
+	defer npr.mutex.Unlock()
+
+	if ts != nil && len(ts) > 0 {
+		npr.lastUpdate = ts[0]
+	} else {
+		npr.lastUpdate = time.Now()
+	}
+}
+
+func (npr *NonPersistedRevision) GetLastUpdate() time.Time {
+	npr.mutex.RLock()
+	defer npr.mutex.RUnlock()
+
+	return npr.lastUpdate
+}
+
 func (npr *NonPersistedRevision) LoadFromPersistence(path string, txid string, blobs map[string]*kvstore.KVPair) []Revision {
 	// stub... required by interface
 	return nil
diff --git a/db/model/persisted_revision.go b/db/model/persisted_revision.go
index ea99cf7..226fc3c 100644
--- a/db/model/persisted_revision.go
+++ b/db/model/persisted_revision.go
@@ -154,6 +154,8 @@
 				if err := proto.Unmarshal(event.Value.([]byte), data.Interface().(proto.Message)); err != nil {
 					log.Errorw("failed-to-unmarshal-watch-data", log.Fields{"key": pr.GetHash(), "watch": pr.GetName(), "error": err})
 				} else {
+					log.Debugw("un-marshaled-watch-data", log.Fields{"key": pr.GetHash(), "watch": pr.GetName(), "data": data.Interface()})
+
 					var pathLock string
 					var pac *proxyAccessControl
 					var blobs map[string]*kvstore.KVPair
@@ -182,69 +184,64 @@
 							log.Debugw("operation-in-progress", log.Fields{
 								"key":       pr.GetHash(),
 								"path":      pr.GetNode().GetProxy().getFullPath(),
-								"operation": pr.GetNode().GetRoot().GetProxy().Operation,
+								"operation": pr.GetNode().GetProxy().Operation.String(),
 							})
 
-							continue
+							// Identify the operation type and determine if the watch event should be applied or not.
+							switch pr.GetNode().GetProxy().Operation {
+							case PROXY_REMOVE:
+								fallthrough
 
-							// TODO/FIXME: keep logic for now in case we need to control based on running operation
-							//
-							// The code below seems to revert the in-memory/persistence value (occasionally) with
-							// the one received from the watch event.
-							//
-							// The same problem may occur, in the scenario where the core owning a device
-							// receives a watch event for an update made by another core, and when the owning core is
-							// also processing an update.  Need to investigate...
-							//
-							//switch pr.GetNode().GetRoot().GetProxy().Operation {
-							//case PROXY_UPDATE:
-							//	// We will need to reload once the update operation completes.
-							//	// Therefore, the data of the current event is most likely out-dated
-							//	// and should be ignored
-							//	log.Debugw("reload-required", log.Fields{
-							//		"key":       pr.GetHash(),
-							//		"path":      pr.GetNode().GetProxy().getFullPath(),
-							//		"operation": pr.GetNode().GetRoot().GetProxy().Operation,
-							//	})
-							//
-							//	// Eliminate the object constructed earlier
-							//	blobs = nil
-							//
-							//case PROXY_ADD:
-							//	fallthrough
-							//
-							//case PROXY_REMOVE:
-							//	fallthrough
-							//
-							//case PROXY_GET:
-							//	fallthrough
-							//
-							//default:
-							//	// No need to process the event ... move on
-							//	log.Debugw("", log.Fields{
-							//		"key":       pr.GetHash(),
-							//		"path":      pr.GetNode().GetProxy().getFullPath(),
-							//		"operation": pr.GetNode().GetRoot().GetProxy().Operation,
-							//	})
-							//
-							//	continue
-							//}
+							case PROXY_ADD:
+								fallthrough
+
+							case PROXY_UPDATE:
+								// We will need to reload once the operation completes.
+								// Therefore, the data of the current event is most likely out-dated
+								// and should be ignored
+								log.Debugw("ignore-watch-event", log.Fields{
+									"key":       pr.GetHash(),
+									"path":      pr.GetNode().GetProxy().getFullPath(),
+									"operation": pr.GetNode().GetProxy().Operation.String(),
+								})
+
+								continue
+
+							case PROXY_CREATE:
+								fallthrough
+
+							case PROXY_LIST:
+								fallthrough
+
+							case PROXY_GET:
+								fallthrough
+
+							default:
+								log.Debugw("process-watch-event", log.Fields{
+									"key":       pr.GetHash(),
+									"path":      pr.GetNode().GetProxy().getFullPath(),
+									"operation": pr.GetNode().GetProxy().Operation.String(),
+								})
+							}
 						}
 
 						// Reserve the path to prevent others to modify while we reload from persistence
 						log.Debugw("reserve-and-lock-path", log.Fields{"key": pr.GetHash(), "path": pathLock})
 						pac = PAC().ReservePath(pr.GetNode().GetProxy().getFullPath(), pr.GetNode().GetProxy(), pathLock)
-						pac.SetProxy(pr.GetNode().GetProxy())
 						pac.lock()
+						pr.GetNode().GetProxy().Operation = PROXY_UPDATE
+						pac.SetProxy(pr.GetNode().GetProxy())
 
 						// Load changes and apply to memory
 						pr.LoadFromPersistence(pr.GetName(), "", blobs)
 
 						log.Debugw("release-and-unlock-path", log.Fields{"key": pr.GetHash(), "path": pathLock})
+						pac.getProxy().Operation = PROXY_GET
 						pac.unlock()
 						PAC().ReleasePath(pathLock)
 
 					} else {
+						// This block should be reached only if coming from a non-proxied request
 						log.Debugw("revision-with-no-proxy", log.Fields{"key": pr.GetHash(), "watch": pr.GetName()})
 
 						// Load changes and apply to memory
@@ -380,42 +377,59 @@
 
 // verifyPersistedEntry validates if the provided data is available or not in memory and applies updates as required
 func (pr *PersistedRevision) verifyPersistedEntry(data interface{}, typeName string, keyName string, keyValue string, txid string) (response Revision) {
-	//rev := pr
+	// Parent which holds the current node entry
+	parent := pr.GetBranch().Node.Root
 
-	children := make([]Revision, len(pr.GetBranch().GetLatest().GetChildren(typeName)))
-	copy(children, pr.GetBranch().GetLatest().GetChildren(typeName))
+	// Get a copy of the parent's children
+	children := make([]Revision, len(parent.GetBranch(NONE).Latest.GetChildren(typeName)))
+	copy(children, parent.GetBranch(NONE).Latest.GetChildren(typeName))
 
-	// Verify if the revision contains a child that matches that key
-	if childIdx, childRev := pr.GetNode().findRevByKey(pr.GetBranch().GetLatest().GetChildren(typeName), keyName,
-		keyValue); childRev != nil {
+	// Verify if a child with the provided key value can be found
+	if childIdx, childRev := pr.GetNode().findRevByKey(children, keyName, keyValue); childRev != nil {
 		// A child matching the provided key exists in memory
-		// Verify if the data differs to what was retrieved from persistence
+		// Verify if the data differs from what was retrieved from persistence
 		if childRev.GetData().(proto.Message).String() != data.(proto.Message).String() {
-			log.Debugw("verify-persisted-entry--data-is-different", log.Fields{
+			log.Debugw("revision-data-is-different", log.Fields{
 				"key":  childRev.GetHash(),
 				"name": childRev.GetName(),
 				"data": childRev.GetData(),
 			})
 
+			//
 			// Data has changed; replace the child entry and update the parent revision
-			childRev.Drop(txid, false)
+			//
+
+			// BEGIN Lock child -- prevent any incoming changes
+			childRev.GetBranch().LatestLock.Lock()
+
+			// Update child
 			updatedChildRev := childRev.UpdateData(data, childRev.GetBranch())
+
 			updatedChildRev.GetNode().SetProxy(childRev.GetNode().GetProxy())
 			updatedChildRev.SetupWatch(updatedChildRev.GetName())
+			childRev.Drop(txid, false)
+			updatedChildRev.SetLastUpdate()
 
-			if childIdx >= 0 {
-				children[childIdx] = updatedChildRev
-			} else {
-				children = append(children, updatedChildRev)
-			}
+			// Update cache
+			GetRevCache().Cache.Store(updatedChildRev.GetName(), updatedChildRev)
 
-			pr.GetBranch().LatestLock.Lock()
-			updatedRev := pr.GetBranch().Node.Latest().UpdateChildren(typeName, children, pr.GetBranch())
-			pr.GetBranch().Node.makeLatest(pr.GetBranch(), updatedRev, nil)
-			pr.GetBranch().LatestLock.Unlock()
+			childRev.GetBranch().LatestLock.Unlock()
+			// END lock child
+
+			// Update child entry
+			children[childIdx] = updatedChildRev
+
+			// BEGIN lock parent -- Update parent
+			parent.GetBranch(NONE).LatestLock.Lock()
+
+			updatedRev := parent.GetBranch(NONE).Latest.UpdateChildren(typeName, children, parent.GetBranch(NONE))
+			parent.GetBranch(NONE).Node.makeLatest(parent.GetBranch(NONE), updatedRev, nil)
+
+			parent.GetBranch(NONE).LatestLock.Unlock()
+			// END lock parent
 
 			// Drop the previous child revision
-			pr.GetBranch().Node.Latest().ChildDrop(typeName, childRev.GetHash())
+			parent.GetBranch(NONE).Latest.ChildDrop(typeName, childRev.GetHash())
 
 			if updatedChildRev != nil {
 				log.Debugw("verify-persisted-entry--adding-child", log.Fields{
@@ -427,49 +441,64 @@
 			}
 		} else {
 			// Data is the same. Continue to the next entry
-			log.Debugw("verify-persisted-entry--same-data", log.Fields{
+			log.Debugw("same-revision-data", log.Fields{
 				"key":  childRev.GetHash(),
 				"name": childRev.GetName(),
 				"data": childRev.GetData(),
 			})
 			if childRev != nil {
-				log.Debugw("verify-persisted-entry--keeping-child", log.Fields{
+				log.Debugw("keeping-same-revision-data", log.Fields{
 					"key":  childRev.GetHash(),
 					"name": childRev.GetName(),
 					"data": childRev.GetData(),
 				})
+
+				// Update timestamp to reflect when it was last read and to reset tracked timeout
+				childRev.SetLastUpdate()
+				GetRevCache().Cache.Store(childRev.GetName(), childRev)
 				response = childRev
 			}
 		}
 	} else {
 		// There is no available child with that key value.
 		// Create a new child and update the parent revision.
-		log.Debugw("verify-persisted-entry--no-such-entry", log.Fields{
+		log.Debugw("no-such-revision-entry", log.Fields{
 			"key":  keyValue,
 			"name": typeName,
 			"data": data,
 		})
 
+		// BEGIN child lock
+		pr.GetBranch().LatestLock.Lock()
+
 		// Construct a new child node with the retrieved persistence data
 		childRev = pr.GetBranch().Node.MakeNode(data, txid).Latest(txid)
 
 		// We need to start watching this entry for future changes
 		childRev.SetName(typeName + "/" + keyValue)
-
-		// Add the child to the parent revision
-		pr.GetBranch().LatestLock.Lock()
-		children = append(children, childRev)
-		updatedRev := pr.GetBranch().Node.Latest().UpdateChildren(typeName, children, pr.GetBranch())
-		updatedRev.GetNode().SetProxy(pr.GetNode().GetProxy())
 		childRev.SetupWatch(childRev.GetName())
 
-		//rev.GetBranch().Node.Latest().Drop(txid, false)
-		pr.GetBranch().Node.makeLatest(pr.GetBranch(), updatedRev, nil)
+		pr.GetBranch().Node.makeLatest(pr.GetBranch(), childRev, nil)
 		pr.GetBranch().LatestLock.Unlock()
+		// END child lock
+
+		//
+		// Add the child to the parent revision
+		//
+
+		// BEGIN parent lock
+		parent.GetBranch(NONE).LatestLock.Lock()
+		children = append(children, childRev)
+		updatedRev := parent.GetBranch(NONE).Latest.UpdateChildren(typeName, children, parent.GetBranch(NONE))
+		updatedRev.GetNode().SetProxy(parent.GetBranch(NONE).Node.GetProxy())
+
+		parent.GetBranch(NONE).Node.makeLatest(parent.GetBranch(NONE), updatedRev, nil)
+		parent.GetBranch(NONE).LatestLock.Unlock()
+		// END parent lock
 
 		// Child entry is valid and can be included in the response object
 		if childRev != nil {
-			log.Debugw("verify-persisted-entry--adding-child", log.Fields{
+			log.Debugw("adding-revision-to-response", log.Fields{
 				"key":  childRev.GetHash(),
 				"name": childRev.GetName(),
 				"data": childRev.GetData(),
@@ -483,7 +512,8 @@
 
 // LoadFromPersistence retrieves data from kv store at the specified location and refreshes the memory
 // by adding missing entries, updating changed entries and ignoring unchanged ones
-func (pr *PersistedRevision) LoadFromPersistence(path string, txid string, blobs map[string]*kvstore.KVPair) []Revision {
+func (pr *PersistedRevision) LoadFromPersistence(
+	path string, txid string, blobs map[string]*kvstore.KVPair) []Revision {
 	pr.mutex.Lock()
 	defer pr.mutex.Unlock()
 
@@ -516,7 +546,7 @@
 		field := ChildrenFields(nodeType)[name]
 
 		if field != nil && field.IsContainer {
-			log.Debugw("load-from-persistence--start-blobs", log.Fields{
+			log.Debugw("parsing-data-blobs", log.Fields{
 				"path": path,
 				"name": name,
 				"size": len(blobs),
@@ -528,13 +558,19 @@
 				data := reflect.New(field.ClassType.Elem())
 
 				if err := proto.Unmarshal(output, data.Interface().(proto.Message)); err != nil {
-					log.Errorw("load-from-persistence--failed-to-unmarshal", log.Fields{
+					log.Errorw("failed-to-unmarshal", log.Fields{
 						"path":  path,
 						"txid":  txid,
 						"error": err,
 					})
 				} else if path == "" {
 					if field.Key != "" {
+						log.Debugw("no-path-with-container-key", log.Fields{
+							"path": path,
+							"txid": txid,
+							"data": data.Interface(),
+						})
+
 						// Retrieve the key identifier value from the data structure
 						// based on the field's key attribute
 						_, key := GetAttributeValue(data.Interface(), field.Key, 0)
@@ -543,9 +579,20 @@
 							txid); entry != nil {
 							response = append(response, entry)
 						}
+					} else {
+						log.Debugw("path-with-no-container-key", log.Fields{
+							"path": path,
+							"txid": txid,
+							"data": data.Interface(),
+						})
 					}
 
 				} else if field.Key != "" {
+					log.Debugw("path-with-container-key", log.Fields{
+						"path": path,
+						"txid": txid,
+						"data": data.Interface(),
+					})
 					// The request is for a specific entry/id
 					partition := strings.SplitN(path, "/", 2)
 					key := partition[0]
@@ -563,10 +610,9 @@
 				}
 			}
 
-			log.Debugw("load-from-persistence--end-blobs", log.Fields{"path": path, "name": name})
+			log.Debugw("no-more-data-blobs", log.Fields{"path": path, "name": name})
 		} else {
-			log.Debugw("load-from-persistence--cannot-process-field", log.Fields{
-
+			log.Debugw("cannot-process-field", log.Fields{
 				"type": pr.GetBranch().Node.Type,
 				"name": name,
 			})
diff --git a/db/model/proxy.go b/db/model/proxy.go
index 2933464..d4a86f4 100644
--- a/db/model/proxy.go
+++ b/db/model/proxy.go
@@ -150,6 +150,19 @@
 	PROXY_CREATE
 )
 
+var proxyOperationTypes = []string{
+	"PROXY_GET",
+	"PROXY_LIST",
+	"PROXY_ADD",
+	"PROXY_UPDATE",
+	"PROXY_REMOVE",
+	"PROXY_CREATE",
+}
+
+func (t ProxyOperation) String() string {
+	return proxyOperationTypes[t]
+}
+
 // parseForControlledPath verifies if a proxy path matches a pattern
 // for locations that need to be access controlled.
 func (p *Proxy) parseForControlledPath(path string) (pathLock string, controlled bool) {
diff --git a/db/model/revision.go b/db/model/revision.go
index 74ae3f7..4e606f1 100644
--- a/db/model/revision.go
+++ b/db/model/revision.go
@@ -17,6 +17,7 @@
 
 import (
 	"github.com/opencord/voltha-go/db/kvstore"
+	"time"
 )
 
 type Revision interface {
@@ -43,6 +44,8 @@
 	GetData() interface{}
 	GetNode() *node
 	LoadFromPersistence(path string, txid string, blobs map[string]*kvstore.KVPair) []Revision
+	SetLastUpdate(ts ...time.Time)
+	GetLastUpdate() time.Time
 	UpdateData(data interface{}, branch *Branch) Revision
 	UpdateChildren(name string, children []Revision, branch *Branch) Revision
 	UpdateAllChildren(children map[string][]Revision, branch *Branch) Revision