[VOL-2364] handle sub-sequent onuDiscoveryIndication
If ChildDeviceDetected times out then the device never receives the
"enable" call. With this patch we are allowing the device to send a new
discovery indication to retry the process (the OpenOlt agent keeps
sending discovery until an "enable" call is received for that device)
Change-Id: I6a2f5d5e9b0a001361bdca1feb14ca22cf092138
diff --git a/Makefile b/Makefile
index df0fcae..afc36aa 100644
--- a/Makefile
+++ b/Makefile
@@ -149,7 +149,7 @@
@[[ `git ls-files --exclude-standard --others go.mod go.sum vendor` == "" ]] || (echo "ERROR: Untracked files detected after running go mod tidy / go mod vendor" && echo "`git status`" && exit 1)
@echo "Vendor check OK."
-lint: lint-style lint-sanity lint-mod lint-dockerfile
+lint: local-lib-go lint-style lint-sanity lint-mod lint-dockerfile
test:
@mkdir -p ./tests/results
diff --git a/VERSION b/VERSION
index 2bf1c1c..4074260 100644
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-2.3.1
+2.3.2-dev
diff --git a/adaptercore/device_handler.go b/adaptercore/device_handler.go
index 10b0dbf..d17d997 100644
--- a/adaptercore/device_handler.go
+++ b/adaptercore/device_handler.go
@@ -31,7 +31,7 @@
"google.golang.org/grpc/codes"
- backoff "github.com/cenkalti/backoff/v3"
+ "github.com/cenkalti/backoff/v3"
"github.com/gogo/protobuf/proto"
"github.com/golang/protobuf/ptypes"
"github.com/opencord/voltha-lib-go/v3/pkg/adapters/adapterif"
@@ -859,69 +859,97 @@
}
func (dh *DeviceHandler) onuDiscIndication(ctx context.Context, onuDiscInd *oop.OnuDiscIndication, sn string) {
+
channelID := onuDiscInd.GetIntfId()
parentPortNo := IntfIDToPortNo(onuDiscInd.GetIntfId(), voltha.Port_PON_OLT)
- log.Debugw("new-discovery-indication", log.Fields{"sn": sn})
+ log.Infow("new-discovery-indication", log.Fields{"sn": sn})
if _, ok := dh.discOnus.Load(sn); ok {
-
- log.Debugw("onu-sn-is-already-being-processed", log.Fields{"sn": sn})
+ log.Warnw("onu-sn-is-already-being-processed", log.Fields{"sn": sn})
return
}
- dh.discOnus.Store(sn, true)
-
kwargs := make(map[string]interface{})
if sn != "" {
kwargs["serial_number"] = sn
} else {
- log.Errorw("invalid onu serial number", log.Fields{"sn": sn})
+ log.Errorw("invalid-onu-serial-number", log.Fields{"sn": sn})
return
}
- onuDevice, err := dh.coreProxy.GetChildDevice(ctx, dh.device.Id, kwargs)
+ dh.discOnus.Store(sn, true)
var onuID uint32
- if onuDevice == nil || err != nil {
- //This is the first time ONU discovered. Create an OnuID for it.
+
+ // check the ONU is already know to the OLT
+ // NOTE the second time the ONU is discovered this should return a device
+ onuDevice, err := dh.coreProxy.GetChildDevice(ctx, dh.device.Id, kwargs)
+
+ if err != nil {
+ log.Errorw("core-proxy-get-child-device-failed", log.Fields{"parentDevice": dh.device.Id, "err": err, "sn": sn})
+ if e, ok := status.FromError(err); ok {
+ log.Warnw("core-proxy-get-child-device-failed-with-code", log.Fields{"errCode": e.Code(), "sn": sn})
+ switch e.Code() {
+ case codes.Internal:
+ // this probably means NOT FOUND, so just create a new device
+ onuDevice = nil
+ case codes.DeadlineExceeded:
+ // if the call times out, cleanup and exit
+ dh.discOnus.Delete(sn)
+ return
+ }
+ }
+ }
+
+ if onuDevice == nil {
+ // NOTE this should happen a single time, and only if GetChildDevice returns NotFound
+ log.Infow("creating-new-onu", log.Fields{"sn": sn})
+ // we need to create a new ChildDevice
ponintfid := onuDiscInd.GetIntfId()
dh.lockDevice.Lock()
onuID, err = dh.resourceMgr.GetONUID(ctx, ponintfid)
dh.lockDevice.Unlock()
- if err != nil {
- log.Errorw("failed to fetch onuID from resource manager", log.Fields{"pon-intf-id": ponintfid, "err": err})
- return
- }
- if onuDevice, err = dh.coreProxy.ChildDeviceDetected(ctx, dh.device.Id, int(parentPortNo),
- "", int(channelID),
- string(onuDiscInd.SerialNumber.GetVendorId()), sn, int64(onuID)); onuDevice == nil {
- log.Errorw("Create onu error",
- log.Fields{"parent_id": dh.device.Id, "ponPort": onuDiscInd.GetIntfId(),
- "onuID": onuID, "sn": sn, "error": err})
- return
- }
- log.Debugw("onu-child-device-added", log.Fields{"onuDevice": onuDevice})
- } else {
- //ONU already discovered before. Use the same OnuID.
- onuID = onuDevice.ProxyAddress.OnuId
+ log.Infow("creating-new-onu-got-onu-id", log.Fields{"sn": sn, "onuId": onuID})
+
+ if err != nil {
+ // if we can't create an ID in resource manager,
+ // cleanup and exit
+ log.Warnw("resource-manage-get-onu-id-failed", log.Fields{"pon-intf-id": ponintfid, "err": err, "sn": sn})
+ dh.discOnus.Delete(sn)
+ return
+ }
+
+ if onuDevice, err = dh.coreProxy.ChildDeviceDetected(context.TODO(), dh.device.Id, int(parentPortNo),
+ "", int(channelID), string(onuDiscInd.SerialNumber.GetVendorId()), sn, int64(onuID)); err != nil {
+ log.Warnw("core-proxy-child-device-detected-failed", log.Fields{"pon-intf-id": ponintfid, "err": err, "sn": sn})
+ dh.discOnus.Delete(sn)
+ dh.resourceMgr.FreeonuID(ctx, ponintfid, []uint32{onuID}) // NOTE I'm not sure this method is actually cleaning up the right thing
+ return
+ }
+
+ log.Infow("onu-child-device-added", log.Fields{"onuDevice": onuDevice, "sn": sn})
}
+
+ // we can now use the existing ONU Id
+ onuID = onuDevice.ProxyAddress.OnuId
+
//Insert the ONU into cache to use in OnuIndication.
//TODO: Do we need to remove this from the cache on ONU change, or wait for overwritten on next discovery.
- log.Debugw("ONU discovery indication key create", log.Fields{"onuID": onuID,
- "intfId": onuDiscInd.GetIntfId()})
+ log.Debugw("onu-discovery-indication-key-create", log.Fields{"onuID": onuID,
+ "intfId": onuDiscInd.GetIntfId(), "sn": sn})
onuKey := dh.formOnuKey(onuDiscInd.GetIntfId(), onuID)
onuDev := NewOnuDevice(onuDevice.Id, onuDevice.Type, onuDevice.SerialNumber, onuID, onuDiscInd.GetIntfId(), onuDevice.ProxyAddress.DeviceId)
dh.onus.Store(onuKey, onuDev)
- log.Debugw("new-onu-device-discovered", log.Fields{"onu": onuDev})
+ log.Debugw("new-onu-device-discovered", log.Fields{"onu": onuDev, "sn": sn})
err = dh.coreProxy.DeviceStateUpdate(ctx, onuDevice.Id, common.ConnectStatus_REACHABLE, common.OperStatus_DISCOVERED)
if err != nil {
- log.Errorw("failed to update device state", log.Fields{"DeviceID": onuDevice.Id, "err": err})
+ log.Errorw("failed-to-update-device-state", log.Fields{"DeviceID": onuDevice.Id, "sn": sn, "err": err})
return
}
- log.Debugw("onu-discovered-reachable", log.Fields{"deviceId": onuDevice.Id})
+ log.Infow("onu-discovered-reachable", log.Fields{"deviceId": onuDevice.Id, "sn": sn})
//TODO: We put this sleep here to prevent the race between state update and onuIndication
//In onuIndication the operStatus of device is checked. If it is still not updated in KV store
//then the initialisation fails.
diff --git a/go.mod b/go.mod
index 23d18c7..871f6a2 100644
--- a/go.mod
+++ b/go.mod
@@ -7,7 +7,7 @@
github.com/cenkalti/backoff/v3 v3.1.1
github.com/gogo/protobuf v1.3.1
github.com/golang/protobuf v1.3.2
- github.com/opencord/voltha-lib-go/v3 v3.0.6
+ github.com/opencord/voltha-lib-go/v3 v3.0.8
github.com/opencord/voltha-protos/v3 v3.2.2
go.etcd.io/etcd v0.0.0-20190930204107-236ac2a90522
google.golang.org/grpc v1.25.1
diff --git a/go.sum b/go.sum
index 0ca681b..2eea07f 100644
--- a/go.sum
+++ b/go.sum
@@ -196,8 +196,8 @@
github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
github.com/onsi/gomega v1.4.2 h1:3mYCb7aPxS/RU7TI1y4rkEn1oKmPRjNJLNEXgw7MH2I=
github.com/onsi/gomega v1.4.2/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1CpauHY=
-github.com/opencord/voltha-lib-go/v3 v3.0.6 h1:J58Pquledy94urZ5Wp+COXkS9VZTIi6TbaHdVNVCT/Y=
-github.com/opencord/voltha-lib-go/v3 v3.0.6/go.mod h1:l/AgBlYqXEiHLHS6NR654Q7m5BfX5YVnrpykf7kOmGw=
+github.com/opencord/voltha-lib-go/v3 v3.0.8 h1:OkiDeiIlB94gEwWwJnmc9nMqaNMUrmYLAqxPj+a6qFg=
+github.com/opencord/voltha-lib-go/v3 v3.0.8/go.mod h1:l/AgBlYqXEiHLHS6NR654Q7m5BfX5YVnrpykf7kOmGw=
github.com/opencord/voltha-protos/v3 v3.2.1 h1:5CAxtWzHqDMNItBRklDkXN5YwE9b6vuCXr5UKTAuJBg=
github.com/opencord/voltha-protos/v3 v3.2.1/go.mod h1:RIGHt7b80BHpHh3ceodknh0DxUjUHCWSbYbZqRx7Og0=
github.com/opencord/voltha-protos/v3 v3.2.2 h1:Fdg2T6xtUjVZPBWV636/mMH6lYggalQ2e7uFPoOhZDc=
diff --git a/main.go b/main.go
index 94f4d19..97f6ca3 100644
--- a/main.go
+++ b/main.go
@@ -58,7 +58,7 @@
}
func init() {
- _, _ = log.AddPackage(log.JSON, log.DebugLevel, nil)
+ _, _ = log.AddPackage(log.CONSOLE, log.DebugLevel, nil)
}
func newAdapter(cf *config.AdapterFlags) *adapter {
@@ -452,8 +452,6 @@
log.With(log.Fields{"error": err}).Fatal("Cannot setup logging")
}
- log.SetPackageLogLevel("github.com/opencord/voltha-lib-go/v3/pkg/adapters/common", log.DebugLevel)
-
defer log.CleanUp()
// Print version / build information and exit
diff --git a/mocks/mockKVClient.go b/mocks/mockKVClient.go
index 90a9742..456d196 100644
--- a/mocks/mockKVClient.go
+++ b/mocks/mockKVClient.go
@@ -241,7 +241,8 @@
}
// IsConnectionUp mock function implementation for KVClient
-func (kvclient *MockKVClient) IsConnectionUp(ctx context.Context) bool { // timeout in second
+func (kvclient *MockKVClient) IsConnectionUp(ctx context.Context) bool {
+ // timeout in second
t, _ := ctx.Deadline()
if t.Second()-time.Now().Second() < 1 {
return false
diff --git a/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/core_proxy.go b/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/core_proxy.go
index c5e1c14..7cb933d 100644
--- a/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/core_proxy.go
+++ b/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/core_proxy.go
@@ -284,7 +284,7 @@
volthaDevice := &voltha.Device{}
if err := ptypes.UnmarshalAny(result, volthaDevice); err != nil {
logger.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
- return nil, status.Errorf(codes.InvalidArgument, "%s", err.Error())
+ return nil, status.Error(codes.InvalidArgument, err.Error())
}
return volthaDevice, nil
} else {
@@ -294,8 +294,8 @@
logger.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
}
logger.Debugw("ChildDeviceDetected-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)
+
+ return nil, status.Error(ICProxyErrorCodeToGrpcErrorCode(unpackResult.Code), unpackResult.Reason)
}
}
@@ -361,7 +361,7 @@
volthaDevice := &voltha.Device{}
if err := ptypes.UnmarshalAny(result, volthaDevice); err != nil {
logger.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
- return nil, status.Errorf(codes.InvalidArgument, "%s", err.Error())
+ return nil, status.Error(codes.InvalidArgument, err.Error())
}
return volthaDevice, nil
} else {
@@ -372,7 +372,7 @@
}
logger.Debugw("GetDevice-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)
+ return nil, status.Error(ICProxyErrorCodeToGrpcErrorCode(unpackResult.Code), unpackResult.Reason)
}
}
@@ -421,7 +421,7 @@
volthaDevice := &voltha.Device{}
if err := ptypes.UnmarshalAny(result, volthaDevice); err != nil {
logger.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
- return nil, status.Errorf(codes.InvalidArgument, "%s", err.Error())
+ return nil, status.Error(codes.InvalidArgument, err.Error())
}
return volthaDevice, nil
} else {
@@ -432,13 +432,7 @@
}
logger.Debugw("GetChildDevice-return", log.Fields{"deviceid": parentDeviceId, "success": success, "error": err})
- code := codes.Internal
-
- if unpackResult.Code == ic.ErrorCode_DEADLINE_EXCEEDED {
- code = codes.DeadlineExceeded
- }
-
- return nil, status.Errorf(code, "%s", unpackResult.Reason)
+ return nil, status.Error(ICProxyErrorCodeToGrpcErrorCode(unpackResult.Code), unpackResult.Reason)
}
}
@@ -463,7 +457,7 @@
volthaDevices := &voltha.Devices{}
if err := ptypes.UnmarshalAny(result, volthaDevices); err != nil {
logger.Warnw("cannot-unmarshal-response", log.Fields{"error": err})
- return nil, status.Errorf(codes.InvalidArgument, "%s", err.Error())
+ return nil, status.Error(codes.InvalidArgument, err.Error())
}
return volthaDevices, nil
} else {
@@ -474,13 +468,7 @@
}
logger.Debugw("GetChildDevices-return", log.Fields{"deviceid": parentDeviceId, "success": success, "error": err})
- code := codes.Internal
-
- if unpackResult.Code == ic.ErrorCode_DEADLINE_EXCEEDED {
- code = codes.DeadlineExceeded
- }
-
- return nil, status.Errorf(code, "%s", unpackResult.Reason)
+ return nil, status.Error(ICProxyErrorCodeToGrpcErrorCode(unpackResult.Code), unpackResult.Reason)
}
}
diff --git a/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/utils.go b/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/utils.go
index d3c562a..b782ebe 100644
--- a/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/utils.go
+++ b/vendor/github.com/opencord/voltha-lib-go/v3/pkg/adapters/common/utils.go
@@ -17,6 +17,9 @@
import (
"fmt"
+ "github.com/opencord/voltha-lib-go/v3/pkg/log"
+ ic "github.com/opencord/voltha-protos/v3/go/inter_container"
+ "google.golang.org/grpc/codes"
"math/rand"
"time"
)
@@ -71,3 +74,17 @@
}
return string(b)
}
+
+func ICProxyErrorCodeToGrpcErrorCode(icErr ic.ErrorCodeCodes) codes.Code {
+ switch icErr {
+ case ic.ErrorCode_INVALID_PARAMETERS:
+ return codes.InvalidArgument
+ case ic.ErrorCode_UNSUPPORTED_REQUEST:
+ return codes.Unavailable
+ case ic.ErrorCode_DEADLINE_EXCEEDED:
+ return codes.DeadlineExceeded
+ default:
+ log.Warnw("cannnot-map-ic-error-code-to-grpc-error-code", log.Fields{"err": icErr})
+ return codes.Internal
+ }
+}
diff --git a/vendor/modules.txt b/vendor/modules.txt
index c3dbb73..7f32653 100644
--- a/vendor/modules.txt
+++ b/vendor/modules.txt
@@ -63,7 +63,7 @@
github.com/mitchellh/go-homedir
# github.com/mitchellh/mapstructure v1.1.2
github.com/mitchellh/mapstructure
-# github.com/opencord/voltha-lib-go/v3 v3.0.6
+# github.com/opencord/voltha-lib-go/v3 v3.0.8
github.com/opencord/voltha-lib-go/v3/pkg/adapters
github.com/opencord/voltha-lib-go/v3/pkg/adapters/adapterif
github.com/opencord/voltha-lib-go/v3/pkg/adapters/common