[VOL-1550] Support for OLT hard reboot with ONU connected

Change-Id: I67642d847d2308f8abf8e9b90986eeecf65b2a41
diff --git a/Gopkg.lock b/Gopkg.lock
index e0f5712..f98da0b 100644
--- a/Gopkg.lock
+++ b/Gopkg.lock
@@ -216,7 +216,7 @@
 
 [[projects]]
   branch = "master"
-  digest = "1:1722471726bccf3da5fe247624549eb517aaeb73ac1cb40ad3a839d052c3e98f"
+  digest = "1:d43c4cb219b7c047c50c055d29d0289a7b045ba4da6bc97cd03a3174f9946b0f"
   name = "github.com/opencord/voltha-go"
   packages = [
     "adapters",
@@ -230,7 +230,7 @@
     "rw_core/utils",
   ]
   pruneopts = "UT"
-  revision = "1678e19a6243b0d8b049ec03df0c11e96e1d8b8f"
+  revision = "89176ab6a90c6657d6fc2600edf5832355230c39"
 
 [[projects]]
   branch = "master"
@@ -449,6 +449,8 @@
     "github.com/opencord/voltha-protos/go/openolt",
     "github.com/opencord/voltha-protos/go/voltha",
     "google.golang.org/grpc",
+    "google.golang.org/grpc/codes",
+    "google.golang.org/grpc/status",
   ]
   solver-name = "gps-cdcl"
   solver-version = 1
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/adaptercore/device_handler.go b/adaptercore/device_handler.go
index 759ff3f..f397d21 100644
--- a/adaptercore/device_handler.go
+++ b/adaptercore/device_handler.go
@@ -25,6 +25,8 @@
 	"sync"
 	"time"
 
+	"google.golang.org/grpc/codes"
+
 	"github.com/gogo/protobuf/proto"
 	"github.com/golang/protobuf/ptypes"
 	"github.com/mdlayher/ethernet"
@@ -37,6 +39,7 @@
 	oop "github.com/opencord/voltha-protos/go/openolt"
 	"github.com/opencord/voltha-protos/go/voltha"
 	"google.golang.org/grpc"
+	"google.golang.org/grpc/status"
 )
 
 //DeviceHandler will interact with the OLT device.
@@ -57,6 +60,7 @@
 	clientCon     *grpc.ClientConn
 	flowMgr       *OpenOltFlowMgr
 	resourceMgr   *rsrcMgr.OpenOltResourceMgr
+	discOnus      map[string]bool
 }
 
 //NewDeviceHandler creates a new device handler
@@ -71,6 +75,7 @@
 	dh.device = cloned
 	dh.openOLT = adapter
 	dh.exitChannel = make(chan int, 1)
+	dh.discOnus = make(map[string]bool)
 	dh.lockDevice = sync.RWMutex{}
 
 	//TODO initialize the support classes.
@@ -234,8 +239,7 @@
 			}*/
 
 			sn := dh.stringifySerialNumber(onuDiscInd.SerialNumber)
-			//FIXME: Duplicate child devices being create in go routine
-			dh.onuDiscIndication(onuDiscInd, onuId, sn)
+			go dh.onuDiscIndication(onuDiscInd, onuId, sn)
 		case *oop.Indication_OnuInd:
 			onuInd := indication.GetOnuInd()
 			log.Infow("Received Onu indication ", log.Fields{"OnuInd": onuInd})
@@ -300,6 +304,21 @@
 		log.Errorw("error-updating-device-state", log.Fields{"deviceId": device.Id, "error": err})
 		return err
 	}
+
+	//get the child device for the parent device
+	onuDevices, err := dh.coreProxy.GetChildDevices(nil, dh.device.Id)
+	if err != nil {
+		log.Errorw("failed to get child devices information", log.Fields{"deviceId": dh.device.Id, "error": err})
+		return err
+	}
+	for _, onuDevice := range onuDevices.Items {
+
+		// Update onu state as down in onu adapter
+		onuInd := oop.OnuIndication{}
+		onuInd.OperState = "down"
+		dh.AdapterProxy.SendInterAdapterMessage(nil, &onuInd, ic.InterAdapterMessageType_ONU_IND_REQUEST, "openolt", onuDevice.Type, onuDevice.Id, onuDevice.ProxyAddress.DeviceId, "")
+
+	}
 	log.Debugw("do-state-down-end", log.Fields{"deviceId": device.Id})
 	return nil
 }
@@ -503,7 +522,12 @@
 	var pir uint32 = 1000000
 	Onu := oop.Onu{IntfId: intfId, OnuId: uint32(onuId), SerialNumber: serialNum, Pir: pir}
 	if _, err := dh.Client.ActivateOnu(context.Background(), &Onu); err != nil {
-		log.Errorw("activate-onu-failed", log.Fields{"Onu": Onu})
+		st, _ := status.FromError(err)
+		if st.Code() == codes.AlreadyExists {
+			log.Debug("ONU activation is in progress", log.Fields{"SerialNumber": serialNumber})
+		} else {
+			log.Errorw("activate-onu-failed", log.Fields{"Onu": Onu, "err ": err})
+		}
 	} else {
 		log.Infow("activated-onu", log.Fields{"SerialNumber": serialNumber})
 	}
@@ -512,14 +536,39 @@
 func (dh *DeviceHandler) onuDiscIndication(onuDiscInd *oop.OnuDiscIndication, onuId uint32, sn string) error {
 	channelId := onuDiscInd.GetIntfId()
 	parentPortNo := IntfIdToPortNo(onuDiscInd.GetIntfId(), voltha.Port_PON_OLT)
-	if err := dh.coreProxy.ChildDeviceDetected(nil, dh.device.Id, int(parentPortNo), "brcm_openomci_onu", int(channelId), string(onuDiscInd.SerialNumber.GetVendorId()), sn, int64(onuId)); err != nil {
-		log.Errorw("Create onu error", log.Fields{"parent_id": dh.device.Id, "ponPort": onuDiscInd.GetIntfId(), "onuId": onuId, "sn": sn, "error": err})
-		return err
+	if _, ok := dh.discOnus[sn]; ok {
+		log.Debugw("onu-sn-is-already-being-processed", log.Fields{"sn": sn})
+		return nil
 	}
 
+	dh.lockDevice.Lock()
+	dh.discOnus[sn] = true
+	dh.lockDevice.Unlock()
+	// evict the onu serial number from local cache
+	defer func() {
+		delete(dh.discOnus, sn)
+	}()
+
 	kwargs := make(map[string]interface{})
+	if sn != "" {
+		kwargs["serial_number"] = sn
+	}
 	kwargs["onu_id"] = onuId
 	kwargs["parent_port_no"] = parentPortNo
+	onuDevice, err := dh.coreProxy.GetChildDevice(nil, dh.device.Id, kwargs)
+	if onuDevice == nil {
+		if err := dh.coreProxy.ChildDeviceDetected(nil, dh.device.Id, int(parentPortNo), "brcm_openomci_onu", int(channelId), string(onuDiscInd.SerialNumber.GetVendorId()), sn, int64(onuId)); err != nil {
+			log.Errorw("Create onu error", log.Fields{"parent_id": dh.device.Id, "ponPort": onuDiscInd.GetIntfId(), "onuId": onuId, "sn": sn, "error": err})
+			return err
+		}
+	}
+	onuDevice, err = dh.coreProxy.GetChildDevice(nil, dh.device.Id, kwargs)
+	if err != nil {
+		log.Errorw("failed to get ONU device information", log.Fields{"err": err})
+		return err
+	}
+	dh.coreProxy.DeviceStateUpdate(nil, onuDevice.Id, common.ConnectStatus_REACHABLE, common.OperStatus_DISCOVERED)
+	log.Debugw("onu-discovered-reachable", log.Fields{"deviceId": onuDevice.Id})
 
 	for i := 0; i < 10; i++ {
 		if onuDevice, _ := dh.coreProxy.GetChildDevice(nil, dh.device.Id, kwargs); onuDevice != nil {
diff --git a/vendor/github.com/opencord/voltha-go/adapters/common/core_proxy.go b/vendor/github.com/opencord/voltha-go/adapters/common/core_proxy.go
index e2d79fc..c4b5bf5 100644
--- a/vendor/github.com/opencord/voltha-go/adapters/common/core_proxy.go
+++ b/vendor/github.com/opencord/voltha-go/adapters/common/core_proxy.go
@@ -418,6 +418,42 @@
 	}
 }
 
+func (ap *CoreProxy) GetChildDevices(ctx context.Context, parentDeviceId string) (*voltha.Devices, error) {
+	log.Debugw("GetChildDevices", log.Fields{"parentDeviceId": parentDeviceId})
+	rpc := "GetChildDevices"
+
+	toTopic := ap.getCoreTopic(parentDeviceId)
+	replyToTopic := ap.getAdapterTopic()
+
+	args := make([]*kafka.KVArg, 1)
+	id := &voltha.ID{Id: parentDeviceId}
+	args[0] = &kafka.KVArg{
+		Key:   "device_id",
+		Value: id,
+	}
+
+	success, result := ap.kafkaICProxy.InvokeRPC(nil, rpc, &toTopic, &replyToTopic, true, parentDeviceId, args...)
+	log.Debugw("GetChildDevices-response", log.Fields{"pDeviceId": parentDeviceId, "success": success})
+
+	if success {
+		volthaDevices := &voltha.Devices{}
+		if err := ptypes.UnmarshalAny(result, volthaDevices); err != nil {
+			log.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
+			return nil, status.Errorf(codes.InvalidArgument, "%s", err.Error())
+		}
+		return volthaDevices, nil
+	} else {
+		unpackResult := &ic.Error{}
+		var err error
+		if err = ptypes.UnmarshalAny(result, unpackResult); err != nil {
+			log.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
+		}
+		log.Debugw("GetChildDevices-return", log.Fields{"deviceid": parentDeviceId, "success": success, "error": err})
+		// TODO:  Need to get the real error code
+		return nil, status.Errorf(codes.Internal, "%s", unpackResult.Reason)
+	}
+}
+
 func (ap *CoreProxy) SendPacketIn(ctx context.Context, deviceId string, port uint32, pktPayload []byte) error {
 	log.Debugw("SendPacketIn", log.Fields{"deviceId": deviceId, "port": port, "pktPayload": pktPayload})
 	rpc := "PacketIn"
diff --git a/vendor/github.com/opencord/voltha-go/db/model/node.go b/vendor/github.com/opencord/voltha-go/db/model/node.go
index 1621b6f..15ea04e 100644
--- a/vendor/github.com/opencord/voltha-go/db/model/node.go
+++ b/vendor/github.com/opencord/voltha-go/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, "/") {
@@ -713,6 +745,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 +868,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 +1002,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 +1024,6 @@
 }
 
 func (n *node) makeEventBus() *EventBus {
-	n.Lock()
-	defer n.Unlock()
 	if n.EventBus == nil {
 		n.EventBus = NewEventBus()
 	}
@@ -1002,21 +1031,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 +1048,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/vendor/github.com/opencord/voltha-go/db/model/non_persisted_revision.go b/vendor/github.com/opencord/voltha-go/db/model/non_persisted_revision.go
index d7b0b58..6075b3f 100644
--- a/vendor/github.com/opencord/voltha-go/db/model/non_persisted_revision.go
+++ b/vendor/github.com/opencord/voltha-go/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/vendor/github.com/opencord/voltha-go/db/model/persisted_revision.go b/vendor/github.com/opencord/voltha-go/db/model/persisted_revision.go
index ea99cf7..226fc3c 100644
--- a/vendor/github.com/opencord/voltha-go/db/model/persisted_revision.go
+++ b/vendor/github.com/opencord/voltha-go/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/vendor/github.com/opencord/voltha-go/db/model/proxy.go b/vendor/github.com/opencord/voltha-go/db/model/proxy.go
index 2933464..d4a86f4 100644
--- a/vendor/github.com/opencord/voltha-go/db/model/proxy.go
+++ b/vendor/github.com/opencord/voltha-go/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/vendor/github.com/opencord/voltha-go/db/model/revision.go b/vendor/github.com/opencord/voltha-go/db/model/revision.go
index 74ae3f7..4e606f1 100644
--- a/vendor/github.com/opencord/voltha-go/db/model/revision.go
+++ b/vendor/github.com/opencord/voltha-go/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