Logging improvement for VGC-APPLICATION
Change-Id: I35c10b43917d5f962484f05c3fb9d9aad67e63f5
diff --git a/internal/pkg/application/application.go b/internal/pkg/application/application.go
index 3e2f299..0117cd7 100644
--- a/internal/pkg/application/application.go
+++ b/internal/pkg/application/application.go
@@ -253,30 +253,33 @@
// AssociateVpvsToDevice - updates the associated VPVs for given device & svlan
func (va *VoltApplication) AssociateVpvsToDevice(device string, vpv *VoltPortVnet) {
+ logger.Debugw(ctx, "AssociateVpvsToDevice", log.Fields{"Device": device})
if d := va.GetDevice(device); d != nil {
vpvMap := d.GetAssociatedVpvs(vpv.SVlan)
vpvMap.Set(vpv, true)
d.VpvsBySvlan.Set(vpv.SVlan, vpvMap)
- logger.Infow(ctx, "VPVMap: SET", log.Fields{"Map": vpvMap.Length()})
+ logger.Debugw(ctx, "VPVMap: SET", log.Fields{"Map": vpvMap.Length()})
return
}
- logger.Errorw(ctx, "Set VPVMap failed: Device Not Found", log.Fields{"Svlan": vpv.SVlan, "Device": device})
+ logger.Warnw(ctx, "Set VPVMap failed: Device Not Found", log.Fields{"Svlan": vpv.SVlan, "Device": device})
}
// DisassociateVpvsFromDevice - disassociated VPVs from given device & svlan
func (va *VoltApplication) DisassociateVpvsFromDevice(device string, vpv *VoltPortVnet) {
+ logger.Debugw(ctx, "DisassociateVpvsToDevice", log.Fields{"Device": device})
if d := va.GetDevice(device); d != nil {
vpvMap := d.GetAssociatedVpvs(vpv.SVlan)
vpvMap.Remove(vpv)
d.VpvsBySvlan.Set(vpv.SVlan, vpvMap)
- logger.Infow(ctx, "VPVMap: Remove", log.Fields{"Map": vpvMap.Length()})
+ logger.Debugw(ctx, "VPVMap: Remove", log.Fields{"Map": vpvMap.Length()})
return
}
- logger.Errorw(ctx, "Remove VPVMap failed: Device Not Found", log.Fields{"Svlan": vpv.SVlan, "Device": device})
+ logger.Warnw(ctx, "Remove VPVMap failed: Device Not Found", log.Fields{"Svlan": vpv.SVlan, "Device": device})
}
// GetAssociatedVpvs - returns the associated VPVs for the given Svlan
func (d *VoltDevice) GetAssociatedVpvs(svlan of.VlanType) *util.ConcurrentMap {
+ logger.Debugw(ctx, "Received Get Associated Vpvs", log.Fields{"svlan": svlan})
var vpvMap *util.ConcurrentMap
var mapIntf interface{}
var ok bool
@@ -286,12 +289,13 @@
} else {
vpvMap = util.NewConcurrentMap()
}
- logger.Infow(ctx, "VPVMap: GET", log.Fields{"Map": vpvMap.Length()})
+ logger.Debugw(ctx, "VPVMap: GET", log.Fields{"Map": vpvMap.Length()})
return vpvMap
}
// AddPort add port to the device.
func (d *VoltDevice) AddPort(port string, id uint32) *VoltPort {
+ logger.Debugw(ctx, "Add Port", log.Fields{"Port": port, "ID": id})
addPonPortFromUniPort := func(vPort *VoltPort) {
if vPort.Type == VoltPortTypeAccess {
ponPortID := GetPonPortIDFromUNIPort(vPort.ID)
@@ -326,6 +330,7 @@
// GetPort to get port information from the device.
func (d *VoltDevice) GetPort(port string) *VoltPort {
+ logger.Debugw(ctx, "Get Port", log.Fields{"Port": port})
if pIntf, ok := d.Ports.Load(port); ok {
return pIntf.(*VoltPort)
}
@@ -334,6 +339,7 @@
// GetPortByPortID to get port information from the device.
func (d *VoltDevice) GetPortNameFromPortID(portID uint32) string {
+ logger.Debugw(ctx, "Get Port Name from the device", log.Fields{"PortID": portID})
portName := ""
d.Ports.Range(func(key, value interface{}) bool {
vp := value.(*VoltPort)
@@ -347,6 +353,7 @@
// DelPort to delete port from the device
func (d *VoltDevice) DelPort(port string) {
+ logger.Debugw(ctx, "Delete Port from the device", log.Fields{"Port": port})
if _, ok := d.Ports.Load(port); ok {
d.Ports.Delete(port)
} else {
@@ -361,7 +368,7 @@
port := key.(string)
vp := value.(*VoltPort)
- logger.Infow(ctx, "NNI Discovered. Sending Port UP Ind for UNI", log.Fields{"Port": port})
+ logger.Debugw(ctx, "NNI Discovered. Sending Port UP Ind for UNI", log.Fields{"Port": port})
//Ignore if UNI port is not UP
if vp.State != PortStateUp {
return true
@@ -473,6 +480,7 @@
// RestoreNbDeviceFromDb restores the NB Device in case of VGC pod restart.
func (va *VoltApplication) RestoreNbDeviceFromDb(cntx context.Context, deviceID string) *NbDevice {
+ logger.Debugw(ctx, "Received Restore Nb Device From Db", log.Fields{"deviceID": deviceID})
nbDevice := NewNbDevice()
nbDevice.SouthBoundID = deviceID
@@ -487,7 +495,7 @@
var port PonPortCfg
err := json.Unmarshal(b, &port)
if err != nil {
- logger.Warn(ctx, "Unmarshal of PonPortCfg failed")
+ logger.Warnw(ctx, "Unmarshal of PonPortCfg failed", log.Fields{"deviceID": deviceID, "port": port})
continue
}
logger.Debugw(ctx, "Port recovered", log.Fields{"port": port})
@@ -495,6 +503,7 @@
nbDevice.PonPorts.Store(uint32(ponPortID), &port)
}
va.NbDevice.Store(deviceID, nbDevice)
+ logger.Debugw(ctx, "Recovered NbDevice From Db", log.Fields{"deviceID": deviceID, "nbDevice": nbDevice})
return nbDevice
}
@@ -508,7 +517,7 @@
func (nbd *NbDevice) WriteToDb(cntx context.Context, portID uint32, ponPort *PonPortCfg) {
b, err := json.Marshal(ponPort)
if err != nil {
- logger.Errorw(ctx, "PonPortConfig-marshal-failed", log.Fields{"err": err})
+ logger.Errorw(ctx, "PonPortConfig-marshal-failed", log.Fields{"err": err, "ponPort": ponPort})
return
}
db.PutNbDevicePort(cntx, nbd.SouthBoundID, portID, string(b))
@@ -517,6 +526,7 @@
// AddPortToNbDevice Adds pon port to NB Device and DB
func (nbd *NbDevice) AddPortToNbDevice(cntx context.Context, portID, allowedChannels uint32,
enableMulticastKPI bool, portAlarmProfileID string) *PonPortCfg {
+ logger.Debugw(ctx, "AddPortToNbDevice", log.Fields{"PortID": portID, "EnableMulticastKPI": enableMulticastKPI, "PortAlarmProfileID": portAlarmProfileID})
ponPort := &PonPortCfg{
PortID: portID,
MaxActiveChannels: allowedChannels,
@@ -541,7 +551,7 @@
devConfig := DeviceConfig{}
err := json.Unmarshal(b, &devConfig)
if err != nil {
- logger.Warn(ctx, "Unmarshal of device configuration failed")
+ logger.Warnw(ctx, "Unmarshal of device configuration failed", log.Fields{"Device Config": devConfig})
continue
}
logger.Debugw(ctx, "Retrieved device config", log.Fields{"Device Config": devConfig})
@@ -555,18 +565,17 @@
func (dc *DeviceConfig) WriteDeviceConfigToDb(cntx context.Context, serialNum string, deviceConfig *DeviceConfig) error {
b, err := json.Marshal(deviceConfig)
if err != nil {
- logger.Errorw(ctx, "deviceConfig-marshal-failed", log.Fields{"err": err})
- return err
+ return fmt.Errorf("deviceConfig-marshal-failed - %w ", err)
}
dberr := db.PutDeviceConfig(cntx, serialNum, string(b))
if dberr != nil {
- logger.Errorw(ctx, "update device config failed", log.Fields{"err": err})
- return dberr
+ return fmt.Errorf("update device config failed - %w ", err)
}
return nil
}
func (va *VoltApplication) AddDeviceConfig(cntx context.Context, serialNum, hardwareIdentifier, nasID, ipAddress, uplinkPort string, nniDhcpTrapID int) error {
+ logger.Debugw(ctx, "Received Add device config", log.Fields{"SerialNumber": serialNum, "HardwareIdentifier": hardwareIdentifier, "NasID": nasID, "IPAddress": ipAddress, "UplinkPort": uplinkPort, "NniDhcpTrapID": nniDhcpTrapID})
var dc *DeviceConfig
deviceConfig := &DeviceConfig{
@@ -580,8 +589,7 @@
va.DevicesConfig.Store(serialNum, deviceConfig)
err := dc.WriteDeviceConfigToDb(cntx, serialNum, deviceConfig)
if err != nil {
- logger.Errorw(ctx, "DB update for device config failed", log.Fields{"err": err})
- return err
+ return fmt.Errorf("DB update for device config failed - %w ", err)
}
// If device is already discovered update the VoltDevice structure
@@ -590,7 +598,7 @@
device.NniDhcpTrapVid = of.VlanType(nniDhcpTrapID)
va.DevicesDisc.Store(id, device)
}
-
+ logger.Debugw(ctx, "Added device config", log.Fields{"Device Config": deviceConfig})
return nil
}
@@ -604,6 +612,7 @@
// UpdatePortToNbDevice Adds pon port to NB Device and DB
func (nbd *NbDevice) UpdatePortToNbDevice(cntx context.Context, portID, allowedChannels uint32, enableMulticastKPI bool, portAlarmProfileID string) *PonPortCfg {
+ logger.Debugw(ctx, "Received Update Port To NbDevice", log.Fields{"portID": portID, "AllowedChannels": allowedChannels, "EnableMulticastKPI": enableMulticastKPI, "PortAlarmProfileID": portAlarmProfileID})
p, exists := nbd.PonPorts.Load(portID)
if !exists {
logger.Errorw(ctx, "PON port not exists in nb-device", log.Fields{"portID": portID})
@@ -623,6 +632,7 @@
// DeletePortFromNbDevice Deletes pon port from NB Device and DB
func (nbd *NbDevice) DeletePortFromNbDevice(cntx context.Context, portID uint32) {
+ logger.Debugw(ctx, "Received Delete Port from NbDevice", log.Fields{"portID": portID})
if _, ok := nbd.PonPorts.Load(portID); ok {
nbd.PonPorts.Delete(portID)
}
@@ -670,9 +680,9 @@
case of.CommandAdd:
return d.FlowAddEventMap, nil
default:
- logger.Error(ctx, "Unknown Flow Mod received")
+ logger.Warnw(ctx, "Unknown Flow Mod received", log.Fields{"flowModtype": flowModType})
}
- return util.NewConcurrentMap(), errors.New("Unknown Flow Mod")
+ return util.NewConcurrentMap(), errors.New("unknown flow mod")
}
// RegisterFlowAddEvent to register a flow event.
@@ -696,7 +706,7 @@
logger.Debugw(ctx, "UnRegistered Flow Add Event", log.Fields{"Cookie": cookie, "Type": flowModType})
flowEventMap, err := d.GetFlowEventRegister(flowModType)
if err != nil {
- logger.Debugw(ctx, "Flow event map does not exists", log.Fields{"flowMod": flowModType, "Error": err})
+ logger.Warnw(ctx, "Flow event map does not exists", log.Fields{"flowMod": flowModType, "Error": err})
return
}
flowEventMap.MapLock.Lock()
@@ -706,6 +716,7 @@
// AddIgmpGroups to add Igmp groups.
func (va *VoltApplication) AddIgmpGroups(numOfGroups uint32) {
+ logger.Debugw(ctx, "AddIgmpGroups", log.Fields{"NumOfGroups": numOfGroups})
//TODO: Temp change to resolve group id issue in pOLT
//for i := 1; uint32(i) <= numOfGroups; i++ {
for i := 2; uint32(i) <= (numOfGroups + 1); i++ {
@@ -717,6 +728,7 @@
// GetAvailIgmpGroupID to get id of available igmp group.
func (va *VoltApplication) GetAvailIgmpGroupID() *IgmpGroup {
+ logger.Info(ctx, "GetAvailIgmpGroupID")
var ig *IgmpGroup
if len(va.IgmpGroupIds) > 0 {
ig, va.IgmpGroupIds = va.IgmpGroupIds[0], va.IgmpGroupIds[1:]
@@ -727,22 +739,25 @@
// GetIgmpGroupID to get id of igmp group.
func (va *VoltApplication) GetIgmpGroupID(gid uint32) (*IgmpGroup, error) {
+ logger.Info(ctx, "GetIgmpGroupID")
for id, ig := range va.IgmpGroupIds {
if ig.GroupID == gid {
va.IgmpGroupIds = append(va.IgmpGroupIds[0:id], va.IgmpGroupIds[id+1:]...)
return ig, nil
}
}
- return nil, errors.New("Group Id Missing")
+ return nil, errors.New("group id missing")
}
// PutIgmpGroupID to add id of igmp group.
func (va *VoltApplication) PutIgmpGroupID(ig *IgmpGroup) {
+ logger.Debugw(ctx, "GetIgmpGroupID", log.Fields{"GroupID": ig.GroupID})
va.IgmpGroupIds = append([]*IgmpGroup{ig}, va.IgmpGroupIds[0:]...)
}
// RestoreUpgradeStatus - gets upgrade/migration status from DB and updates local flags
func (va *VoltApplication) RestoreUpgradeStatus(cntx context.Context) {
+ logger.Info(ctx, "Received Restore Upgrade Status")
Migrate := new(DataMigration)
if err := GetMigrationInfo(cntx, Migrate); err == nil {
if Migrate.Status == MigrationInProgress {
@@ -823,7 +838,7 @@
// protection mechanism (LAG, ERPS, etc.). The aggregate of the such protection
// is represented by a single NNI port
func (va *VoltApplication) AddDevice(cntx context.Context, device string, slno, southBoundID string) {
- logger.Warnw(ctx, "Received Device Ind: Add", log.Fields{"Device": device, "SrNo": slno, "southBoundID": southBoundID})
+ logger.Debugw(ctx, "Received Device Ind: Add", log.Fields{"Device": device, "SrNo": slno, "southBoundID": southBoundID})
if _, ok := va.DevicesDisc.Load(device); ok {
logger.Warnw(ctx, "Device Exists", log.Fields{"Device": device})
}
@@ -857,7 +872,7 @@
// DelDevice to delete a device.
func (va *VoltApplication) DelDevice(cntx context.Context, device string) {
- logger.Warnw(ctx, "Received Device Ind: Delete", log.Fields{"Device": device})
+ logger.Debugw(ctx, "Received Device Ind: Delete", log.Fields{"Device": device})
if vdIntf, ok := va.DevicesDisc.Load(device); ok {
vd := vdIntf.(*VoltDevice)
va.DevicesDisc.Delete(device)
@@ -875,6 +890,7 @@
// GetDeviceBySerialNo to get a device by serial number.
// TODO - Transform this into a MAP instead
func (va *VoltApplication) GetDeviceBySerialNo(slno string) (*VoltDevice, string) {
+ logger.Debugw(ctx, "Received Device Ind: Get", log.Fields{"Serial Num": slno})
var device *VoltDevice
var deviceID string
getserial := func(key interface{}, value interface{}) bool {
@@ -890,7 +906,7 @@
// a request coming from VOLTHA. The device and identity of the port is provided
// in this request. Add them to the application for further use
func (va *VoltApplication) PortAddInd(cntx context.Context, device string, id uint32, portName string) {
- logger.Infow(ctx, "Received Port Ind: Add", log.Fields{"Device": device, "Port": portName})
+ logger.Debugw(ctx, "Received Port Ind: Add", log.Fields{"Device": device, "ID": id, "Port": portName})
va.portLock.Lock()
if d := va.GetDevice(device); d != nil {
p := d.AddPort(portName, id)
@@ -902,14 +918,14 @@
}
} else {
va.portLock.Unlock()
- logger.Warnw(ctx, "Device Not Found - Dropping Port Ind: Add", log.Fields{"Device": device, "Port": portName})
+ logger.Warnw(ctx, "Device Not Found - Dropping Port Ind: Add", log.Fields{"Device": device, "ID": id, "Port": portName})
}
}
// PortDelInd : Only the NNI ports are recorded in the device for now. When port delete
// arrives, only the NNI ports need adjustments.
func (va *VoltApplication) PortDelInd(cntx context.Context, device string, port string) {
- logger.Infow(ctx, "Received Port Ind: Delete", log.Fields{"Device": device, "Port": port})
+ logger.Debugw(ctx, "Received Port Ind: Delete", log.Fields{"Device": device, "Port": port})
if d := va.GetDevice(device); d != nil {
p := d.GetPort(port)
if p != nil && p.State == PortStateUp {
@@ -942,20 +958,21 @@
// PortUpdateInd Updates port Id incase of ONU movement
func (va *VoltApplication) PortUpdateInd(device string, portName string, id uint32) {
- logger.Infow(ctx, "Received Port Ind: Update", log.Fields{"Device": device, "Port": portName})
+ logger.Debugw(ctx, "Received Port Ind: Update", log.Fields{"Device": device, "Port": portName, "ID": id})
va.portLock.Lock()
defer va.portLock.Unlock()
if d := va.GetDevice(device); d != nil {
vp := d.GetPort(portName)
vp.ID = id
} else {
- logger.Warnw(ctx, "Device Not Found", log.Fields{"Device": device, "Port": portName})
+ logger.Warnw(ctx, "Device Not Found", log.Fields{"Device": device, "Port": portName, "ID": id})
}
}
// AddNbPonPort Add pon port to nbDevice
func (va *VoltApplication) AddNbPonPort(cntx context.Context, oltSbID string, portID, maxAllowedChannels uint32,
enableMulticastKPI bool, portAlarmProfileID string) error {
+ logger.Debugw(ctx, "Received NbPonPort Ind: Add", log.Fields{"oltSbID": oltSbID, "portID": portID, "maxAllowedChannels": maxAllowedChannels, "enableMulticastKPI": enableMulticastKPI, "portAlarmProfileID": portAlarmProfileID})
var nbd *NbDevice
nbDevice, ok := va.NbDevice.Load(oltSbID)
@@ -966,7 +983,7 @@
nbd = nbDevice.(*NbDevice)
}
port := nbd.AddPortToNbDevice(cntx, portID, maxAllowedChannels, enableMulticastKPI, portAlarmProfileID)
-
+ logger.Debugw(ctx, "Added Port To NbDevice", log.Fields{"port": port})
// Add this port to voltDevice
addPort := func(key, value interface{}) bool {
voltDevice := value.(*VoltDevice)
@@ -986,18 +1003,19 @@
// UpdateNbPonPort update pon port to nbDevice
func (va *VoltApplication) UpdateNbPonPort(cntx context.Context, oltSbID string, portID, maxAllowedChannels uint32, enableMulticastKPI bool, portAlarmProfileID string) error {
+ logger.Debugw(ctx, "Received NbPonPort Ind: Update", log.Fields{"oltSbID": oltSbID, "portID": portID, "maxAllowedChannels": maxAllowedChannels, "enableMulticastKPI": enableMulticastKPI, "portAlarmProfileID": portAlarmProfileID})
var nbd *NbDevice
nbDevice, ok := va.NbDevice.Load(oltSbID)
if !ok {
logger.Errorw(ctx, "Device-doesn't-exists", log.Fields{"deviceID": oltSbID})
- return fmt.Errorf("Device-doesn't-exists-%v", oltSbID)
+ return fmt.Errorf("device-doesn't-exists - %s", oltSbID)
}
nbd = nbDevice.(*NbDevice)
port := nbd.UpdatePortToNbDevice(cntx, portID, maxAllowedChannels, enableMulticastKPI, portAlarmProfileID)
if port == nil {
- return fmt.Errorf("Port-doesn't-exists-%v", portID)
+ return fmt.Errorf("port-doesn't-exists-%d", portID)
}
va.NbDevice.Store(oltSbID, nbd)
@@ -1026,6 +1044,7 @@
// DeleteNbPonPort Delete pon port to nbDevice
func (va *VoltApplication) DeleteNbPonPort(cntx context.Context, oltSbID string, portID uint32) error {
+ logger.Debugw(ctx, "Received NbPonPort Ind: Delete", log.Fields{"oltSbID": oltSbID, "portID": portID})
nbDevice, ok := va.NbDevice.Load(oltSbID)
if ok {
nbDevice.(*NbDevice).DeletePortFromNbDevice(cntx, portID)
@@ -1056,18 +1075,19 @@
// NNI port ID to identify possibly a single physical port or a logical
// port which is a result of protection methods applied.
func (va *VoltApplication) GetNniPort(device string) (string, error) {
+ logger.Debugw(ctx, "NNI Get Ind", log.Fields{"device": device})
va.portLock.Lock()
defer va.portLock.Unlock()
d, ok := va.DevicesDisc.Load(device)
if !ok {
- return "", errors.New("Device Doesn't Exist")
+ return "", errors.New("device doesn't exist")
}
return d.(*VoltDevice).NniPort, nil
}
// NniDownInd process for Nni down indication.
func (va *VoltApplication) NniDownInd(cntx context.Context, deviceID string, devSrNo string) {
- logger.Debugw(ctx, "NNI Down Ind", log.Fields{"device": devSrNo})
+ logger.Debugw(ctx, "NNI Down Ind", log.Fields{"DeviceID": deviceID, "Device SrNo": devSrNo})
handleIgmpDsFlows := func(key interface{}, value interface{}) bool {
mvProfile := value.(*MvlanProfile)
@@ -1082,27 +1102,27 @@
// DeviceUpInd changes device state to up.
func (va *VoltApplication) DeviceUpInd(device string) {
- logger.Warnw(ctx, "Received Device Ind: UP", log.Fields{"Device": device})
+ logger.Infow(ctx, "Received Device Ind: UP", log.Fields{"Device": device})
if d := va.GetDevice(device); d != nil {
d.State = controller.DeviceStateUP
} else {
- logger.Errorw(ctx, "Ignoring Device indication: UP. Device Missing", log.Fields{"Device": device})
+ logger.Warnw(ctx, "Ignoring Device indication: UP. Device Missing", log.Fields{"Device": device})
}
}
// DeviceDownInd changes device state to down.
func (va *VoltApplication) DeviceDownInd(device string) {
- logger.Warnw(ctx, "Received Device Ind: DOWN", log.Fields{"Device": device})
+ logger.Infow(ctx, "Received Device Ind: DOWN", log.Fields{"Device": device})
if d := va.GetDevice(device); d != nil {
d.State = controller.DeviceStateDOWN
} else {
- logger.Errorw(ctx, "Ignoring Device indication: DOWN. Device Missing", log.Fields{"Device": device})
+ logger.Warnw(ctx, "Ignoring Device indication: DOWN. Device Missing", log.Fields{"Device": device})
}
}
// DeviceRebootInd process for handling flow clear flag for device reboot
func (va *VoltApplication) DeviceRebootInd(cntx context.Context, device string, serialNum string, southBoundID string) {
- logger.Warnw(ctx, "Received Device Ind: Reboot", log.Fields{"Device": device, "SerialNumber": serialNum})
+ logger.Infow(ctx, "Received Device Ind: Reboot", log.Fields{"Device": device, "SerialNumber": serialNum, "SouthBoundID": southBoundID})
if d := va.GetDevice(device); d != nil {
if d.State == controller.DeviceStateREBOOTED {
@@ -1116,11 +1136,11 @@
// DeviceDisableInd handles device deactivation process
func (va *VoltApplication) DeviceDisableInd(cntx context.Context, device string) {
- logger.Warnw(ctx, "Received Device Ind: Disable", log.Fields{"Device": device})
+ logger.Infow(ctx, "Received Device Ind: Disable", log.Fields{"Device": device})
d := va.GetDevice(device)
if d == nil {
- logger.Errorw(ctx, "Ignoring Device indication: DISABLED. Device Missing", log.Fields{"Device": device})
+ logger.Warnw(ctx, "Ignoring Device indication: DISABLED. Device Missing", log.Fields{"Device": device})
return
}
@@ -1164,6 +1184,7 @@
// only to access ports, and the services which are also attached only
// to access ports
func (va *VoltApplication) GetDeviceFromPort(port string) (*VoltDevice, error) {
+ logger.Debugw(ctx, "Received Get Device From Port", log.Fields{"Port": port})
va.portLock.Lock()
defer va.portLock.Unlock()
var err error
@@ -1182,6 +1203,7 @@
// GetPortID : This too applies only to access ports. The ports can be indexed
// purely by their names without the device forming part of the key
func (va *VoltApplication) GetPortID(port string) (uint32, error) {
+ logger.Debugw(ctx, "Received Get Port ID", log.Fields{"Port": port})
va.portLock.Lock()
defer va.portLock.Unlock()
p, ok := va.PortsDisc.Load(port)
@@ -1194,6 +1216,7 @@
// GetPortName : This too applies only to access ports. The ports can be indexed
// purely by their names without the device forming part of the key
func (va *VoltApplication) GetPortName(port uint32) (string, error) {
+ logger.Debugw(ctx, "Received Get Port Name", log.Fields{"Port": port})
va.portLock.Lock()
defer va.portLock.Unlock()
var portName string
@@ -1210,6 +1233,7 @@
// GetPonFromUniPort to get Pon info from UniPort
func (va *VoltApplication) GetPonFromUniPort(port string) (string, error) {
+ logger.Debugw(ctx, "Received Get Pon From UniPort", log.Fields{"Port": port})
uniPortID, err := va.GetPortID(port)
if err == nil {
ponPortID := (uniPortID & 0x0FF00000) >> 20 //pon(8) + onu(8) + uni(12)
@@ -1221,17 +1245,19 @@
// GetPortState : This too applies only to access ports. The ports can be indexed
// purely by their names without the device forming part of the key
func (va *VoltApplication) GetPortState(port string) (PortState, error) {
+ logger.Debugw(ctx, "Received Get Port State", log.Fields{"Port": port})
va.portLock.Lock()
defer va.portLock.Unlock()
p, ok := va.PortsDisc.Load(port)
if !ok {
- return 0, errors.New("Port not configured")
+ return 0, errors.New("port not configured")
}
return p.(*VoltPort).State, nil
}
// GetIcmpv6Receivers to get Icmp v6 receivers
func (va *VoltApplication) GetIcmpv6Receivers(device string) []uint32 {
+ logger.Debugw(ctx, "Get Icmpv6 Receivers", log.Fields{"Device": device})
var receiverList []uint32
receivers, _ := va.Icmpv6Receivers.Load(device)
if receivers != nil {
@@ -1242,6 +1268,7 @@
// AddIcmpv6Receivers to add Icmp v6 receivers
func (va *VoltApplication) AddIcmpv6Receivers(device string, portID uint32) []uint32 {
+ logger.Debugw(ctx, "Received Add Icmpv6 Receivers", log.Fields{"device": device, "portID": portID})
var receiverList []uint32
receivers, _ := va.Icmpv6Receivers.Load(device)
if receivers != nil {
@@ -1255,6 +1282,7 @@
// DelIcmpv6Receivers to delete Icmp v6 receievers
func (va *VoltApplication) DelIcmpv6Receivers(device string, portID uint32) []uint32 {
+ logger.Debugw(ctx, "Received Add Icmpv6 Receivers", log.Fields{"device": device, "portID": portID})
var receiverList []uint32
receivers, _ := va.Icmpv6Receivers.Load(device)
if receivers != nil {
@@ -1276,6 +1304,7 @@
// vnet - vnet profile name
// enabled - vlan enabled/disabled - based on the status, the flow shall be added/removed
func (va *VoltApplication) ProcessDevFlowForDevice(cntx context.Context, device *VoltDevice, vnet *VoltVnet, enabled bool) {
+ logger.Debugw(ctx, "Process Dev Flow For Device", log.Fields{"Device": device, "VnetName": vnet.Name, "Enabled": enabled})
_, applied := device.ConfiguredVlanForDeviceFlows.Get(VnetKey(vnet.SVlan, vnet.CVlan, 0))
if enabled {
va.PushDevFlowForVlan(cntx, vnet)
@@ -1288,7 +1317,7 @@
// NniVlanIndToIgmp - Trigger receiver up indication to all ports with igmp enabled
// and has the provided mvlan
func (va *VoltApplication) NniVlanIndToIgmp(device *VoltDevice, mvp *MvlanProfile) {
- logger.Infow(ctx, "Sending Igmp Receiver UP indication for all Services", log.Fields{"Vlan": mvp.Mvlan})
+ logger.Infow(ctx, "Received Nni Vlan Ind To Igmp", log.Fields{"Vlan": mvp.Mvlan})
// Trigger nni indication for receiver only for first time
if device.IgmpDsFlowAppliedForMvlan[uint16(mvp.Mvlan)] {
@@ -1321,6 +1350,7 @@
// so that the services can configure flows applicable when the port goes
// up from down state
func (va *VoltApplication) PortUpInd(cntx context.Context, device string, port string) {
+ logger.Infow(ctx, "Received Southbound Port Ind: UP", log.Fields{"Device": device, "Port": port})
d := va.GetDevice(device)
if d == nil {
@@ -1336,23 +1366,22 @@
p := d.GetPort(port)
if p == nil {
- logger.Infow(ctx, "Ignoring Port Ind: UP, Port doesnt exist", log.Fields{"Device": device, "PortName": port, "PortId": p})
+ logger.Warnw(ctx, "Ignoring Port Ind: UP, Port doesnt exist", log.Fields{"Device": device, "PortName": port, "PortId": p})
va.portLock.Unlock()
return
}
p.State = PortStateUp
va.portLock.Unlock()
- logger.Infow(ctx, "Received SouthBound Port Ind: UP", log.Fields{"Device": device, "PortName": port, "PortId": p.ID})
if p.Type == VoltPortTypeNni {
- logger.Warnw(ctx, "Received NNI Port Ind: UP", log.Fields{"Device": device, "PortName": port, "PortId": p.ID})
+ logger.Debugw(ctx, "Received NNI Port Ind: UP", log.Fields{"Device": device, "PortName": port, "PortId": p.ID})
//va.PushDevFlowForDevice(d)
//Build Igmp TrapFlowRule
//va.ProcessIgmpDSFlowForDevice(d, true)
}
vpvs, ok := va.VnetsByPort.Load(port)
if !ok || nil == vpvs || len(vpvs.([]*VoltPortVnet)) == 0 {
- logger.Infow(ctx, "No VNETs on port", log.Fields{"Device": device, "Port": port})
+ logger.Warnw(ctx, "No VNETs on port", log.Fields{"Device": device, "Port": port})
//msgbus.ProcessPortInd(msgbus.PortUp, d.SerialNum, p.Name, false, getServiceList(port))
return
}
@@ -1404,11 +1433,12 @@
// ReceiverUpInd - Send receiver up indication for service with Igmp enabled
func ReceiverUpInd(key, value interface{}) bool {
+ logger.Info(ctx, "Receiver Indication: UP")
svc := value.(*VoltService)
var vlan of.VlanType
if !svc.IPAssigned() {
- logger.Infow(ctx, "IP Not assigned, skipping general query", log.Fields{"Service": svc})
+ logger.Warnw(ctx, "IP Not assigned, skipping general query", log.Fields{"Service": svc})
return false
}
@@ -1444,7 +1474,7 @@
// may lead to dead-lock
p := d.GetPort(port)
if p == nil {
- logger.Infow(ctx, "Ignoring Port Ind: Down, Port doesnt exist", log.Fields{"Device": device, "PortName": port, "PortId": p})
+ logger.Warnw(ctx, "Ignoring Port Ind: Down, Port doesnt exist", log.Fields{"Device": device, "PortName": port, "PortId": p})
va.portLock.Unlock()
return
}
@@ -1452,19 +1482,19 @@
va.portLock.Unlock()
if d.State == controller.DeviceStateREBOOTED {
- logger.Infow(ctx, "Ignoring Port Ind: Down, Device has been Rebooted", log.Fields{"Device": device, "PortName": port, "PortId": p})
+ logger.Warnw(ctx, "Ignoring Port Ind: Down, Device has been Rebooted", log.Fields{"Device": device, "PortName": port, "PortId": p})
return
}
if p.Type == VoltPortTypeNni {
- logger.Warnw(ctx, "Received NNI Port Ind: DOWN", log.Fields{"Device": device, "Port": port})
+ logger.Debugw(ctx, "Received NNI Port Ind: DOWN", log.Fields{"Device": device, "Port": port})
va.DeleteDevFlowForDevice(cntx, d)
va.NniDownInd(cntx, device, d.SerialNum)
va.RemovePendingGroups(cntx, device, true)
}
vpvs, ok := va.VnetsByPort.Load(port)
if !ok || nil == vpvs || len(vpvs.([]*VoltPortVnet)) == 0 {
- logger.Infow(ctx, "No VNETs on port", log.Fields{"Device": device, "Port": port})
+ logger.Warnw(ctx, "No VNETs on port", log.Fields{"Device": device, "Port": port})
//msgbus.ProcessPortInd(msgbus.PortDown, d.SerialNum, p.Name, false, getServiceList(port))
return
}
@@ -1488,14 +1518,13 @@
// plan to support only DHCP and IGMP. In future, we can add more
// capabilities as needed
func (va *VoltApplication) PacketInInd(cntx context.Context, device string, port string, pkt []byte) {
+ logger.Infow(ctx, "Received a Packet-In Indication", log.Fields{"Device": device, "Port": port})
// Decode the incoming packet
packetSide := US
if strings.Contains(port, NNI) {
packetSide = DS
}
- logger.Debugw(ctx, "Received a Packet-In Indication", log.Fields{"Device": device, "Port": port})
-
gopkt := gopacket.NewPacket(pkt, layers.LayerTypeEthernet, gopacket.Default)
var dot1qFound = false
@@ -1574,7 +1603,7 @@
if callBack, ok := PacketHandlers[PPPOE]; ok {
callBack(cntx, device, port, gopkt)
} else {
- logger.Debugw(ctx, "PPPoE handler is not registered, dropping the packet", log.Fields{"Pkt": hex.EncodeToString(gopkt.Data())})
+ logger.Warnw(ctx, "PPPoE handler is not registered, dropping the packet", log.Fields{"Pkt": hex.EncodeToString(gopkt.Data())})
}
}
}
@@ -1610,15 +1639,15 @@
// HandleFlowClearFlag to handle flow clear flag during reboot
func (va *VoltApplication) HandleFlowClearFlag(cntx context.Context, deviceID string, serialNum, southBoundID string) {
- logger.Warnw(ctx, "Clear All flags for Device", log.Fields{"Device": deviceID, "SerialNum": serialNum, "SBID": southBoundID})
+ logger.Infow(ctx, "Clear All flags for Device", log.Fields{"Device": deviceID, "SerialNum": serialNum, "SBID": southBoundID})
dev, ok := va.DevicesDisc.Load(deviceID)
if ok && dev != nil {
- logger.Infow(ctx, "Clear Flags for device", log.Fields{"voltDevice": dev.(*VoltDevice).Name})
+ logger.Debugw(ctx, "Clear Flags for device", log.Fields{"voltDevice": dev.(*VoltDevice).Name})
dev.(*VoltDevice).icmpv6GroupAdded = false
- logger.Infow(ctx, "Clearing DS Icmpv6 Map",
+ logger.Debugw(ctx, "Clearing DS Icmpv6 Map",
log.Fields{"voltDevice": dev.(*VoltDevice).Name})
dev.(*VoltDevice).ConfiguredVlanForDeviceFlows = util.NewConcurrentMap()
- logger.Infow(ctx, "Clearing DS IGMP Map",
+ logger.Debugw(ctx, "Clearing DS IGMP Map",
log.Fields{"voltDevice": dev.(*VoltDevice).Name})
for k := range dev.(*VoltDevice).IgmpDsFlowAppliedForMvlan {
delete(dev.(*VoltDevice).IgmpDsFlowAppliedForMvlan, k)
@@ -1635,7 +1664,7 @@
vpvs := value.([]*VoltPortVnet)
for _, vpv := range vpvs {
if vpv.Device == deviceID {
- logger.Infow(ctx, "Clear Flags for vpv",
+ logger.Debugw(ctx, "Clear Flags for vpv",
log.Fields{"device": vpv.Device, "port": vpv.Port,
"svlan": vpv.SVlan, "cvlan": vpv.CVlan, "univlan": vpv.UniVlan})
vpv.ClearAllServiceFlags(cntx)
@@ -1655,7 +1684,7 @@
// Clear Static Group
va.ReceiverDownInd(cntx, deviceID, StaticPort)
- logger.Warnw(ctx, "All flags cleared for device", log.Fields{"Device": deviceID})
+ logger.Infow(ctx, "All flags cleared for device", log.Fields{"Device": deviceID})
// Reset pending group pool
va.RemovePendingGroups(cntx, deviceID, true)
@@ -1686,9 +1715,10 @@
// ProcessFlowModResultIndication - Processes Flow mod operation indications from controller
func (va *VoltApplication) ProcessFlowModResultIndication(cntx context.Context, flowStatus intf.FlowStatus) {
+ logger.Debugw(ctx, "Received Flow Mod Result Indication.", log.Fields{"Cookie": flowStatus.Cookie, "Device": flowStatus.Device})
d := va.GetDevice(flowStatus.Device)
if d == nil {
- logger.Errorw(ctx, "Dropping Flow Mod Indication. Device not found", log.Fields{"Cookie": flowStatus.Cookie, "Device": flowStatus.Device})
+ logger.Warnw(ctx, "Dropping Flow Mod Indication. Device not found", log.Fields{"Cookie": flowStatus.Cookie, "Device": flowStatus.Device})
return
}
@@ -1706,11 +1736,12 @@
subFlow := flowStatus.Flow
cookie := subFlow.Cookie
uniPort := cookie >> 16 & 0xFFFFFFFF
- logger.Errorw(ctx, "Flow Failure Notification", log.Fields{"uniPort": uniPort, "Cookie": cookie})
+ logger.Warnw(ctx, "Flow Failure Notification", log.Fields{"uniPort": uniPort, "Cookie": cookie})
}
// UpdateMvlanProfilesForDevice to update mvlan profile for device
func (va *VoltApplication) UpdateMvlanProfilesForDevice(cntx context.Context, device string) {
+ logger.Debugw(ctx, "Received Update Mvlan Profiles For Device", log.Fields{"device": device})
checkAndAddMvlanUpdateTask := func(key, value interface{}) bool {
mvp := value.(*MvlanProfile)
if mvp.IsUpdateInProgressForDevice(device) {
@@ -1730,6 +1761,7 @@
// GetTaskList to get task list information.
func (va *VoltApplication) GetTaskList(device string) map[int]*TaskInfo {
+ logger.Debugw(ctx, "Received Get Task List", log.Fields{"device": device})
taskList := cntlr.GetController().GetTaskList(device)
taskMap := make(map[int]*TaskInfo)
for i, task := range taskList {
@@ -1744,11 +1776,12 @@
// UpdateDeviceSerialNumberList to update the device serial number list after device serial number is updated for vnet and mvlan
func (va *VoltApplication) UpdateDeviceSerialNumberList(oldOltSlNo string, newOltSlNo string) {
+ logger.Debugw(ctx, "Update Device Serial Number List", log.Fields{"oldOltSlNo": oldOltSlNo, "newOltSlNo": newOltSlNo})
voltDevice, _ := va.GetDeviceBySerialNo(oldOltSlNo)
if voltDevice != nil {
// Device is present with old serial number ID
- logger.Errorw(ctx, "OLT Migration cannot be completed as there are dangling devices", log.Fields{"Serial Number": oldOltSlNo})
+ logger.Warnw(ctx, "OLT Migration cannot be completed as there are dangling devices", log.Fields{"Serial Number": oldOltSlNo})
} else {
logger.Infow(ctx, "No device present with old serial number", log.Fields{"Serial Number": oldOltSlNo})
// Add Serial Number to Blocked Devices List.
@@ -1792,6 +1825,7 @@
// GetVpvsForDsPkt to get vpv for downstream packets
func (va *VoltApplication) GetVpvsForDsPkt(cvlan of.VlanType, svlan of.VlanType, clientMAC net.HardwareAddr,
pbit uint8) ([]*VoltPortVnet, error) {
+ logger.Debugw(ctx, "Received Get Vpvs For Ds Pkt", log.Fields{"Cvlan": cvlan, "Svlan": svlan, "Mac": clientMAC})
var matchVPVs []*VoltPortVnet
findVpv := func(key, value interface{}) bool {
vpvs := value.([]*VoltPortVnet)
@@ -1818,14 +1852,15 @@
va.VnetsByPort.Range(findVpv)
if len(matchVPVs) != 1 {
- logger.Infow(ctx, "No matching VPV found or multiple vpvs found", log.Fields{"Match VPVs": matchVPVs, "MAC": clientMAC})
- return nil, errors.New("No matching VPV found or multiple vpvs found")
+ logger.Errorw(ctx, "No matching VPV found or multiple vpvs found", log.Fields{"Match VPVs": matchVPVs, "MAC": clientMAC})
+ return nil, errors.New("no matching VPV found or multiple vpvs found")
}
return matchVPVs, nil
}
// GetMacInPortMap to get PORT value based on MAC key
func (va *VoltApplication) GetMacInPortMap(macAddr net.HardwareAddr) string {
+ logger.Debugw(ctx, "Received Get PORT value based on MAC key", log.Fields{"MacAddr": macAddr.String()})
if NonZeroMacAddress(macAddr) {
va.macPortLock.Lock()
defer va.macPortLock.Unlock()
@@ -1840,6 +1875,7 @@
// UpdateMacInPortMap to update MAC PORT (key value) information in MacPortMap
func (va *VoltApplication) UpdateMacInPortMap(macAddr net.HardwareAddr, port string) {
+ logger.Debugw(ctx, "Update Macportmap", log.Fields{"MacAddr": macAddr.String(), "Port": port})
if NonZeroMacAddress(macAddr) {
va.macPortLock.Lock()
va.macPortMap[macAddr.String()] = port
@@ -1850,6 +1886,7 @@
// DeleteMacInPortMap to remove MAC key from MacPortMap
func (va *VoltApplication) DeleteMacInPortMap(macAddr net.HardwareAddr) {
+ logger.Debugw(ctx, "Delete Mac from Macportmap", log.Fields{"MacAddr": macAddr.String()})
if NonZeroMacAddress(macAddr) {
port := va.GetMacInPortMap(macAddr)
va.macPortLock.Lock()
@@ -1916,6 +1953,7 @@
// 2. Delete the IgmpGroup obj and release the group ID to pool
// Note: Make sure to obtain PendingPoolLock lock before calling this func
func (va *VoltApplication) RemoveGroupListFromPendingPool(cntx context.Context, key string) {
+ logger.Infow(ctx, "Remove GroupList from Pending Pool for ", log.Fields{"key": key})
if grpMap, ok := va.IgmpPendingPool[key]; ok {
delete(va.IgmpPendingPool, key)
for ig := range grpMap {
@@ -1947,7 +1985,7 @@
// Gets all IgmpGrp Obj for the device
grpMap, ok := va.IgmpPendingPool[key]
if !ok || len(grpMap) == 0 {
- logger.Infow(ctx, "Matching IgmpGroup not found in Global Pending Pool", log.Fields{"Device": device, "Mvlan": mvlan.String()})
+ logger.Warnw(ctx, "Matching IgmpGroup not found in Global Pending Pool", log.Fields{"Device": device, "Mvlan": mvlan.String()})
return nil
}
@@ -2001,7 +2039,7 @@
}
func (va *VoltApplication) removeExpiredGroups(cntx context.Context) {
- logger.Debug(ctx, "Check for expired Igmp Groups")
+ logger.Info(ctx, "Remove expired Igmp Groups")
removeExpiredGroups := func(key interface{}, value interface{}) bool {
ig := value.(*IgmpGroup)
ig.removeExpiredGroupFromDevice(cntx)
@@ -2012,24 +2050,25 @@
// TriggerPendingProfileDeleteReq - trigger pending profile delete request
func (va *VoltApplication) TriggerPendingProfileDeleteReq(cntx context.Context, device string) {
+ logger.Infow(ctx, "Trigger Pending Profile Delete for device", log.Fields{"Device": device})
va.TriggerPendingServiceDeactivateReq(cntx, device)
va.TriggerPendingServiceDeleteReq(cntx, device)
va.TriggerPendingVpvDeleteReq(cntx, device)
va.TriggerPendingVnetDeleteReq(cntx, device)
- logger.Warnw(ctx, "All Pending Profile Delete triggered for device", log.Fields{"Device": device})
+ logger.Infow(ctx, "All Pending Profile Delete triggered for device", log.Fields{"Device": device})
}
// TriggerPendingServiceDeactivateReq - trigger pending service deactivate request
func (va *VoltApplication) TriggerPendingServiceDeactivateReq(cntx context.Context, device string) {
logger.Infow(ctx, "Pending Services to be deactivated", log.Fields{"Count": len(va.ServicesToDeactivate)})
for serviceName := range va.ServicesToDeactivate {
- logger.Infow(ctx, "Trigger Service Deactivate", log.Fields{"Service": serviceName})
+ logger.Debugw(ctx, "Trigger Service Deactivate", log.Fields{"Service": serviceName})
if vs := va.GetService(serviceName); vs != nil {
if vs.Device == device {
- logger.Warnw(ctx, "Triggering Pending Service Deactivate", log.Fields{"Service": vs.Name})
+ logger.Infow(ctx, "Triggering Pending Service Deactivate", log.Fields{"Service": vs.Name})
vpv := va.GetVnetByPort(vs.Port, vs.SVlan, vs.CVlan, vs.UniVlan)
if vpv == nil {
- logger.Errorw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name, "port": vs.Port, "Vnet": vs.VnetID})
+ logger.Warnw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name, "port": vs.Port, "Vnet": vs.VnetID})
continue
}
@@ -2039,36 +2078,36 @@
vpv.ClearServiceCounters(cntx)
}
} else {
- logger.Errorw(ctx, "Pending Service Not found", log.Fields{"Service": serviceName})
+ logger.Warnw(ctx, "Pending Service Not found", log.Fields{"Service": serviceName})
}
}
}
// TriggerPendingServiceDeleteReq - trigger pending service delete request
func (va *VoltApplication) TriggerPendingServiceDeleteReq(cntx context.Context, device string) {
- logger.Warnw(ctx, "Pending Services to be deleted", log.Fields{"Count": len(va.ServicesToDelete)})
+ logger.Infow(ctx, "Pending Services to be deleted", log.Fields{"Count": len(va.ServicesToDelete)})
for serviceName := range va.ServicesToDelete {
logger.Debugw(ctx, "Trigger Service Delete", log.Fields{"Service": serviceName})
if vs := va.GetService(serviceName); vs != nil {
if vs.Device == device {
- logger.Warnw(ctx, "Triggering Pending Service delete", log.Fields{"Service": vs.Name})
+ logger.Infow(ctx, "Triggering Pending Service delete", log.Fields{"Service": vs.Name})
vs.DelHsiaFlows(cntx)
if vs.ForceDelete {
vs.DelFromDb(cntx)
}
}
} else {
- logger.Errorw(ctx, "Pending Service Not found", log.Fields{"Service": serviceName})
+ logger.Warnw(ctx, "Pending Service Not found", log.Fields{"Service": serviceName})
}
}
}
// TriggerPendingVpvDeleteReq - trigger pending VPV delete request
func (va *VoltApplication) TriggerPendingVpvDeleteReq(cntx context.Context, device string) {
- logger.Warnw(ctx, "Pending VPVs to be deleted", log.Fields{"Count": len(va.VoltPortVnetsToDelete)})
+ logger.Infow(ctx, "Pending VPVs to be deleted", log.Fields{"Count": len(va.VoltPortVnetsToDelete)})
for vpv := range va.VoltPortVnetsToDelete {
if vpv.Device == device {
- logger.Warnw(ctx, "Triggering Pending VPv flow delete", log.Fields{"Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
+ logger.Debugw(ctx, "Triggering Pending VPv flow delete", log.Fields{"Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
va.DelVnetFromPort(cntx, vpv.Port, vpv)
}
}
@@ -2076,12 +2115,12 @@
// TriggerPendingVnetDeleteReq - trigger pending vnet delete request
func (va *VoltApplication) TriggerPendingVnetDeleteReq(cntx context.Context, device string) {
- logger.Warnw(ctx, "Pending Vnets to be deleted", log.Fields{"Count": len(va.VnetsToDelete)})
+ logger.Infow(ctx, "Pending Vnets to be deleted", log.Fields{"Count": len(va.VnetsToDelete)})
for vnetName := range va.VnetsToDelete {
if vnetIntf, _ := va.VnetsByName.Load(vnetName); vnetIntf != nil {
vnet := vnetIntf.(*VoltVnet)
- logger.Warnw(ctx, "Triggering Pending Vnet flows delete", log.Fields{"Vnet": vnet.Name})
if d, _ := va.GetDeviceBySerialNo(vnet.PendingDeviceToDelete); d != nil && d.SerialNum == vnet.PendingDeviceToDelete {
+ logger.Infow(ctx, "Triggering Pending Vnet flows delete", log.Fields{"Vnet": vnet.Name, "Device": vnet.PendingDeviceToDelete})
va.DeleteDevFlowForVlanFromDevice(cntx, vnet, vnet.PendingDeviceToDelete)
va.deleteVnetConfig(vnet)
} else {
@@ -2128,13 +2167,14 @@
}
func (va *VoltApplication) UpdateDeviceConfig(cntx context.Context, deviceConfig *DeviceConfig) {
+ logger.Infow(ctx, "Received UpdateDeviceConfig", log.Fields{"DeviceInfo": deviceConfig})
var dc *DeviceConfig
va.DevicesConfig.Store(deviceConfig.SerialNumber, deviceConfig)
err := dc.WriteDeviceConfigToDb(cntx, deviceConfig.SerialNumber, deviceConfig)
if err != nil {
- logger.Errorw(ctx, "DB update for device config failed", log.Fields{"err": err})
+ logger.Warnw(ctx, "DB update for device config failed", log.Fields{"err": err})
}
- logger.Infow(ctx, "Added OLT configurations", log.Fields{"DeviceInfo": deviceConfig})
+ logger.Debugw(ctx, "Added OLT configurations", log.Fields{"DeviceInfo": deviceConfig})
// If device is already discovered update the VoltDevice structure
device, id := va.GetDeviceBySerialNo(deviceConfig.SerialNumber)
if device != nil {
diff --git a/internal/pkg/application/dhcprelay.go b/internal/pkg/application/dhcprelay.go
index 580ea85..354db3c 100644
--- a/internal/pkg/application/dhcprelay.go
+++ b/internal/pkg/application/dhcprelay.go
@@ -138,6 +138,7 @@
// GetDhcpVnet to add dhcp vnet
func (dn *DhcpNetworks) GetDhcpVnet(outerVlan uint16, innerVlan uint16) *DhcpRelayVnet {
+ logger.Debugw(ctx, "Get Dhcp Vnet", log.Fields{"OuterVlan": outerVlan, "InnerVlan": innerVlan})
comboVlan := uint32(outerVlan)<<16 + uint32(innerVlan)
drv, ok := dn.Networks[comboVlan]
if ok {
@@ -148,6 +149,7 @@
// AddDhcpVnet to add dhcp vnet
func (dn *DhcpNetworks) AddDhcpVnet(outerVlan uint16, innerVlan uint16) *DhcpRelayVnet {
+ logger.Debugw(ctx, "Add Dhcp Vnet", log.Fields{"OuterVlan": outerVlan, "InnerVlan": innerVlan})
comboVlan := uint32(outerVlan)<<16 + uint32(innerVlan)
if drv, ok := dn.Networks[comboVlan]; ok {
return drv
@@ -166,6 +168,7 @@
// AddDhcpSession to add dhcp session
func (dn *DhcpNetworks) AddDhcpSession(pkt gopacket.Packet, session IDhcpRelaySession) error {
+ logger.Info(ctx, "Add Dhcp Session")
var key [6]byte
ethl := pkt.Layer(layers.LayerTypeEthernet)
eth, _ := ethl.(*layers.Ethernet)
@@ -186,6 +189,7 @@
// DelDhcpSession to delete dhcp session
func (dn *DhcpNetworks) DelDhcpSession(pkt gopacket.Packet, session IDhcpRelaySession) {
+ logger.Info(ctx, "Delete Dhcp Session")
var key [6]byte
ethl := pkt.Layer(layers.LayerTypeEthernet)
eth, _ := ethl.(*layers.Ethernet)
@@ -203,9 +207,10 @@
// delDhcpSessions to delete dhcp sessions
func delDhcpSessions(addr net.HardwareAddr, outervlan of.VlanType, innervlan of.VlanType, sessionKey [MaxLenDhcpv6DUID]byte) {
+ logger.Debugw(ctx, "Delete Dhcp Sessions", log.Fields{"Addr": addr, "OuterVlan": outervlan, "InnerVlan": innervlan})
var key [6]byte
if addr == nil || !NonZeroMacAddress(addr) {
- logger.Warnw(ctx, "Invalid MAC address", log.Fields{"Addr": addr})
+ logger.Warnw(ctx, "Invalid MAC address", log.Fields{"Addr": addr, "OuterVlan": outervlan, "InnerVlan": innervlan})
return
}
copy(key[:], addr[0:6])
@@ -220,7 +225,7 @@
// AddDhcp6Session to add dhcpv6 session
func (dn *DhcpNetworks) AddDhcp6Session(key [MaxLenDhcpv6DUID]byte, session IDhcpRelaySession) error {
outerVlan, innerVlan := session.GetNniVlans()
- logger.Infow(ctx, "Adding Session", log.Fields{"outerVlan": outerVlan, "innerVlan": innerVlan, "Addr": key})
+ logger.Debugw(ctx, "Adding Dhcp6 Session", log.Fields{"outerVlan": outerVlan, "innerVlan": innerVlan, "Addr": key})
drv := dn.AddDhcpVnet(outerVlan, innerVlan)
drv.sessionLock.Lock()
drv.sessionsv6[key] = session
@@ -231,7 +236,7 @@
// DelDhcp6Session to delete dhcpv6 session
func (dn *DhcpNetworks) DelDhcp6Session(key [MaxLenDhcpv6DUID]byte, session IDhcpRelaySession) {
outerVlan, innerVlan := session.GetNniVlans()
- logger.Infow(ctx, "Get Session", log.Fields{"OuterVLAN": outerVlan, "InnerVLAN": innerVlan, "Addr": key})
+ logger.Debugw(ctx, "Delete Dhcp6 Session", log.Fields{"OuterVLAN": outerVlan, "InnerVLAN": innerVlan, "Addr": key})
drv := dn.GetDhcpVnet(outerVlan, innerVlan)
drv.sessionLock.Lock()
delete(drv.sessionsv6, key)
@@ -240,6 +245,7 @@
// GetDhcpSession to get dhcp session info
func (dn *DhcpNetworks) GetDhcpSession(outerVlan uint16, innerVlan uint16, addr net.HardwareAddr) (IDhcpRelaySession, error) {
+ logger.Debugw(ctx, "Get Dhcp Session", log.Fields{"OuterVLAN": outerVlan, "InnerVLAN": innerVlan, "Addr": addr})
var key [6]byte
if len(addr) != 6 {
logger.Errorw(ctx, "Invalid MAC address", log.Fields{"Addr": addr})
@@ -257,7 +263,7 @@
// GetDhcp6Session to get Dhcp6Session
func (dn *DhcpNetworks) GetDhcp6Session(outerVlan uint16, innerVlan uint16, key [MaxLenDhcpv6DUID]byte) (IDhcpRelaySession, error) {
- logger.Infow(ctx, "Locating Session", log.Fields{"OuterVlan": outerVlan, "InnerVlan": innerVlan, "key": key})
+ logger.Debugw(ctx, "Locating Session", log.Fields{"OuterVlan": outerVlan, "InnerVlan": innerVlan, "key": key})
drv := dn.AddDhcpVnet(outerVlan, innerVlan)
drv.sessionLock.RLock()
@@ -270,6 +276,7 @@
// GetVlansFromPacket to get vlans from the packet
func GetVlansFromPacket(pkt gopacket.Packet) (innerVlan of.VlanType, outerVlan of.VlanType) {
+ logger.Debugw(ctx, "Get Vlans From Packet", log.Fields{"OuterVlan": outerVlan, "InnerVlan": innerVlan})
vlans := GetVlans(pkt)
if len(vlans) == 1 {
outerVlan = vlans[0]
@@ -289,7 +296,7 @@
var err error
var session IDhcpRelaySession
var vpvList []*VoltPortVnet
- logger.Infow(ctx, "Mac Obtained MAC: ", log.Fields{"Addr": dhcp.ClientHWAddr})
+ logger.Debugw(ctx, "Get Vnet For V4 Nni: ", log.Fields{"Addr": dhcp.ClientHWAddr})
session, err = dhcpNws.GetDhcpSession(uint16(svlan), uint16(cvlan), dhcp.ClientHWAddr)
if session != nil {
@@ -303,7 +310,7 @@
if err == ErrSessionDoNotExist {
//No DHCP Session found, find matching VPV to send the packet out
- logger.Info(ctx, "Session Doesnt Exist: Finding matching VPV")
+ logger.Warn(ctx, "Session Doesnt Exist: Finding matching VPV")
return GetApplication().GetVpvsForDsPkt(cvlan, svlan, dhcp.ClientHWAddr, pbit)
}
return nil, errors.New("The session retrieved of wrong type")
@@ -315,6 +322,7 @@
var err error
var session IDhcpRelaySession
var vpvList []*VoltPortVnet
+ logger.Info(ctx, "Get Vnet For V6 Nni")
var sessionKey [MaxLenDhcpv6DUID]byte
@@ -374,6 +382,7 @@
// getDhcpv6ClientDUID to get Dhcpv6 client DUID
func getDhcpv6ClientDUID(dhcpv6 *layers.DHCPv6) ([]byte, *layers.DHCPv6DUID) {
+ logger.Info(ctx, "Get Dhcp v6 Client DUID")
for _, option := range dhcpv6.Options {
logger.Debugw(ctx, "DHCPv6 Options", log.Fields{"option": option.Code})
if option.Code == layers.DHCPv6OptClientID {
@@ -387,11 +396,11 @@
}
return option.Data[0:duidLen], duid
}
- logger.Errorw(ctx, "Client DUID decode failed", log.Fields{"error": err})
+ logger.Warnw(ctx, "Client DUID decode failed", log.Fields{"error": err})
break
}
}
- logger.Error(ctx, "Client DUID is not present in the packet")
+ logger.Warn(ctx, "Client DUID is not present in the packet")
return nil, nil
}
@@ -400,6 +409,7 @@
// into the packet. This happens as the request is relayed to the
// DHCP servers on the NNI
func AddDhcpv4Option82(svc *VoltService, rID []byte, dhcpv4 *layers.DHCPv4) {
+ logger.Debugw(ctx, "Add Dhcp v4 Option82", log.Fields{"Addr": dhcpv4.ClientHWAddr})
//NOTE : both cID and rID should not be empty if this function is called
cID := svc.GetCircuitID()
var data []byte
@@ -444,6 +454,7 @@
// Once the packet is received, the option 82 is stripped off and the
// packet is forwarded towards access
func DelOption82(dhcpv4 *layers.DHCPv4) {
+ logger.Debugw(ctx, "Delete Dhcp v4 Option82", log.Fields{"Addr": dhcpv4.ClientHWAddr})
for index, option := range dhcpv4.Options {
if option.Type == opt82 {
dhcpv4.Options = append(dhcpv4.Options[0:index], dhcpv4.Options[index+1:]...)
@@ -454,6 +465,7 @@
// DhcpMsgType returns the DHCP message type from the packet
func DhcpMsgType(dhcp *layers.DHCPv4) layers.DHCPMsgType {
+ logger.Debugw(ctx, "Dhcp msg type", log.Fields{"Addr": dhcp.ClientHWAddr})
for _, option := range dhcp.Options {
if option.Type == layers.DHCPOptMessageType {
return layers.DHCPMsgType(option.Data[0])
@@ -464,6 +476,7 @@
// GetIpv4Addr returns the IP address in the DHCP reply
func GetIpv4Addr(dhcp *layers.DHCPv4) (net.IP, int64) {
+ logger.Debugw(ctx, "Get Dhcp ipv4 addr", log.Fields{"Addr": dhcp.ClientHWAddr})
var leaseTime uint32
for _, opt := range dhcp.Options {
if opt.Type == layers.DHCPOptLeaseTime {
@@ -480,6 +493,7 @@
// GetIpv6Addr returns the IPv6 address in the DHCPv6 reply
func GetIpv6Addr(dhcp6 *layers.DHCPv6) (net.IP, uint32) {
+ logger.Debugw(ctx, "Get Dhcp ipv6 addr", log.Fields{"Addr": dhcp6.MsgType})
var ipv6Addr net.IP
var leaseTime uint32
@@ -495,6 +509,7 @@
// GetIANAAddress returns the IPv6 address in the DHCPv6 reply
func GetIANAAddress(dhcp6 *layers.DHCPv6) (net.IP, uint32) {
+ logger.Debugw(ctx, "Get Dhcp IANA addr", log.Fields{"Addr": dhcp6.MsgType})
var ipv6Addr net.IP
var leaseTime uint32
if dhcp6.MsgType == layers.DHCPv6MsgTypeReply {
@@ -518,6 +533,7 @@
// GetIAPDAddress returns the IPv6 address in the DHCPv6 reply
func GetIAPDAddress(dhcp6 *layers.DHCPv6) (net.IP, uint32) {
+ logger.Debugw(ctx, "Get Dhcp IAPD addr", log.Fields{"Addr": dhcp6.MsgType})
var ipv6Addr net.IP
var leaseTime uint32
if dhcp6.MsgType == layers.DHCPv6MsgTypeReply {
@@ -607,7 +623,7 @@
// Create the outgoing bufer and set the checksum in the packet
buff := gopacket.NewSerializeBuffer()
if err := udp.SetNetworkLayerForChecksum(ip); err != nil {
- logger.Error(ctx, "Error in setting checksum")
+ logger.Errorw(ctx, "Error in setting checksum", log.Fields{"Reason": err.Error()})
return
}
opts := gopacket.SerializeOptions{
@@ -659,7 +675,7 @@
udot1q := &layers.Dot1Q{Priority: dsPbit, VLANIdentifier: uint16(vpv.UniVlan), DropEligible: dropEligible, Type: cTagType}
pktLayers = append(pktLayers, udot1q)
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vpv.VlanControl})
+ logger.Warnw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vpv.VlanControl})
}
pktLayers = append(pktLayers, qVlanLayers...)
@@ -756,6 +772,7 @@
// ProcessUsDhcpv4Packet : The US DHCPv4 packet is identified the DHCP OP in the packet. A request is considered upstream
// and the service associated with the packet is located by the port and VLANs in the packet
func (va *VoltApplication) ProcessUsDhcpv4Packet(cntx context.Context, device string, port string, pkt gopacket.Packet) {
+ logger.Infow(ctx, "Processing Southbound US DHCPv4 packet", log.Fields{"Device": device, "Port": port})
// We received the packet on an access port and the service for the packet can be
// gotten from the port and the packet
vpv, svc := va.GetVnetFromPkt(device, port, pkt)
@@ -778,7 +795,6 @@
udp := pkt.Layer(layers.LayerTypeUDP).(*layers.UDP)
dhcp4 := pkt.Layer(layers.LayerTypeDHCPv4).(*layers.DHCPv4)
msgType := DhcpMsgType(dhcp4)
- logger.Infow(ctx, "Processing Southbound US DHCPv4 packet", log.Fields{"Device": device, "Port": port, "Type": msgType})
// Learn the 8021P values from the packet received
var priority uint8
@@ -927,6 +943,7 @@
// Currently DHCP is the only application supported by the application
// We check for DHCP before proceeding further. In future, this could be
// based on registration and the callbacks
+ logger.Debugw(ctx, "Process UDP4 Packet", log.Fields{"Device": device, "Port": port})
dhcpl := pkt.Layer(layers.LayerTypeDHCPv4)
if dhcpl == nil {
return
@@ -956,11 +973,11 @@
// additional option that identifies to the server that the DHCP packet is forwarded
// by an LDRA node.
func (va *VoltApplication) ProcessUDP6Packet(cntx context.Context, device string, port string, pkt gopacket.Packet) []byte {
+ logger.Debugw(ctx, "Processing DHCPv6 packet", log.Fields{"Device": device, "Port": port})
dhcpl := pkt.Layer(layers.LayerTypeDHCPv6)
if dhcpl == nil {
return nil
}
- logger.Infow(ctx, "Processing DHCPv6 packet", log.Fields{"Port": port})
dhcpv6 := dhcpl.(*layers.DHCPv6)
switch dhcpv6.MsgType {
case layers.DHCPv6MsgTypeSolicit, layers.DHCPv6MsgTypeRequest, layers.DHCPv6MsgTypeRenew,
@@ -981,7 +998,7 @@
// GetRelayReplyBytes to get relay reply bytes
func GetRelayReplyBytes(dhcp6 *layers.DHCPv6) []byte {
for _, o := range dhcp6.Options {
- logger.Infow(ctx, "Received Option", log.Fields{"Code": o.Code})
+ logger.Debugw(ctx, "Received Option", log.Fields{"Code": o.Code})
if o.Code == layers.DHCPv6OptRelayMessage {
return o.Data
}
@@ -991,6 +1008,7 @@
// BuildRelayFwd to build forward relay
func BuildRelayFwd(paddr net.IP, intfID []byte, remoteID []byte, payload []byte, isOption82Enabled bool, dhcpRelay bool) *layers.DHCPv6 {
+ logger.Debugw(ctx, "Build Relay Fwd", log.Fields{"Paddr": paddr, "isOption82Enabled": isOption82Enabled, "dhcpRelay": dhcpRelay})
dhcp6 := &layers.DHCPv6{MsgType: layers.DHCPv6MsgTypeRelayForward, LinkAddr: net.ParseIP("::"), PeerAddr: []byte(paddr)}
dhcp6.Options = append(dhcp6.Options, layers.NewDHCPv6Option(layers.DHCPv6OptRelayMessage, payload))
// Check IsOption82Enabled flag in configuration. if true(enabled), add remoteID and circuitID into dhcpv6 header.
@@ -1014,7 +1032,7 @@
func (va *VoltApplication) ProcessUsDhcpv6Packet(cntx context.Context, device string, port string, pkt gopacket.Packet) {
// We received the packet on an access port and the service for the packet can be
// gotten from the port and the packet
- logger.Infow(ctx, "Processing Southbound US DHCPv6 packet", log.Fields{"Port": port})
+ logger.Infow(ctx, "Processing Southbound US DHCPv6 packet", log.Fields{"Device": device, "Port": port})
logger.Debugw(ctx, "Packet IN", log.Fields{"Pkt": hex.EncodeToString(pkt.Data())})
vpv, svc := va.GetVnetFromPkt(device, port, pkt)
if vpv == nil {
@@ -1415,10 +1433,10 @@
}
func (va *VoltApplication) GetMacLearnerInfo(cntx context.Context, deviceID, portNumber, vlanID string) (MacLearnerInfo, error) {
- logger.Info(ctx, "GetMecLearnerInfo")
+ logger.Debugw(ctx, "GetMecLearnerInfo", log.Fields{"DeviceID": deviceID, "PortNumber": portNumber, "VlanID": vlanID})
macLearn := MacLearnerInfo{}
for _, drv := range dhcpNws.Networks {
- logger.Infow(ctx, "drv found", log.Fields{"drv": drv})
+ logger.Debugw(ctx, "drv found", log.Fields{"drv": drv})
drv.sessionLock.RLock()
for _, session := range drv.sessions {
vpv, ok := session.(*VoltPortVnet)
@@ -1430,7 +1448,7 @@
VlanID: vpv.SVlan.String(),
MacAddress: vpv.MacAddr.String(),
}
- logger.Infow(ctx, "MacLerner found", log.Fields{"MacLearn": macLearn})
+ logger.Debugw(ctx, "MacLerner found", log.Fields{"MacLearn": macLearn})
} else if deviceID == vpv.Device && portNumber == vpv.Port && vlanID == "" {
macLearn = MacLearnerInfo{
DeviceID: vpv.Device,
@@ -1438,7 +1456,7 @@
VlanID: vpv.SVlan.String(),
MacAddress: vpv.MacAddr.String(),
}
- logger.Infow(ctx, "MacLerner found", log.Fields{"MacLearn": macLearn})
+ logger.Debugw(ctx, "MacLerner found", log.Fields{"MacLearn": macLearn})
}
}
}
@@ -1452,10 +1470,10 @@
IgnoredPorts := make(map[string][]string)
portIgnored := func(key, value interface{}) bool {
voltDevice := value.(*VoltDevice)
- logger.Infow(ctx, "Inside GetIgnoredPorts method", log.Fields{"deviceName": voltDevice.Name})
+ logger.Debugw(ctx, "Inside GetIgnoredPorts method", log.Fields{"deviceName": voltDevice.Name})
voltDevice.Ports.Range(func(key, value interface{}) bool {
port := key.(string)
- logger.Infow(ctx, "Inside GetIgnoredPorts method", log.Fields{"port": port})
+ logger.Debugw(ctx, "Inside GetIgnoredPorts method", log.Fields{"port": port})
//Obtain all VPVs associated with the port
vnets, ok := GetApplication().VnetsByPort.Load(port)
if !ok {
@@ -1466,12 +1484,12 @@
IgnoredPorts[vpv.Device] = append(IgnoredPorts[vpv.Device], vpv.Port)
}
}
- logger.Debugw(ctx, "Ignored Port", log.Fields{"Ignored Port": IgnoredPorts})
+ logger.Warnw(ctx, "Ignored Port", log.Fields{"Ignored Port": IgnoredPorts})
return true
})
return true
}
va.DevicesDisc.Range(portIgnored)
- logger.Info(ctx, "GetIgnoredPorts completed")
+ logger.Debug(ctx, "GetIgnoredPorts completed")
return IgnoredPorts, nil
}
diff --git a/internal/pkg/application/dhcpserverhandler.go b/internal/pkg/application/dhcpserverhandler.go
index 44cdb8e..484e18d 100644
--- a/internal/pkg/application/dhcpserverhandler.go
+++ b/internal/pkg/application/dhcpserverhandler.go
@@ -93,12 +93,12 @@
// dhcpRequestReceived called for every DHCP request received from client.
func dhcpRequestReceived(cTag, sTag uint16, smac string) {
+ logger.Infow(ctx, "Dhcp Request Received", log.Fields{"ctag": cTag, "stag": sTag, "smac": smac})
var dtInfo dhcpTransactionInfo
var valueExist bool
dsTag := newDhcpServerTag(cTag, sTag)
mux.Lock()
- logger.Debugw(ctx, "dhcpRequestReceived", log.Fields{"ctag": cTag, "stag": sTag, "smac": smac})
if dtInfo, valueExist = dhcpServerInfo[dsTag]; !valueExist {
dtInfo = newDhcpTransactionInfo(dhcpTimeout, smac)
dtInfo.incrementPendingRequestCount()
@@ -117,12 +117,12 @@
// dhcpResponseReceived called for every DHCP response received from dhcp server.
func dhcpResponseReceived(cTag, sTag uint16) {
+ logger.Infow(ctx, "Dhcp Response Received", log.Fields{"ctag": cTag, "stag": sTag})
var dtInfo dhcpTransactionInfo
var valueExist bool
dsTag := newDhcpServerTag(cTag, sTag)
mux.Lock()
- logger.Debugw(ctx, "dhcpResponseReceived", log.Fields{"ctag": cTag, "stag": sTag})
if dtInfo, valueExist = dhcpServerInfo[dsTag]; !valueExist {
logger.Warnw(ctx, "Ignore unknown response", log.Fields{"DhcpResp": dsTag})
mux.Unlock()
diff --git a/internal/pkg/application/flowevent.go b/internal/pkg/application/flowevent.go
index be52fbb..577cdca 100644
--- a/internal/pkg/application/flowevent.go
+++ b/internal/pkg/application/flowevent.go
@@ -77,11 +77,12 @@
// ExecuteFlowEvent - Process flow based event triggers
func ExecuteFlowEvent(cntx context.Context, vd *VoltDevice, cookie string, flowStatus intf.FlowStatus) bool {
+ logger.Debugw(ctx, "Execute Flow event", log.Fields{"Cookie": cookie, "flowMod": flowStatus.FlowModType})
var event interface{}
flowEventMap, err := vd.GetFlowEventRegister(flowStatus.FlowModType)
if err != nil {
- logger.Debugw(ctx, "Flow event map does not exists", log.Fields{"flowMod": flowStatus.FlowModType, "Error": err})
+ logger.Warnw(ctx, "Flow event map does not exists", log.Fields{"flowMod": flowStatus.FlowModType, "Error": err})
return false
}
flowEventMap.MapLock.Lock()
@@ -164,7 +165,7 @@
// ProcessDeviceFlowDelEvent - Process Control Flow event trigger
func ProcessDeviceFlowDelEvent(cntx context.Context, event *FlowEvent, flowStatus intf.FlowStatus) {
- logger.Infow(ctx, "Processing Post Flow Remove Event for VNET", log.Fields{"Cookie": event.cookie, "event": event})
+ logger.Debugw(ctx, "Processing Post Flow Remove Event for VNET", log.Fields{"Cookie": event.cookie, "event": event})
vnet := event.eventData.(*VoltVnet)
if isFlowStatusSuccess(flowStatus.Status, false) {
vnet.FlowRemoveSuccess(cntx, event.cookie, event.device)
@@ -175,6 +176,7 @@
// TODO: Update the func or flowStatus struct once all flow status are based on NB error code
func isFlowStatusSuccess(status uint32, flowAdd bool) bool {
+ logger.Infow(ctx, "Processing isFlowStatusSuccess", log.Fields{"Status": status, "FlowAdd": flowAdd})
result := false
errorCode := infraerrorcode.ErrorCode(status)
diff --git a/internal/pkg/application/major_upgrade.go b/internal/pkg/application/major_upgrade.go
index 2cd488c..66408ca 100644
--- a/internal/pkg/application/major_upgrade.go
+++ b/internal/pkg/application/major_upgrade.go
@@ -19,6 +19,7 @@
"context"
"encoding/json"
"errors"
+ "fmt"
"sync"
common "voltha-go-controller/internal/pkg/types"
@@ -92,6 +93,7 @@
// DelFromDb delete a meter profile from DB
func (md *DataMigration) DelFromDb(cntx context.Context) {
+ logger.Debug(ctx, "Received Delete from Db")
if err := db.DelMigrationInfo(cntx); err != nil {
logger.Warnw(ctx, "DelMigrationInfo Failed", log.Fields{"Error": err})
}
@@ -99,6 +101,7 @@
// GetMigrationInfo to get data migration info
func GetMigrationInfo(cntx context.Context, dmInfo *DataMigration) error {
+ logger.Debug(ctx, "Get Migration Info")
var migrationInfo string
var err error
if db == nil {
@@ -120,6 +123,7 @@
// When Roll back happens just Delete of DB keys has to happen
// which will be done once delete key request is received from MSM
func CheckIfMigrationRequired(ctx context.Context) bool {
+ logger.Debug(ctx, "Check If Migration Required")
Migrate := new(DataMigration)
var NoDataInDB bool
err := GetMigrationInfo(ctx, Migrate)
@@ -127,7 +131,7 @@
// No DB entry represents N version Bring Up for the First time
if err != nil {
NoDataInDB = true
- logger.Error(ctx, "Failed to read the Migration Data from DB ")
+ logger.Warn(ctx, "Failed to read the Migration Data from DB ")
}
// Covers N version bringup and Reboot Scenarios
if NoDataInDB {
@@ -136,7 +140,7 @@
Migrate.Status = MigrationComplete
Migrate.ModuleVer = database.PresentVersionMap
if err := Migrate.WriteToDb(ctx); err != nil {
- logger.Errorw(ctx, "DB Write failed for Migration Path", log.Fields{"error": err})
+ logger.Warnw(ctx, "DB Write failed for Migration Path", log.Fields{"error": err})
}
// MigrateProbestatus has to be Updated to Complete when No Migration is Required
logger.Debugw(ctx, "Migration Probe Status", log.Fields{"Migration Probe": Migrate.Status})
@@ -181,6 +185,7 @@
// InitiateDataMigration Migrates the DB data
// depending on the bool value returned by CheckIfMigrationDone
func InitiateDataMigration(ctx context.Context) {
+ logger.Debug(ctx, "Initiate Data Migration")
var err error
Migrate := new(DataMigration)
var migrationWG sync.WaitGroup
@@ -234,6 +239,7 @@
// MigrateDBData to migrate database data
func MigrateDBData(cntx context.Context) error {
+ logger.Debug(ctx, "Migrate DB Data")
var err error
for module, currentVersion := range database.PresentVersionMap {
if currentVersion == database.DBVersionMap[module] {
@@ -257,8 +263,7 @@
}
if err != nil {
- logger.Errorw(ctx, "Error in data migration", log.Fields{"Module": module})
- return err
+ return fmt.Errorf("error in data migration for module %s : %w", module, err)
}
}
return nil
@@ -266,21 +271,22 @@
// FetchAndMigrateDeviceDBData fetchs the data from database and migrte the same to latest versions and store ot back ot database
func FetchAndMigrateDeviceDBData(module string) error {
- logger.Error(ctx, "Data Migration not implemented for Device DB Data")
+ logger.Errorw(ctx, "Data Migration not implemented for Device DB Data", log.Fields{"Table": module})
return nil
}
// FetchAndMigrateDBData fetchs the data from database and migrte the same to latest versions and store ot back ot database
func FetchAndMigrateDBData(cntx context.Context, module string) error {
+ logger.Debugw(ctx, "Fetch And Migrate DB Data", log.Fields{"Module": module})
previousPath := database.GetModuleKeypath(module, database.PreviousVersionMap[module])
dbPathKeysValueMap, err := db.List(cntx, previousPath)
if err != nil {
- logger.Errorw(ctx, "failed to Fetch the Keys from Redis", log.Fields{"error": err})
+ logger.Warnw(ctx, "failed to Fetch the Keys from Redis", log.Fields{"error": err})
// No return required, Data might not be present in DB
return nil
}
if len(dbPathKeysValueMap) == 0 {
- logger.Debugw(ctx, "No data present in DB for the path", log.Fields{"dbPath": module})
+ logger.Warnw(ctx, "No data present in DB for the path", log.Fields{"dbPath": module})
return nil
}
@@ -290,14 +296,12 @@
// convert the value to a specific type based on the dbPath
b, ok := value.Value.([]byte)
if !ok {
- logger.Error(ctx, "The value type is not []byte")
- return errors.New("Error-in-migration")
+ return errors.New("Error-in-migration, The value type is not []byt")
}
presentParams := migrationMap[module](cntx, b)
logger.Infow(ctx, "Migrated data", log.Fields{"presentParams": presentParams})
if "" == presentParams {
- logger.Error(ctx, "Error in migrating data\n")
return errors.New("Error-in-migration")
} else if ModuleToBeDeleted == presentParams {
return nil
@@ -314,6 +318,7 @@
// MigrateServices modifyies the old data as per current version requirement and updates the database
func MigrateServices(cntx context.Context, data []byte) string {
+ logger.Debug(ctx, "Migrate Services")
var vs VoltService
var updatedData, updatedData1 []byte
var vsmap map[string]interface{}
@@ -390,6 +395,7 @@
// MigrateVnets modifyies the old data as per current version requirement and updates the database
func MigrateVnets(cntx context.Context, data []byte) string {
+ logger.Debug(ctx, "Migrate Vnets")
var vnet VoltVnet
var updatedData []byte
@@ -420,6 +426,7 @@
// MigrateVpvs modifyies the old data as per current version requirement and updates the database
func MigrateVpvs(cntx context.Context, data []byte) string {
+ logger.Debug(ctx, "Migrate Vpvs")
var vpv VoltPortVnet
var updatedData, updatedData1 []byte
var vpvmap map[string]interface{}
@@ -474,6 +481,7 @@
// MigrateMvlans modifyies the old data as per current version requirement and updates the database
func MigrateMvlans(cntx context.Context, data []byte) string {
+ logger.Debug(ctx, "Migrate Mvlans")
var mvp MvlanProfile
var updatedData []byte
@@ -505,6 +513,7 @@
// MigrateIgmpConfs modifyies the old data as per current version requirement and updates the database
func MigrateIgmpConfs(cntx context.Context, data []byte) string {
+ logger.Debug(ctx, "Migrate IgmpConfs")
var igmpProfile IgmpProfile
err := json.Unmarshal(data, &igmpProfile)
@@ -513,7 +522,7 @@
return ""
}
if err := igmpProfile.WriteToDb(cntx); err != nil {
- logger.Errorw(ctx, "Igmp profile Write to DB failed", log.Fields{"profileID": igmpProfile.ProfileID})
+ logger.Warnw(ctx, "Igmp profile Write to DB failed", log.Fields{"profileID": igmpProfile.ProfileID})
}
logger.Infow(ctx, "Igmp Conf Migrated", log.Fields{"Profile": igmpProfile, "PresentVersion": database.PresentVersionMap[database.VpvPath]})
diff --git a/internal/pkg/application/meters.go b/internal/pkg/application/meters.go
index 2592be5..a7fa722 100644
--- a/internal/pkg/application/meters.go
+++ b/internal/pkg/application/meters.go
@@ -108,7 +108,7 @@
// GetMeterByName to get meter by name
func (m *MeterMgr) GetMeterByName(name string) (*VoltMeter, bool) {
meter, ok := m.Meters.Load(name)
- logger.Infow(ctx, "Meter Obtained Name", log.Fields{"Meter": meter})
+ logger.Infow(ctx, "Meter Obtained Name", log.Fields{"Name": name, "Meter": meter})
if ok {
return meter.(*VoltMeter), ok
}
@@ -118,7 +118,7 @@
// GetMeterByID to get meter by ID
func (m *MeterMgr) GetMeterByID(id uint32) (*VoltMeter, bool) {
meter, ok := m.MetersByID.Load(id)
- logger.Infow(ctx, "Meter Obtained ID", log.Fields{"Meter": meter})
+ logger.Infow(ctx, "GetMeter Obtained ID", log.Fields{"ID": id, "Meter": meter})
if ok {
return meter.(*VoltMeter), ok
}
@@ -141,7 +141,7 @@
// AddToDevice to add meter to the device
func (vm *VoltMeter) AddToDevice(port string, device string, aggVM *VoltMeter) {
- logger.Debugw(ctx, "Adding Meter To Device", log.Fields{"Id": vm.ID, "Device": device, "Port": port})
+ logger.Debugw(ctx, "Add To Device", log.Fields{"Id": vm.ID, "Device": device, "Port": port})
meter := of.NewMeter(vm.ID)
// meter.AddBand(vm.Air, vm.BurstSize)
// meter.AddBand(vm.Eir, vm.BurstSize)
@@ -201,6 +201,7 @@
// AddMeterToDevice to add meter to the device
func (m *MeterMgr) AddMeterToDevice(port string, device string, meterID uint32, aggMeterID uint32) {
+ logger.Debugw(ctx, "Adding Meter To Device", log.Fields{"Agg MeterID": aggMeterID, "Device": device, "Port": port, "MeterID": meterID})
var aggVM *VoltMeter
vm, err := m.GetMeterByProfID(meterID)
if err == nil {
@@ -218,7 +219,7 @@
// RestoreMetersFromDb to read from the DB and restore all the services
func (m *MeterMgr) RestoreMetersFromDb(cntx context.Context) {
// VNETS must be learnt first
- logger.Infow(ctx, "LastMeterID on restart", log.Fields{"LastMeterID": m.LastMeterID})
+ logger.Infow(ctx, "Received RestoreMetersFromDb and LastMeterID on restart", log.Fields{"LastMeterID": m.LastMeterID})
ms, _ := db.GetMeters(cntx)
for _, mt := range ms {
b, ok := mt.Value.([]byte)
@@ -232,17 +233,18 @@
logger.Warn(ctx, "Unmarshal of meter profile failed")
continue
}
- logger.Infow(ctx, "Retrieved Meter", log.Fields{"Meter": meter.Name})
+ logger.Debugw(ctx, "Retrieved Meter", log.Fields{"Meter": meter.Name})
m.AddMeter(&meter)
if meter.ID > m.LastMeterID {
m.LastMeterID = meter.ID
}
}
- logger.Infow(ctx, "LastMeterID on reading DB", log.Fields{"LastMeterID": m.LastMeterID})
+ logger.Debugw(ctx, "LastMeterID on reading DB", log.Fields{"LastMeterID": m.LastMeterID})
}
// AddMeterProf to add the meter profile name as key
func (va *VoltApplication) AddMeterProf(cntx context.Context, cfg VoltMeter) {
+ logger.Infow(ctx, "Add the meter profile name as key", log.Fields{"MeterConfig": cfg})
mm := &va.MeterMgr
if _, ok := mm.GetMeterByName(cfg.Name); ok {
logger.Warnw(ctx, "Meter profile exists", log.Fields{"Name": cfg.Name})
@@ -263,6 +265,7 @@
// UpdateMeterProf to update the meter profile
func (va *VoltApplication) UpdateMeterProf(cntx context.Context, cfg VoltMeter) {
+ logger.Debugw(ctx, "Update the meter profile name as key", log.Fields{"MeterConfig": cfg})
mm := &va.MeterMgr
if _, ok := mm.GetMeterByName(cfg.Name); !ok {
logger.Warnw(ctx, "Meter profile does not exist", log.Fields{"Name": cfg.Name})
@@ -277,6 +280,7 @@
// GetMeterByProfID to get a meter based on the identities of bandwidth profile and shaper
// profile names.
func (m *MeterMgr) GetMeterByProfID(id uint32) (*VoltMeter, error) {
+ logger.Debugw(ctx, "Get Meter by Profile id", log.Fields{"ID": id})
if mtr, ok := m.GetMeterByID(id); ok {
return mtr, nil
}
@@ -286,6 +290,7 @@
// GetMeter to get a meter based on the identities of bandwidth profile and shaper
// profile names.
func (m *MeterMgr) GetMeter(meterID string) (*VoltMeter, error) {
+ logger.Debugw(ctx, "Get Meter by Meter id", log.Fields{"MeterID": meterID})
if mt, ok := m.GetMeterByName(meterID); ok {
return mt, nil
}
@@ -294,6 +299,7 @@
// DeleteFromDevice to delete meter from the device
func (vm *VoltMeter) DeleteFromDevice(port string, device string) {
+ logger.Debugw(ctx, "Delete meter from device", log.Fields{"Id": vm.ID, "Port": port, "Device": device})
meter := of.NewMeter(vm.ID)
logger.Debugw(ctx, "Delete meter from device", log.Fields{"Id": vm.ID, "meter": *meter})
@@ -304,6 +310,7 @@
// DelMeterProf to delete meter profile
func (va *VoltApplication) DelMeterProf(cntx context.Context, name string) error {
+ logger.Debugw(ctx, "Delete meter profile", log.Fields{"Name": name})
mm := &va.MeterMgr
if _, ok := mm.GetMeterByName(name); !ok {
logger.Warnw(ctx, "Meter profile does not exist", log.Fields{"Name": name})
diff --git a/internal/pkg/application/minor_upgrade.go b/internal/pkg/application/minor_upgrade.go
index 4d6b3d6..096d7b5 100644
--- a/internal/pkg/application/minor_upgrade.go
+++ b/internal/pkg/application/minor_upgrade.go
@@ -44,10 +44,10 @@
// UpdateDbData to update database data
func UpdateDbData(cntx context.Context, dbPath, hash string, value interface{}) error {
+ logger.Debugw(ctx, "Update Db Data", log.Fields{"DbPath": dbPath, "Hash": hash})
if migrationFunc, ok := updationMap[dbPath]; ok {
err := migrationFunc(cntx, hash, value)
if err != nil {
- logger.Error(ctx, "Error in migrating data\n")
return errors.New("Error-in-migration")
}
}
@@ -57,6 +57,7 @@
// This function modifyies the old data as per current version requirement and also
// returns the new path on which the modified data has to be written
func updateServices(cntx context.Context, hash string, value interface{}) error {
+ logger.Debugw(ctx, "Update Services", log.Fields{"Hash": hash})
param := value.(*VoltService)
param.VnetID = VnetKey(param.SVlan, param.CVlan, param.UniVlan)
return nil
@@ -65,6 +66,7 @@
// This function modifyies the old data as per current version requirement and also
// returns the new path on which the modified data has to be written
func updateVnets(cntx context.Context, hash string, value interface{}) error {
+ logger.Debugw(ctx, "Update Vnets", log.Fields{"Hash": hash})
param := value.(*VoltVnet)
newKey := VnetKey(param.SVlan, param.CVlan, param.UniVlan)
if newKey != hash {
@@ -86,6 +88,7 @@
// This function modifyies the old data as per current version requirement and also
// returns the new path on which the modified data has to be written
func updateVpvs(cntx context.Context, hash string, value interface{}) error {
+ logger.Debugw(ctx, "Update Vpvs", log.Fields{"Hash": hash})
//var param VoltPortVnet
param := value.(*VoltPortVnet)
@@ -110,6 +113,7 @@
}
func updateMvlans(cntx context.Context, hash string, value interface{}) error {
+ logger.Debugw(ctx, "Update Mvlans", log.Fields{"Hash": hash})
param := value.(*MvlanProfile)
if param.DevicesList == nil || len(param.DevicesList) == 0 {
param.DevicesList = make(map[string]OperInProgress) // Empty OLT serial number as of now since submgr won't have proper serial num
@@ -178,7 +182,7 @@
logger.Errorw(ctx, "Igmp Group Delete from DB failed", log.Fields{"Error": err, "key": key})
}
if err := UpdateDbData(cntx, database.IgmpDevicePath, key, igd); err != nil {
- logger.Warnw(ctx, "Group Device Migration failed", log.Fields{"IGD": igd, "Error": err})
+ logger.Errorw(ctx, "Group Device Migration failed", log.Fields{"IGD": igd, "Error": err})
} else {
logger.Infow(ctx, "Group Device Migrated", log.Fields{"IGD": igd})
}
diff --git a/internal/pkg/application/pppoeia.go b/internal/pkg/application/pppoeia.go
index 8b62760..6459d4c 100644
--- a/internal/pkg/application/pppoeia.go
+++ b/internal/pkg/application/pppoeia.go
@@ -100,6 +100,7 @@
// NewPppoeIaRelayVnet is constructor for a PppoeIa Relay Virtual network
func NewPppoeIaRelayVnet(outerVlan uint16, innerVlan uint16) *PppoeIaRelayVnet {
+ logger.Debugw(ctx, "NewPppoeIaRelayVnet", log.Fields{"OuterVlan": outerVlan, "innerVlan": innerVlan})
var drv PppoeIaRelayVnet
drv.OuterVlan = outerVlan
@@ -110,6 +111,7 @@
// AddPppoeIaRelayVnet add pppoeia relay vnet
func (dn *PppoeIaNetworks) AddPppoeIaRelayVnet(outerVlan uint16, innerVlan uint16) *PppoeIaRelayVnet {
+ logger.Debugw(ctx, "AddPppoeIaRelayVnet", log.Fields{"OuterVlan": outerVlan, "innerVlan": innerVlan})
comboVlan := uint32(outerVlan)<<16 + uint32(innerVlan)
if drv, ok := dn.Networks.Get(comboVlan); ok {
return drv.(*PppoeIaRelayVnet)
@@ -121,6 +123,7 @@
// NewPppoeIaNetworks is constructor for PppoeIa network
func NewPppoeIaNetworks() *PppoeIaNetworks {
+ logger.Info(ctx, "NewPppoeIaNetworks")
var dn PppoeIaNetworks
dn.Networks = util.NewConcurrentMap() //make(map[uint32]*PppoeIaRelayVnet)
return &dn
@@ -128,6 +131,7 @@
// AddPppoeIaSession to add pppoeia session
func (dn *PppoeIaNetworks) AddPppoeIaSession(pkt gopacket.Packet, session IPppoeIaSession) {
+ logger.Info(ctx, "AddPppoeIaSession")
var key [6]byte
ethl := pkt.Layer(layers.LayerTypeEthernet)
eth, _ := ethl.(*layers.Ethernet)
@@ -139,6 +143,7 @@
// DelPppoeIaSession to delete pppoeia session
func (dn *PppoeIaNetworks) DelPppoeIaSession(pkt gopacket.Packet, session IPppoeIaSession) {
+ logger.Info(ctx, "DelPppoeIaSession")
var key [6]byte
ethl := pkt.Layer(layers.LayerTypeEthernet)
eth, _ := ethl.(*layers.Ethernet)
@@ -154,6 +159,7 @@
// delPppoeIaSessions to delete pppoeia sessions
func delPppoeIaSessions(addr net.HardwareAddr, outervlan of.VlanType, innervlan of.VlanType) {
+ logger.Infow(ctx, "delPppoeIaSessions", log.Fields{"Addr": addr, "OuterVlan": outervlan, "innerVlan": innervlan})
var key [6]byte
if addr == nil || !NonZeroMacAddress(addr) {
logger.Warnw(ctx, "Invalid MAC address", log.Fields{"Addr": addr})
@@ -162,11 +168,12 @@
copy(key[:], addr[0:6])
drv := pppoeIaNws.AddPppoeIaRelayVnet(uint16(outervlan), uint16(innervlan))
drv.sessions.Remove(key)
- logger.Infow(ctx, "PppoeIa Sessions deleted", log.Fields{"MAC": addr})
+ logger.Debugw(ctx, "PppoeIa Sessions deleted", log.Fields{"MAC": addr})
}
// GetPppoeIaSession to get pppoeia sessions
func (dn *PppoeIaNetworks) GetPppoeIaSession(outerVlan uint16, innerVlan uint16, addr net.HardwareAddr) (IPppoeIaSession, error) {
+ logger.Debugw(ctx, "GetPppoeIaSession", log.Fields{"Addr": addr, "OuterVlan": outerVlan, "innerVlan": innerVlan})
var key [6]byte
if len(addr) != 6 {
logger.Errorw(ctx, "Invalid MAC address", log.Fields{"Addr": addr})
@@ -174,7 +181,7 @@
}
copy(key[:], addr[0:6])
drv := dn.AddPppoeIaRelayVnet(outerVlan, innerVlan)
- logger.Infow(ctx, "Key for PPPoE session", log.Fields{"Key": key})
+ logger.Debugw(ctx, "Key for PPPoE session", log.Fields{"Key": key})
if session, ok := drv.sessions.Get(key); ok {
return session.(IPppoeIaSession), nil
}
@@ -185,7 +192,7 @@
func GetVnetForNni(addr net.HardwareAddr, cvlan of.VlanType, svlan of.VlanType, pbit uint8) (*VoltPortVnet, error) {
var err error
var session IPppoeIaSession
- logger.Infow(ctx, "Mac Obtained MAC: ", log.Fields{"Addr": addr})
+ logger.Infow(ctx, "GetVnetForNni, Mac Obtained MAC: ", log.Fields{"Addr": addr})
if session, err = pppoeIaNws.GetPppoeIaSession(uint16(svlan), uint16(cvlan), addr); err != nil {
logger.Errorw(ctx, "PPPoE Session retrieval failed", log.Fields{"Error": err})
if err == ErrSessionDoNotExist {
@@ -219,6 +226,7 @@
var data []byte
cID := svc.GetCircuitID()
rID := svc.RemoteID
+ logger.Debugw(ctx, "AddIaOption", log.Fields{"cID": cID, "rID": rID})
if len(cID) != 0 || len(rID) != 0 || svc.isDataRateAttrPresent() {
data = append(data, DSLATTRVendorID...)
@@ -264,6 +272,7 @@
// DelIaOption for deletion of IA option from the packet received on the NNI interface.
func DelIaOption(pppoe *layers.PPPoE) {
+ logger.Info(ctx, "DelIaOption")
for index, option := range pppoe.Options {
if option.Type == layers.PPPoEOptVendorSpecific {
pppoe.Options = append(pppoe.Options[0:index], pppoe.Options[index+1:]...)
@@ -284,7 +293,7 @@
eth := pkt.Layer(layers.LayerTypeEthernet).(*layers.Ethernet)
pppoe := pkt.Layer(layers.LayerTypePPPoE).(*layers.PPPoE)
- logger.Infow(ctx, "Processing Southbound DS PppoeIa packet", log.Fields{"Port": port, "Type": pppoe.Code})
+ logger.Infow(ctx, "Processing Southbound DS PppoeIa packet", log.Fields{"Device": device, "Port": port, "Type": pppoe.Code})
// Retrieve the priority and drop eligible flags from the
// packet received
@@ -391,6 +400,7 @@
// ProcessUsPppoeIaPacket : The US PppoeIa packet is identified the PppoeIa OP in the packet. A request is considered upstream
// and the service associated with the packet is located by the port and VLANs in the packet
func (va *VoltApplication) ProcessUsPppoeIaPacket(cntx context.Context, device string, port string, pkt gopacket.Packet) {
+ logger.Infow(ctx, "Processing Southbound US PppoeIa packet", log.Fields{"Device": device, "Port": port})
// We received the packet on an access port and the service for the packet can be
// gotten from the port and the packet
vpv, svc := va.GetVnetFromPkt(device, port, pkt)
@@ -414,7 +424,7 @@
eth := pkt.Layer(layers.LayerTypeEthernet).(*layers.Ethernet)
pppoe := pkt.Layer(layers.LayerTypePPPoE).(*layers.PPPoE)
msgType := pppoe.Code
- logger.Infow(ctx, "Processing Southbound US PppoeIa packet", log.Fields{"Device": device, "Port": port, "Type": pppoe.Code})
+ logger.Debugw(ctx, "Processing Southbound US PppoeIa packet", log.Fields{"Device": device, "Port": port, "Type": pppoe.Code})
AddIaOption(svc, pppoe)
@@ -517,6 +527,7 @@
// ProcessPPPoEIaPacket to process Pppoeia packet
func (va *VoltApplication) ProcessPPPoEIaPacket(cntx context.Context, device string, port string, pkt gopacket.Packet) {
+ logger.Infow(ctx, "Processing PPPoEIa packet", log.Fields{"Device": device, "Port": port})
// Make some error checks before proceeding
pppoel := pkt.Layer(layers.LayerTypePPPoE)
if pppoel == nil {
@@ -548,6 +559,7 @@
// ProcessPPPoEPacket to process Pppoe packet
func (va *VoltApplication) ProcessPPPoEPacket(device string, port string, pkt gopacket.Packet) {
+ logger.Debugw(ctx, "Processing PPPoE packet", log.Fields{"Device": device, "Port": port})
dpt := NewPppoeIaPacketTask(pkt, device, port)
va.pppoeTasks.AddTask(dpt)
}
@@ -577,6 +589,7 @@
// NewPppoeIaPacketTask constructor for PppoeIaPacketTask
func NewPppoeIaPacketTask(pkt gopacket.Packet, dev string, port string) *PppoeIaPacketTask {
+ logger.Debugw(ctx, "New PPPoEIa packet", log.Fields{"Device": dev, "Port": port})
var dpt PppoeIaPacketTask
dpt.pkt = pkt
dpt.device = dev
@@ -606,6 +619,7 @@
// Start to start PppoeIaPacketTask
func (dpt *PppoeIaPacketTask) Start(ctx context.Context, taskID uint8) error {
+ logger.Debugw(ctx, "Start PPPoEIa task", log.Fields{"TaskID": taskID})
dpt.taskID = taskID
dpt.ctx = ctx
GetApplication().ProcessPPPoEIaPacket(ctx, dpt.device, dpt.port, dpt.pkt)
diff --git a/internal/pkg/application/service.go b/internal/pkg/application/service.go
index 532ff62..0ca2988 100644
--- a/internal/pkg/application/service.go
+++ b/internal/pkg/application/service.go
@@ -20,6 +20,7 @@
"context"
"encoding/json"
"errors"
+ "fmt"
"net"
"reflect"
"sort"
@@ -266,6 +267,7 @@
// IsPbitExist allows matching a service to a pbit. This is used
// to search for a service matching the pbit
func (vs *VoltService) IsPbitExist(pbit of.PbitType) bool {
+ logger.Debugw(ctx, "Request for IsPbitExist", log.Fields{"pbit": pbit})
for _, pb := range vs.Pbits {
if pb == pbit {
return true
@@ -276,6 +278,7 @@
// AddHsiaFlows - Adds US & DS HSIA Flows for the service
func (vs *VoltService) AddHsiaFlows(cntx context.Context) {
+ logger.Debugw(ctx, "Add US & DS HSIA Flows for the service", log.Fields{"ServiceName": vs.Name})
if err := vs.AddUsHsiaFlows(cntx); err != nil {
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
@@ -288,6 +291,7 @@
// DelHsiaFlows - Deletes US & DS HSIA Flows for the service
func (vs *VoltService) DelHsiaFlows(cntx context.Context) {
+ logger.Debugw(ctx, "Delete US & DS HSIA Flows for the service", log.Fields{"ServiceName": vs.Name})
if err := vs.DelUsHsiaFlows(cntx); err != nil {
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
@@ -300,15 +304,15 @@
}
func (vs *VoltService) AddMeterToDevice(cntx context.Context) error {
+ logger.Debugw(ctx, "Add Meter To Device for the service", log.Fields{"ServiceName": vs.Name})
if vs.DeleteInProgress || vs.UpdateInProgress {
- logger.Errorw(ctx, "Ignoring Meter Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
+ logger.Warnw(ctx, "Ignoring Meter Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
}
va := GetApplication()
logger.Infow(ctx, "Configuring Meters for FTTB", log.Fields{"ServiceName": vs.Name})
device, err := va.GetDeviceFromPort(vs.Port)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error()})
- return errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("Error during Getting Device from Port %s for service %s : %w", vs.Port, vs.Name, err)
} else if device.State != controller.DeviceStateUP {
logger.Warnw(ctx, "Device state Down. Ignoring Meter Push", log.Fields{"Service": vs.Name, "Port": vs.Port})
return nil
@@ -320,18 +324,17 @@
// AddUsHsiaFlows - Add US HSIA Flows for the service
func (vs *VoltService) AddUsHsiaFlows(cntx context.Context) error {
+ logger.Infow(ctx, "Configuring US HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
if vs.DeleteInProgress || vs.UpdateInProgress {
- logger.Errorw(ctx, "Ignoring US HSIA Flow Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
+ logger.Warnw(ctx, "Ignoring US HSIA Flow Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
return nil
}
va := GetApplication()
- logger.Infow(ctx, "Configuring US HSIA Service Flows", log.Fields{"ServiceName": vs.Name})
if !vs.UsHSIAFlowsApplied || vgcRebooted {
device, err := va.GetDeviceFromPort(vs.Port)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error()})
- return errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("Error Getting Device for Service %s and Port %s : %w", vs.Name, vs.Port, err)
} else if device.State != controller.DeviceStateUP {
logger.Warnw(ctx, "Device state Down. Ignoring US HSIA Flow Push", log.Fields{"Service": vs.Name, "Port": vs.Port})
return nil
@@ -343,7 +346,6 @@
va.AddMeterToDevice(vs.Port, device.Name, vs.UsMeterID, 0)
va.AddMeterToDevice(vs.Port, device.Name, vs.DsMeterID, vs.AggDsMeterID)
}
- logger.Infow(ctx, "Adding HSIA flows", log.Fields{"Name": vs.Name})
pBits := vs.Pbits
// If no pbits configured for service, hence add PbitNone for flows
@@ -353,20 +355,20 @@
for _, pbits := range pBits {
usflows, err := vs.BuildUsHsiaFlows(pbits)
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA US flows", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Error Building HSIA US flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
continue
}
usflows.MigrateCookie = vgcRebooted
if err := vs.AddFlows(cntx, device, usflows); err != nil {
- logger.Errorw(ctx, "Error adding HSIA US flows", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Error adding HSIA US flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
}
vs.UsHSIAFlowsApplied = true
- logger.Infow(ctx, "Pushed US HSIA Service Flows", log.Fields{"ServiceName": vs.Name})
+ logger.Debugw(ctx, "Pushed US HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
}
vs.WriteToDb(cntx)
return nil
@@ -374,36 +376,33 @@
// AddDsHsiaFlows - Add DS HSIA Flows for the service
func (vs *VoltService) AddDsHsiaFlows(cntx context.Context) error {
+ logger.Infow(ctx, "Configuring DS HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
if vs.DeleteInProgress {
- logger.Errorw(ctx, "Ignoring DS HSIA Flow Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
+ logger.Warnw(ctx, "Ignoring DS HSIA Flow Push, Service deleteion In-Progress", log.Fields{"Device": vs.Device, "Service": vs.Name})
return nil
}
va := GetApplication()
- logger.Infow(ctx, "Configuring DS HSIA Service Flows", log.Fields{"ServiceName": vs.Name})
if !vs.DsHSIAFlowsApplied || vgcRebooted {
device, err := va.GetDeviceFromPort(vs.Port)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error()})
- return errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("Error Getting Device for Service %s and Port %s : %w", vs.Name, vs.Port, err)
} else if device.State != controller.DeviceStateUP {
logger.Warnw(ctx, "Device state Down. Ignoring DS HSIA Flow Push", log.Fields{"Service": vs.Name, "Port": vs.Port})
return nil
}
va.AddMeterToDevice(vs.Port, device.Name, vs.DsMeterID, vs.AggDsMeterID)
- logger.Infow(ctx, "Adding HSIA flows", log.Fields{"Name": vs.Name})
//If no pbits configured for service, hence add PbitNone for flows
if len(vs.DsRemarkPbitsMap) == 0 {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(of.PbitMatchNone))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("Error Building HSIA DS flows for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
dsflows.MigrateCookie = vgcRebooted
if err = vs.AddFlows(cntx, device, dsflows); err != nil {
- logger.Errorw(ctx, "Failed to add HSIA DS flows", log.Fields{"Reason": err})
+ logger.Errorw(ctx, "Failed to add HSIA DS flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -412,13 +411,12 @@
if _, ok := vs.DsRemarkPbitsMap[int(of.PbitMatchAll)]; ok {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(of.PbitMatchAll))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("Error Building HSIA DS flows for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
logger.Debug(ctx, "Add-one-match-all-pbit-flow")
dsflows.MigrateCookie = vgcRebooted
if err := vs.AddFlows(cntx, device, dsflows); err != nil {
- logger.Errorw(ctx, "Failed to add HSIA DS flows", log.Fields{"Reason": err})
+ logger.Errorw(ctx, "Failed to add HSIA DS flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -426,14 +424,14 @@
for matchPbit := range vs.DsRemarkPbitsMap {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(matchPbit))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
continue
}
dsflows.MigrateCookie = vgcRebooted
if err := vs.AddFlows(cntx, device, dsflows); err != nil {
- logger.Errorw(ctx, "Failed to Add HSIA DS flows", log.Fields{"Reason": err})
+ logger.Errorw(ctx, "Failed to Add HSIA DS flows", log.Fields{"Device": vs.Device, "Service": vs.Name, "Reason": err})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -441,7 +439,7 @@
}
}
vs.DsHSIAFlowsApplied = true
- logger.Infow(ctx, "Pushed DS HSIA Service Flows", log.Fields{"ServiceName": vs.Name})
+ logger.Debugw(ctx, "Pushed DS HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
}
vs.WriteToDb(cntx)
return nil
@@ -449,15 +447,12 @@
// DelUsHsiaFlows - Deletes US HSIA Flows for the service
func (vs *VoltService) DelUsHsiaFlows(cntx context.Context) error {
- logger.Infow(ctx, "Removing US HSIA Services", log.Fields{"Services": vs.Name})
+ logger.Infow(ctx, "Removing US HSIA Services", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
if vs.UsHSIAFlowsApplied || vgcRebooted {
device, err := GetApplication().GetDeviceFromPort(vs.Port)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error()})
- return errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("Error Getting Device for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
-
- logger.Infow(ctx, "Removing HSIA flows", log.Fields{"Name": vs.Name})
pBits := vs.Pbits
// If no pbits configured for service, hence add PbitNone for flows
@@ -467,13 +462,14 @@
for _, pbits := range pBits {
usflows, err := vs.BuildUsHsiaFlows(pbits)
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA US flows", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Error Building HSIA US flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
continue
}
usflows.MigrateCookie = vgcRebooted
if err = vs.DelFlows(cntx, device, usflows); err != nil {
+ logger.Errorw(ctx, "Error Deleting HSIA US flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -486,36 +482,34 @@
// DelDsHsiaFlows - Deletes DS HSIA Flows for the service
func (vs *VoltService) DelDsHsiaFlows(cntx context.Context) error {
- logger.Infow(ctx, "Removing DS HSIA Services", log.Fields{"Services": vs.Name})
+ logger.Infow(ctx, "Removing DS HSIA Services", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
if vs.DsHSIAFlowsApplied || vgcRebooted {
device, err := GetApplication().GetDeviceFromPort(vs.Port)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error()})
- return errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("Error Getting Device for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
- logger.Infow(ctx, "Removing HSIA flows", log.Fields{"Name": vs.Name})
var matchPbit int
// If no pbits configured for service, hence add PbitNone for flows
if len(vs.DsRemarkPbitsMap) == 0 {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(PbitMatchNone))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("Error Building HSIA DS flows for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
dsflows.MigrateCookie = vgcRebooted
if err = vs.DelFlows(cntx, device, dsflows); err != nil {
+ logger.Errorw(ctx, "Error Deleting HSIA DS flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
} else if _, ok := vs.DsRemarkPbitsMap[int(PbitMatchAll)]; ok {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(int(PbitMatchAll)))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("Error Building HSIA DS flows for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
dsflows.MigrateCookie = vgcRebooted
if err = vs.DelFlows(cntx, device, dsflows); err != nil {
+ logger.Errorw(ctx, "Error Deleting HSIA DS flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -523,13 +517,14 @@
for matchPbit = range vs.DsRemarkPbitsMap {
dsflows, err := vs.BuildDsHsiaFlows(of.PbitType(matchPbit))
if err != nil {
- logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Error Building HSIA DS flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
continue
}
dsflows.MigrateCookie = vgcRebooted
if err = vs.DelFlows(cntx, device, dsflows); err != nil {
+ logger.Errorw(ctx, "Error Deleting HSIA DS flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name, "Reason": err.Error()})
statusCode, statusMessage := infraerrorCodes.GetErrorInfo(err)
vs.triggerServiceFailureInd(statusCode, statusMessage)
}
@@ -537,7 +532,7 @@
}
vs.DsHSIAFlowsApplied = false
}
- logger.Infow(ctx, "Deleted HSIA DS flows from DB successfully", log.Fields{"ServiceName": vs.Name})
+ logger.Infow(ctx, "Deleted HSIA DS flows from DB successfully", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
// Post HSIA configuration success indication on message bus
vs.WriteToDb(cntx)
return nil
@@ -546,13 +541,14 @@
// BuildDsHsiaFlows build the DS HSIA flows
// Called for add/delete HSIA flows
func (vs *VoltService) BuildDsHsiaFlows(pbits of.PbitType) (*of.VoltFlow, error) {
+ logger.Debugw(ctx, "Building DS HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
// Get the out and in ports for the flows
device, err := GetApplication().GetDeviceFromPort(vs.Port)
if err != nil {
- return nil, errorCodes.ErrDeviceNotFound
+ return nil, fmt.Errorf("Error Getting Device for Service %s and Port %s : %w", vs.Name, vs.Port, err)
}
inport, _ := GetApplication().GetPortID(device.NniPort)
outport, _ := GetApplication().GetPortID(vs.Port)
@@ -578,8 +574,7 @@
l2ProtoValue, err := GetMetadataForL2Protocol(vs.SVlanTpid)
if err != nil {
- logger.Errorw(ctx, "DS HSIA flow push failed: Invalid SvlanTpid", log.Fields{"SvlanTpid": vs.SVlanTpid, "Service": vs.Name})
- return nil, err
+ return nil, fmt.Errorf("DS HSIA flow push failed: Invalid SvlanTpid for Service %s and SvlanTpid %s : %w", vs.SVlanTpid, vs.Port, err)
}
// Add Table-0 flow that deals with the outer VLAN in pOLT
@@ -729,6 +724,7 @@
// BuildUsHsiaFlows build the US HSIA flows
// Called for add/delete HSIA flows
func (vs *VoltService) BuildUsHsiaFlows(pbits of.PbitType) (*of.VoltFlow, error) {
+ logger.Debugw(ctx, "Building US HSIA Service Flows", log.Fields{"Device": vs.Device, "ServiceName": vs.Name})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
@@ -838,6 +834,7 @@
func (vs *VoltService) generateUSCookie(vlan of.VlanType, valToShift uint64, inport uint32, pbits of.PbitType) uint64 {
// | 12-bit cvlan/UniVlan | 4 bits empty | <32-bits uniport>| 16-bits HSIA mask OR flow mask OR pbit |
+ logger.Debugw(ctx, "Generate US Cookie", log.Fields{"Vlan": vlan, "ValToShift": vlan, "Inport": inport, "Pbits": pbits})
cookie := uint64(vlan)<<52 + uint64(inport)<<16 | of.HsiaFlowMask
cookie = cookie | of.UsFlowMask
cookie = cookie + (valToShift << 4) + uint64(pbits)
@@ -847,6 +844,7 @@
// setUSMatchActionVlanT1 - Sets the Match & Action w.r.t Vlans for US Table-1
// based on different Vlan Controls
func (vs *VoltService) setUSMatchActionVlanT1(flow *of.VoltSubFlow) error {
+ logger.Debugw(ctx, "Set US Match Action Vlan T1", log.Fields{"Value": vs.VlanControl})
switch vs.VlanControl {
case None:
flow.SetMatchVlan(vs.SVlan)
@@ -870,8 +868,8 @@
flow.SetPushVlan(vs.SVlan, layers.EthernetTypeDot1Q)
}
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vs.VlanControl})
- return errorCodes.ErrInvalidParamInRequest
+ err := errorCodes.ErrInvalidParamInRequest
+ return fmt.Errorf("Invalid Vlan Control Option %d : %w", vs.VlanControl, err)
}
return nil
}
@@ -879,6 +877,7 @@
// setDSMatchActionVlanT0 - Sets the Match & Action w.r.t Vlans for DS Table-0
// based on different Vlan Controls
func (vs *VoltService) setDSMatchActionVlanT0(flow *of.VoltSubFlow) error {
+ logger.Debugw(ctx, "Set DS Match Action Vlan T0", log.Fields{"Value": vs.VlanControl})
switch vs.VlanControl {
case None:
flow.SetMatchVlan(vs.SVlan)
@@ -899,8 +898,8 @@
flow.SetPopVlan()
}
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vs.VlanControl})
- return errorCodes.ErrInvalidParamInRequest
+ err := errorCodes.ErrInvalidParamInRequest
+ return fmt.Errorf("Invalid Vlan Control Option %d : %w", vs.VlanControl, err)
}
return nil
}
@@ -908,6 +907,7 @@
// setUSMatchActionVlanT0 - Sets the Match & Action w.r.t Vlans for US Table-0
// based on different Vlan Controls
func (vs *VoltService) setUSMatchActionVlanT0(flow *of.VoltSubFlow) error {
+ logger.Debugw(ctx, "Set US Match Action Vlan T0", log.Fields{"Value": vs.VlanControl})
switch vs.VlanControl {
case None:
flow.SetMatchVlan(vs.SVlan)
@@ -930,8 +930,8 @@
case OLTSVlan:
flow.SetMatchVlan(vs.UniVlan)
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vs.VlanControl})
- return errorCodes.ErrInvalidParamInRequest
+ err := errorCodes.ErrInvalidParamInRequest
+ return fmt.Errorf("Invalid Vlan Control Option %d : %w", vs.VlanControl, err)
}
return nil
}
@@ -939,6 +939,7 @@
// setDSMatchActionVlanT1 - Sets the Match & Action w.r.t Vlans for DS Table-1
// based on different Vlan Controls
func (vs *VoltService) setDSMatchActionVlanT1(flow *of.VoltSubFlow) error {
+ logger.Debugw(ctx, "Set DS Match Action Vlan T1", log.Fields{"Value": vs.VlanControl})
switch vs.VlanControl {
case None:
flow.SetMatchVlan(vs.SVlan)
@@ -961,8 +962,8 @@
case OLTSVlan:
flow.SetMatchVlan(vs.UniVlan)
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vs.VlanControl})
- return errorCodes.ErrInvalidParamInRequest
+ err := errorCodes.ErrInvalidParamInRequest
+ return fmt.Errorf("Invalid Vlan Control Option %d : %w", vs.VlanControl, err)
}
return nil
}
@@ -1007,6 +1008,7 @@
// unique L2 (MAC address + VLANs) or unique L3 (VLANs + IP address)
// FUNC: Add Service
func (va *VoltApplication) AddService(cntx context.Context, cfg VoltServiceCfg, oper *VoltServiceOper) error {
+ logger.Infow(ctx, "Service to be configured", log.Fields{"Cfg": cfg})
var mmUs, mmDs *VoltMeter
var err error
@@ -1017,11 +1019,10 @@
if oper == nil {
if svc := va.GetService(cfg.Name); svc != nil {
logger.Warnw(ctx, "Service Already Exists. Ignoring Add Service Request", log.Fields{"Name": cfg.Name})
- return errors.New("Service Already Exists")
+ return errors.New("service already exists")
}
}
- logger.Infow(ctx, "Service to be configured", log.Fields{"Cfg": cfg})
// Service doesn't exist. So create it and add to the port
vs := NewVoltService(&cfg)
if oper != nil {
@@ -1049,7 +1050,7 @@
if mmDs, err = va.GetMeter(cfg.DsMeterProfile); err == nil {
vs.DsMeterID = mmDs.ID
} else {
- return errors.New("DownStream meter profile not found")
+ return errors.New("downStream meter profile not found")
}
// The aggregated downstream meter profile
@@ -1066,7 +1067,7 @@
if mmUs, err = va.GetMeter(cfg.UsMeterProfile); err == nil {
vs.UsMeterID = mmUs.ID
} else {
- return errors.New("Upstream meter profile not found")
+ return errors.New("upstream meter profile not found")
}
//}
@@ -1084,8 +1085,8 @@
va.AddVnetToPort(cntx, vs.Port, vnet, vs)
}
} else {
- logger.Errorw(ctx, "VNET-does-not-exist-for-service", log.Fields{"ServiceName": cfg.Name})
- return errors.New("VNET doesn't exist")
+ logger.Warnw(ctx, "VNET-does-not-exist-for-service", log.Fields{"ServiceName": cfg.Name})
+ return errors.New("vnet doesn't exist")
}
// If the device is already discovered, update the device name in service
@@ -1116,13 +1117,14 @@
logger.Debugw(ctx, "northbound-service-add-successful", log.Fields{"ServiceName": vs.Name})
}
- logger.Warnw(ctx, "Added Service to DB", log.Fields{"Name": vs.Name, "Port": (vs.Port), "ML": vs.MacLearning})
+ logger.Debugw(ctx, "Added Service to DB", log.Fields{"Name": vs.Name, "Port": (vs.Port), "ML": vs.MacLearning})
return nil
}
// DelServiceWithPrefix - Deletes service with the provided prefix.
// Added for DT/TT usecase with sadis replica interface
func (va *VoltApplication) DelServiceWithPrefix(cntx context.Context, prefix string) error {
+ logger.Infow(ctx, "Delete Service With provided Prefix", log.Fields{"Prefix": prefix})
var isServiceExist bool
va.ServiceByName.Range(func(key, value interface{}) bool {
srvName := key.(string)
@@ -1153,7 +1155,7 @@
AppMutex.ServiceDataMutex.Lock()
defer AppMutex.ServiceDataMutex.Unlock()
- logger.Warnw(ctx, "Delete Service Request", log.Fields{"Service": name, "ForceDelete": forceDelete, "serviceMigration": serviceMigration})
+ logger.Infow(ctx, "Delete Service Request", log.Fields{"Service": name, "ForceDelete": forceDelete, "serviceMigration": serviceMigration})
var noFlowsPresent bool
vsIntf, ok := va.ServiceByName.Load(name)
@@ -1164,7 +1166,7 @@
vs := vsIntf.(*VoltService)
vpv := va.GetVnetByPort(vs.Port, vs.SVlan, vs.CVlan, vs.UniVlan)
if vpv == nil {
- logger.Errorw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name})
+ logger.Warnw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name})
return
}
@@ -1196,7 +1198,7 @@
if vs.ForceDelete {
vs.DelFromDb(cntx)
GetApplication().ServiceByName.Delete(vs.Name)
- logger.Warnw(ctx, "Deleted service from DB/Cache successfully", log.Fields{"serviceName": vs.Name})
+ logger.Debugw(ctx, "Deleted service from DB/Cache successfully", log.Fields{"serviceName": vs.Name})
}
if nil != newSvc {
@@ -1254,6 +1256,7 @@
// race condition during flow response indication processing
vs.ServiceLock.Lock()
defer vs.ServiceLock.Unlock()
+ logger.Debugw(ctx, "Adds the flow to the service", log.Fields{"Port": vs.Port, "Device": device.Name})
for cookie := range flow.SubFlows {
cookie := strconv.FormatUint(cookie, 10)
@@ -1272,6 +1275,7 @@
// FlowInstallSuccess - Called when corresponding service flow installation is success
// If no more pending flows, HSIA indication wil be triggered
func (vs *VoltService) FlowInstallSuccess(cntx context.Context, cookie string, bwAvailInfo of.BwAvailDetails) {
+ logger.Debugw(ctx, "Flow Add Success Notification", log.Fields{"Cookie": cookie, "bwAvailInfo": bwAvailInfo, "Service": vs.Name})
if vs.DeleteInProgress {
logger.Warnw(ctx, "Skipping Flow Add Success Notification. Service deletion in-progress", log.Fields{"Cookie": cookie, "Service": vs.Name})
return
@@ -1279,7 +1283,7 @@
vs.ServiceLock.Lock()
if _, ok := vs.PendingFlows[cookie]; !ok {
- logger.Errorw(ctx, "Flow Add Success for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie})
+ logger.Warnw(ctx, "Flow Add Success for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie})
vs.ServiceLock.Unlock()
return
}
@@ -1321,19 +1325,21 @@
func (vs *VoltService) FlowInstallFailure(cookie string, errorCode uint32, errReason string) {
vs.ServiceLock.RLock()
+ logger.Debugw(ctx, "Service flow installation failure", log.Fields{"Service": vs.Name, "Cookie": cookie, "errorCode": errorCode, "errReason": errReason})
if _, ok := vs.PendingFlows[cookie]; !ok {
logger.Errorw(ctx, "Flow Add Failure for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie})
vs.ServiceLock.RUnlock()
return
}
vs.ServiceLock.RUnlock()
- logger.Errorw(ctx, "HSIA Flow Add Failure Notification", log.Fields{"uniPort": vs.Port, "Cookie": cookie, "Service": vs.Name, "ErrorCode": errorCode, "ErrorReason": errReason})
+ logger.Debugw(ctx, "HSIA Flow Add Failure Notification", log.Fields{"uniPort": vs.Port, "Cookie": cookie, "Service": vs.Name, "ErrorCode": errorCode, "ErrorReason": errReason})
vs.triggerServiceFailureInd(errorCode, errReason)
}
// DelFlows - Deletes the flow from the service
// Triggers flow deletion after registering for flow indication event
func (vs *VoltService) DelFlows(cntx context.Context, device *VoltDevice, flow *of.VoltFlow) error {
+ logger.Debugw(ctx, "Delete the flow from the service", log.Fields{"Port": vs.Port, "Device": device.Name})
if !vs.ForceDelete {
// Using locks instead of concurrent map for AssociatedFlows to avoid
// race condition during flow response indication processing
@@ -1355,10 +1361,11 @@
// CheckAndDeleteService - remove service from DB is there are no pending flows to be removed
func (vs *VoltService) CheckAndDeleteService(cntx context.Context) {
+ logger.Debugw(ctx, "Delete service from DB/Cache", log.Fields{"serviceName": vs.Name})
if vs.DeleteInProgress && len(vs.AssociatedFlows) == 0 && !vs.DsHSIAFlowsApplied {
vs.DelFromDb(cntx)
GetApplication().ServiceByName.Delete(vs.Name)
- logger.Warnw(ctx, "Deleted service from DB/Cache successfully", log.Fields{"serviceName": vs.Name})
+ logger.Debugw(ctx, "Deleted service from DB/Cache successfully", log.Fields{"serviceName": vs.Name})
}
}
@@ -1375,9 +1382,9 @@
if _, ok := vs.AssociatedFlows[cookie]; ok {
delete(vs.AssociatedFlows, cookie)
} else if _, ok := vs.PendingFlows[cookie]; ok {
- logger.Errorw(ctx, "Service Flow Remove: Cookie Present in Pending Flow list. No Action", log.Fields{"Service": vs.Name, "Cookie": cookie, "AssociatedFlows": vs.AssociatedFlows, "PendingFlows": vs.PendingFlows})
+ logger.Debugw(ctx, "Service Flow Remove: Cookie Present in Pending Flow list. No Action", log.Fields{"Service": vs.Name, "Cookie": cookie, "AssociatedFlows": vs.AssociatedFlows, "PendingFlows": vs.PendingFlows})
} else {
- logger.Errorw(ctx, "Service Flow Remove Success for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie, "AssociatedFlows": vs.AssociatedFlows, "PendingFlows": vs.PendingFlows})
+ logger.Debugw(ctx, "Service Flow Remove Success for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie, "AssociatedFlows": vs.AssociatedFlows, "PendingFlows": vs.PendingFlows})
}
vs.ServiceLock.Unlock()
@@ -1411,9 +1418,10 @@
// Trigger service failure indication to NB
func (vs *VoltService) FlowRemoveFailure(cntx context.Context, cookie string, errorCode uint32, errReason string) {
vs.ServiceLock.RLock()
+ logger.Debugw(ctx, "Processing Service Flow Remove Failure Indication", log.Fields{"Cookie": cookie, "Service": vs.Name, "Associated Flows": vs.AssociatedFlows, "DsFlowsApplied": vs.DsHSIAFlowsApplied})
if _, ok := vs.AssociatedFlows[cookie]; !ok {
- logger.Errorw(ctx, "Flow Failure for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie})
+ logger.Warnw(ctx, "Flow Failure for unknown Cookie", log.Fields{"Service": vs.Name, "Cookie": cookie})
vs.ServiceLock.RUnlock()
return
}
@@ -1421,13 +1429,14 @@
delete(vs.AssociatedFlows, cookie)
}
vs.ServiceLock.RUnlock()
- logger.Errorw(ctx, "Service Flow Remove Failure Notification", log.Fields{"uniPort": vs.Port, "Cookie": cookie, "Service": vs.Name, "ErrorCode": errorCode, "ErrorReason": errReason})
+ logger.Debugw(ctx, "Service Flow Remove Failure Notification", log.Fields{"uniPort": vs.Port, "Cookie": cookie, "Service": vs.Name, "ErrorCode": errorCode, "ErrorReason": errReason})
vs.triggerServiceFailureInd(errorCode, errReason)
vs.CheckAndDeleteService(cntx)
}
func (vs *VoltService) triggerServiceFailureInd(errorCode uint32, errReason string) {
+ logger.Debugw(ctx, "Trigger Service Failure Ind", log.Fields{"Service": vs.Name, "Port": vs.Port})
device, err := GetApplication().GetDeviceFromPort(vs.Port)
if err != nil {
logger.Errorw(ctx, "Error Getting Device. Dropping DEL_HSIA Failure indication to NB", log.Fields{"Reason": err.Error(), "Service": vs.Name, "Port": vs.Port})
@@ -1441,6 +1450,7 @@
// RestoreSvcsFromDb read from the DB and restore all the services
func (va *VoltApplication) RestoreSvcsFromDb(cntx context.Context) {
// VNETS must be learnt first
+ logger.Debug(ctx, "Restore Svcs From Db")
vss, _ := db.GetServices(cntx)
for _, vs := range vss {
b, ok := vs.Value.([]byte)
@@ -1501,6 +1511,7 @@
// GetServiceNameFromCookie to get service name from cookie
func (va *VoltApplication) GetServiceNameFromCookie(cookie uint64, portName string, pbit uint8, device string, tableMetadata uint64) *VoltService {
+ logger.Debugw(ctx, "Get Service Name From Cookie", log.Fields{"Cookie": cookie, "PortName": portName, "Pbit": pbit, "Device": device, "TableMetadata": tableMetadata})
var vlan uint64
vlanControl := (tableMetadata >> 32) & 0xF
@@ -1511,14 +1522,14 @@
// Fetching CVlan for other vlanControl
vlan = cookie >> 52
}
- logger.Infow(ctx, "Configured Params", log.Fields{"VlanControl": vlanControl, "vlan": vlan})
+ logger.Debugw(ctx, "Configured Params", log.Fields{"VlanControl": vlanControl, "vlan": vlan})
var vlans []of.VlanType
vlans = append(vlans, of.VlanType(vlan))
service := GetApplication().GetServiceFromCvlan(device, portName, vlans, uint8(pbit))
if nil != service {
logger.Infow(ctx, "Service Found for", log.Fields{"serviceName": service.Name, "portName": portName, "ctag": vlan})
} else {
- logger.Errorw(ctx, "No Service for", log.Fields{"portName": portName, "ctag": vlan, "Pbit": pbit, "device": device, "VlanControl": vlanControl})
+ logger.Warnw(ctx, "No Service for", log.Fields{"portName": portName, "ctag": vlan, "Pbit": pbit, "device": device, "VlanControl": vlanControl})
}
return service
}
@@ -1583,12 +1594,12 @@
// MigrateServices - updated vnet profile for services
func (va *VoltApplication) MigrateServices(cntx context.Context, serialNum string, reqID string, oldVnetID, newVnetID string, serviceList []string) error {
- logger.Warnw(ctx, "Migrate Serviec Request Received", log.Fields{"SerialNum": serialNum, "RequestID": reqID, "OldVnet": oldVnetID, "NewVnet": newVnetID, "ServiceList": serviceList})
+ logger.Debugw(ctx, "Migrate Serviec Request Received", log.Fields{"SerialNum": serialNum, "RequestID": reqID, "OldVnet": oldVnetID, "NewVnet": newVnetID, "ServiceList": serviceList})
if _, ok := va.VnetsByName.Load(oldVnetID); !ok {
- return errors.New("Old Vnet Id not found")
+ return errors.New("old vnet id not found")
}
if _, ok := va.VnetsByName.Load(newVnetID); !ok {
- return errors.New("New Vnet Id not found")
+ return errors.New("new vnet id not found")
}
d, _ := va.GetDeviceBySerialNo(serialNum)
@@ -1612,6 +1623,7 @@
// ProcessMigrateServicesProfRequest - collects all associated profiles
func (msr *MigrateServicesRequest) ProcessMigrateServicesProfRequest(cntx context.Context) {
+ logger.Debug(ctx, "Process Migrate Services Prof Request")
va := GetApplication()
for srv, processed := range msr.ServicesList {
// Indicates new service is already created and only deletion of old one is pending
@@ -1626,7 +1638,7 @@
vs := vsIntf.(*VoltService)
vpv := va.GetVnetByPort(vs.Port, vs.SVlan, vs.CVlan, vs.UniVlan)
if vpv == nil {
- logger.Errorw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name, "port": vs.Port, "Vnet": vs.VnetID})
+ logger.Warnw(ctx, "Vpv Not found for Service", log.Fields{"vs": vs.Name, "port": vs.Port, "Vnet": vs.VnetID})
continue
}
logger.Infow(ctx, "Migrating Service", log.Fields{"Service": vs.Name, "UsFlowApplied": vs.UsHSIAFlowsApplied})
@@ -1660,6 +1672,7 @@
// AddMigratingServices - store msr info to device obj
func (d *VoltDevice) AddMigratingServices(msr *MigrateServicesRequest) {
+ logger.Infow(ctx, "Add Migrating Services", log.Fields{"Vnet": msr.OldVnetID})
var msrMap *util.ConcurrentMap
if msrMapIntf, ok := d.MigratingServices.Get(msr.OldVnetID); !ok {
msrMap = util.NewConcurrentMap()
@@ -1668,30 +1681,32 @@
}
msrMap.Set(msr.ID, msr)
- logger.Infow(ctx, "1: MsrListLen", log.Fields{"Len": msrMap.Length(), "Vnet": msr.OldVnetID})
+ logger.Debugw(ctx, "1: MsrListLen", log.Fields{"Len": msrMap.Length(), "Vnet": msr.OldVnetID})
d.MigratingServices.Set(msr.OldVnetID, msrMap)
- logger.Infow(ctx, "1: DeviceMsr", log.Fields{"Device": d.Name, "Vnet": msr.OldVnetID, "Len": d.MigratingServices.Length()})
+ logger.Debugw(ctx, "1: DeviceMsr", log.Fields{"Device": d.Name, "Vnet": msr.OldVnetID, "Len": d.MigratingServices.Length()})
}
// getMigrateServicesRequest - fetches msr info from device
func (va *VoltApplication) getMigrateServicesRequest(deviceID string, oldVnetID string, requestID string) *MigrateServicesRequest {
+ logger.Debugw(ctx, "Get Migrate Services Request", log.Fields{"DeviceID": deviceID, "OldVnetID": oldVnetID, "RequestID": requestID})
if vd := va.GetDevice(deviceID); vd != nil {
- logger.Infow(ctx, "2: DeviceMsr", log.Fields{"Device": deviceID, "Vnet": oldVnetID, "Len": vd.MigratingServices.Length()})
+ logger.Debugw(ctx, "2: DeviceMsr", log.Fields{"Device": deviceID, "Vnet": oldVnetID, "Len": vd.MigratingServices.Length()})
if msrListIntf, ok := vd.MigratingServices.Get(oldVnetID); ok {
msrList := msrListIntf.(*util.ConcurrentMap)
- logger.Infow(ctx, "2: MsrListLen", log.Fields{"Len": msrList.Length(), "Vnet": oldVnetID})
+ logger.Debugw(ctx, "2: MsrListLen", log.Fields{"Len": msrList.Length(), "Vnet": oldVnetID})
if msrObj, ok := msrList.Get(requestID); ok {
return msrObj.(*MigrateServicesRequest)
}
}
}
- logger.Errorw(ctx, "Device Not Found", log.Fields{"Device": deviceID})
+ logger.Warnw(ctx, "Device Not Found", log.Fields{"DeviceID": deviceID})
return nil
}
// updateMigrateServicesRequest - Updates the device with updated msr
func (va *VoltApplication) updateMigrateServicesRequest(deviceID string, oldVnetID string, requestID string, msr *MigrateServicesRequest) {
+ logger.Debugw(ctx, "Update Migrate Services Request", log.Fields{"DeviceID": deviceID, "OldVnetID": oldVnetID, "RequestID": requestID})
if vd := va.GetDevice(deviceID); vd != nil {
if msrList, ok := vd.MigratingServices.Get(oldVnetID); ok {
if _, ok := msrList.(*util.ConcurrentMap).Get(requestID); ok {
@@ -1738,7 +1753,7 @@
oldSrvName := vs.Name
if metadata == nil || metadata.NewVnetID == "" {
- logger.Errorw(ctx, "Migrate Service Metadata not found. Dropping vnet profile update request", log.Fields{"Service": vs.Name, "Vnet": vs.VnetID})
+ logger.Warnw(ctx, "Migrate Service Metadata not found. Dropping vnet profile update request", log.Fields{"Service": vs.Name, "Vnet": vs.VnetID})
return
}
@@ -1761,7 +1776,7 @@
nvs.Name = svcName + strconv.FormatUint(uint64(vs.TechProfileID), 10)
// TODO:Nav Pass a copy, not the pointer
- logger.Infow(ctx, "Add New Service Triggering", log.Fields{"Service": nvs.Name, "US": nvs.UsHSIAFlowsApplied, "DS": nvs.DsHSIAFlowsApplied, "DelFlag": nvs.DeleteInProgress})
+ logger.Debugw(ctx, "Add New Service Triggering", log.Fields{"Service": nvs.Name, "US": nvs.UsHSIAFlowsApplied, "DS": nvs.DsHSIAFlowsApplied, "DelFlag": nvs.DeleteInProgress})
if err := va.AddService(cntx, nvs.VoltServiceCfg, &nvs.VoltServiceOper); err != nil {
logger.Warnw(ctx, "Add New Service Failed", log.Fields{"Service": nvs.Name, "Error": err})
}
@@ -1771,15 +1786,16 @@
va.updateMigrateServicesRequest(deviceID, oldVnetID, id, msr)
msr.WriteToDB(cntx)
- logger.Infow(ctx, "Del Old Service Triggering", log.Fields{"Service": oldSrvName, "US": vs.UsHSIAFlowsApplied, "DS": vs.DsHSIAFlowsApplied, "DelFlag": vs.DeleteInProgress})
+ logger.Debugw(ctx, "Del Old Service Triggering", log.Fields{"Service": oldSrvName, "US": vs.UsHSIAFlowsApplied, "DS": vs.DsHSIAFlowsApplied, "DelFlag": vs.DeleteInProgress})
va.DelService(cntx, oldSrvName, true, nil, true)
- logger.Infow(ctx, "Del Old Service Triggered", log.Fields{"Service": oldSrvName, "US": vs.UsHSIAFlowsApplied, "DS": vs.DsHSIAFlowsApplied, "DelFlag": vs.DeleteInProgress})
+ logger.Debugw(ctx, "Del Old Service Triggered", log.Fields{"Service": oldSrvName, "US": vs.UsHSIAFlowsApplied, "DS": vs.DsHSIAFlowsApplied, "DelFlag": vs.DeleteInProgress})
msr.serviceMigrated(cntx, oldSrvName)
}
// serviceMigrated - called on successful service updation
// Removes the service entry from servicelist and deletes the request on process completion
func (msr *MigrateServicesRequest) serviceMigrated(cntx context.Context, serviceName string) {
+ logger.Infow(ctx, "Service Migrated", log.Fields{"ServiceName": serviceName})
msr.MigrateServicesLock.Lock()
defer msr.MigrateServicesLock.Unlock()
@@ -1800,6 +1816,7 @@
// FetchAndProcessAllMigrateServicesReq - fetch all pending migrate services req from DB and process based on provided func
func (va *VoltApplication) FetchAndProcessAllMigrateServicesReq(cntx context.Context, device string, msrAction func(context.Context, *MigrateServicesRequest)) {
+ logger.Infow(ctx, "Fetch all pending migrate services req from DB and process based on provided func", log.Fields{"Device": device})
msrList, _ := db.GetAllMigrateServicesReq(cntx, device)
for _, msr := range msrList {
b, ok := msr.Value.([]byte)
@@ -1809,12 +1826,13 @@
}
msr := va.createMigrateServicesFromString(b)
msrAction(cntx, msr)
- logger.Warnw(ctx, "Triggering Pending Migrate Services Req", log.Fields{"OldVnet": msr.OldVnetID, "NewVnet": msr.NewVnetID, "Device": device, "PendingProfiles": len(msr.ServicesList)})
+ logger.Debugw(ctx, "Triggering Pending Migrate Services Req", log.Fields{"OldVnet": msr.OldVnetID, "NewVnet": msr.NewVnetID, "Device": device, "PendingProfiles": len(msr.ServicesList)})
}
}
// createMigrateServicesFromString to create Service from string
func (va *VoltApplication) createMigrateServicesFromString(b []byte) *MigrateServicesRequest {
+ logger.Info(ctx, "Create Migrate Services From String")
var msr MigrateServicesRequest
if err := json.Unmarshal(b, &msr); err == nil {
logger.Debugw(ctx, "Adding Migrate Services Request From Db", log.Fields{"Vlan": msr.OldVnetID})
@@ -1826,6 +1844,7 @@
// storeAndProcessMigrateSrvRequest - stores the msr info in device obj and triggers req
func storeAndProcessMigrateSrvRequest(cntx context.Context, msr *MigrateServicesRequest) {
+ logger.Infow(ctx, "Store And Process Migrate Srv Request", log.Fields{"MsrID": msr.DeviceID})
d := GetApplication().GetDevice(msr.DeviceID)
d.AddMigratingServices(msr)
msr.ProcessMigrateServicesProfRequest(cntx)
@@ -1833,6 +1852,7 @@
// forceUpdateAllServices - force udpate services with new vnet profile
func forceUpdateAllServices(cntx context.Context, msr *MigrateServicesRequest) {
+ logger.Infow(ctx, "Force udpate services with new vnet profile", log.Fields{"MsrID": msr.NewVnetID})
for srv := range msr.ServicesList {
if vsIntf, ok := GetApplication().ServiceByName.Load(srv); ok {
vsIntf.(*VoltService).updateVnetProfile(cntx, msr.DeviceID)
@@ -1945,15 +1965,16 @@
func (vs *VoltService) TriggerAssociatedFlowDelete(cntx context.Context) bool {
// Clear the Flows flag if already set
// This case happens only in case of some race condition
+ logger.Infow(ctx, "Trigger Associated Flow Delete", log.Fields{"Device": vs.Device, "Service": vs.Name})
if vs.UsHSIAFlowsApplied {
if err := vs.DelUsHsiaFlows(cntx); err != nil {
- logger.Errorw(ctx, "DelUsHsiaFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Error": err})
+ logger.Warnw(ctx, "DelUsHsiaFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Error": err})
}
}
if vs.DsHSIAFlowsApplied {
if err := vs.DelDsHsiaFlows(cntx); err != nil {
- logger.Errorw(ctx, "DelDsHsiaFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Error": err})
+ logger.Warnw(ctx, "DelDsHsiaFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Error": err})
}
}
@@ -1978,7 +1999,7 @@
flow.SubFlows[cookie] = subFlow
logger.Infow(ctx, "Retriggering Service Delete Flow", log.Fields{"Device": vs.Device, "Service": vs.Name, "Cookie": cookie})
if err := vs.DelFlows(cntx, vd, flow); err != nil {
- logger.Errorw(ctx, "DelFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Cookie": cookie, "Error": err})
+ logger.Warnw(ctx, "DelFlows Failed", log.Fields{"Device": vs.Device, "Service": vs.Name, "Cookie": cookie, "Error": err})
}
}
}
@@ -2084,24 +2105,23 @@
// ActivateService to activate pre-provisioned service
func (va *VoltApplication) ActivateService(cntx context.Context, deviceID, portNo string, sVlan, cVlan of.VlanType, tpID uint16) error {
var isParmsInvalid bool
- logger.Infow(ctx, "Service Activate Request ", log.Fields{"Device": deviceID, "Port": portNo})
+ logger.Infow(ctx, "Service Activate Request ", log.Fields{"Device": deviceID, "Port": portNo, "Svaln": sVlan, "Cvlan": cVlan, "TpID": tpID})
device, err := va.GetDeviceFromPort(portNo)
if err != nil {
- logger.Errorw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error(), "Port": portNo})
- return errorCodes.ErrPortNotFound
+ return fmt.Errorf("error getting device for portNo %s : %w", portNo, err)
}
// If device id is not provided check only port number
if deviceID == DeviceAny {
deviceID = device.Name
} else if deviceID != device.Name {
- logger.Errorw(ctx, "Wrong Device ID", log.Fields{"Device": deviceID, "Port": portNo})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("wrong device id %s : %w", deviceID, err)
}
va.ServiceByName.Range(func(key, value interface{}) bool {
vs := value.(*VoltService)
// If svlan if provided, then the tags and tpID of service has to be matching
if sVlan != of.VlanNone && (sVlan != vs.SVlan || cVlan != vs.CVlan || tpID != vs.TechProfileID) {
- logger.Infow(ctx, "Service Activate Request Does not match", log.Fields{"Device": deviceID, "voltService": vs})
+ logger.Warnw(ctx, "Service Activate Request Does not match", log.Fields{"Device": deviceID, "voltService": vs})
isParmsInvalid = true
return true
}
@@ -2112,7 +2132,7 @@
logger.Warnw(ctx, "Wrong device or port", log.Fields{"Device": deviceID, "Port": portNo})
return true
}
- logger.Infow(ctx, "Service Activate", log.Fields{"Name": vs.Name})
+ logger.Debugw(ctx, "Service Activate", log.Fields{"Name": vs.Name})
vs.IsActivated = true
va.ServiceByName.Store(vs.Name, vs)
vs.WriteToDb(cntx)
@@ -2137,16 +2157,16 @@
// DeactivateService to activate pre-provisioned service
func (va *VoltApplication) DeactivateService(cntx context.Context, deviceID, portNo string, sVlan, cVlan of.VlanType, tpID uint16) error {
- logger.Infow(ctx, "Service Deactivate Request ", log.Fields{"Device": deviceID, "Port": portNo})
+ logger.Infow(ctx, "Service Deactivate Request ", log.Fields{"Device": deviceID, "Port": portNo, "Svaln": sVlan, "Cvlan": cVlan, "TpID": tpID})
var isServiceExist bool
var isParmsInvalid bool
va.ServiceByName.Range(func(key, value interface{}) bool {
vs := value.(*VoltService)
// If svlan if provided, then the tags and tpID of service has to be matching
- logger.Infow(ctx, "Service Deactivate Request ", log.Fields{"Device": deviceID, "Port": portNo})
+ logger.Debugw(ctx, "Service Deactivate Request ", log.Fields{"Device": deviceID, "Port": portNo})
if sVlan != of.VlanNone && (sVlan != vs.SVlan || cVlan != vs.CVlan || tpID != vs.TechProfileID) {
- logger.Infow(ctx, "condition not matched", log.Fields{"Device": deviceID, "Port": portNo, "sVlan": sVlan, "cVlan": cVlan, "tpID": tpID})
+ logger.Warnw(ctx, "condition not matched", log.Fields{"Device": deviceID, "Port": portNo, "sVlan": sVlan, "cVlan": cVlan, "tpID": tpID})
isParmsInvalid = true
return true
}
@@ -2161,7 +2181,7 @@
if err != nil {
// Even if the port/device does not exists at this point in time, the deactivate request is succss.
// So no error is returned
- logger.Infow(ctx, "Error Getting Device", log.Fields{"Reason": err.Error(), "Port": portNo})
+ logger.Warnw(ctx, "Error Getting Device", log.Fields{"Reason": err.Error(), "Port": portNo})
return true
}
p := device.GetPort(vs.Port)
diff --git a/internal/pkg/application/timer.go b/internal/pkg/application/timer.go
index 167f8ae..42b16d8 100644
--- a/internal/pkg/application/timer.go
+++ b/internal/pkg/application/timer.go
@@ -18,6 +18,7 @@
import (
"context"
"time"
+ "voltha-go-controller/log"
)
// TimerType - type of timer used
@@ -42,6 +43,7 @@
// Start to start timer
func (va *VoltApplication) Start(cntx context.Context, cfg TimerCfg, timerType TimerType) {
+ logger.Infow(ctx, " Timer Starts", log.Fields{"Duration ": cfg})
if timerMap[timerType] {
logger.Warn(ctx, "Duplicate Timer!!! Timer already running")
return
diff --git a/internal/pkg/application/util.go b/internal/pkg/application/util.go
index f157bf9..0fb5313 100644
--- a/internal/pkg/application/util.go
+++ b/internal/pkg/application/util.go
@@ -18,6 +18,7 @@
import (
"errors"
"strconv"
+ "voltha-go-controller/log"
"github.com/google/gopacket/layers"
)
@@ -35,6 +36,7 @@
// GetMetadataForL2Protocol - returns metadata value for provide ethertype
func GetMetadataForL2Protocol(etherType layers.EthernetType) (uint8, error) {
+ logger.Debugw(ctx, " GetMetadataForL2Protocol", log.Fields{"EtherType ": etherType})
switch etherType {
case layers.EthernetTypeDot1Q:
return EtherType8100, nil
diff --git a/internal/pkg/application/vnets.go b/internal/pkg/application/vnets.go
index 2a9d4b2..df89c68 100644
--- a/internal/pkg/application/vnets.go
+++ b/internal/pkg/application/vnets.go
@@ -19,6 +19,7 @@
"context"
"encoding/json"
"errors"
+ "fmt"
"net"
"reflect"
"strconv"
@@ -181,15 +182,16 @@
// disassociatePortFromVnet - disassociate a port from Vnet and return true if the association map is empty
func (vv *VoltVnet) disassociatePortFromVnet(cntx context.Context, device string, port string) {
+ logger.Infow(ctx, "Disassociate Port from Vnet", log.Fields{"Device": device, "Port": port})
vv.VnetPortLock.Lock()
delete(vv.AssociatedPorts, port)
- logger.Infow(ctx, "Disassociated Port from Vnet", log.Fields{"Device": device, "Port": port, "Vnet": vv.Name, "PendingDeleteFlow": vv.PendingDeleteFlow, "AssociatedPorts": vv.AssociatedPorts, "DeleteFlag": vv.DeleteInProgress})
+ logger.Debugw(ctx, "Disassociated Port from Vnet", log.Fields{"Device": device, "Port": port, "Vnet": vv.Name, "PendingDeleteFlow": vv.PendingDeleteFlow, "AssociatedPorts": vv.AssociatedPorts, "DeleteFlag": vv.DeleteInProgress})
vv.VnetPortLock.Unlock()
if vv.DeleteInProgress {
if !vv.isAssociatedPortsPresent() {
if len(vv.PendingDeleteFlow[device]) == 0 {
- logger.Warnw(ctx, "Deleting Vnet", log.Fields{"Name": vv.Name})
+ logger.Debugw(ctx, "Deleting Vnet", log.Fields{"Name": vv.Name})
GetApplication().deleteVnetConfig(vv)
_ = db.DelVnet(cntx, vv.Name)
} else {
@@ -212,7 +214,7 @@
// WriteToDb commit the VNET to the database
func (vv *VoltVnet) WriteToDb(cntx context.Context) {
if vv.DeleteInProgress {
- logger.Warnw(ctx, "Skipping Redis Update for Vnet, Vnet delete in progress", log.Fields{"Vnet": vv.Name})
+ logger.Warnw(ctx, "Skipping Redis Update for Vnet, Vnet delete in progress", log.Fields{"Vnet": vv.Name, "SVlan": vv.SVlan})
return
}
vv.ForceWriteToDb(cntx)
@@ -226,7 +228,7 @@
logger.Debugw(ctx, "Updating VNET....", log.Fields{"vnet": vv})
if b, err := json.Marshal(vv); err == nil {
if err := db.PutVnet(cntx, vv.Name, string(b)); err != nil {
- logger.Warnw(ctx, "Add Vnet to DB failed", log.Fields{"vnet name": vv.Name, "Error": err})
+ logger.Warnw(ctx, "Add Vnet to DB failed", log.Fields{"Vnet": vv.Name, "SVlan": vv.SVlan, "Error": err})
}
}
}
@@ -242,6 +244,7 @@
// When matching VNET, it is expected to match first just the outer
// tag, and then the combination to make sure there is no conflict
// for the new configuration.
+ logger.Debugw(ctx, "Get Vnet configuration", log.Fields{"SVlan": otag, "CVlan": itag, "UniVlan": utag})
if vnet, ok := va.VnetsByTag.Load(VnetKey(otag, of.VlanNone, utag)); ok {
return vnet.(*VoltVnet)
}
@@ -256,6 +259,7 @@
// GetVnetByName to get vnet by name
func (va *VoltApplication) GetVnetByName(name string) *VoltVnet {
+ logger.Debugw(ctx, "Get Vnet by Name", log.Fields{"Name": name})
if vnet, ok := va.VnetsByName.Load(name); ok {
return vnet.(*VoltVnet)
}
@@ -264,6 +268,7 @@
// storeVnetConfig to store vnet config
func (va *VoltApplication) storeVnetConfig(cfg VnetConfig, vv *VoltVnet) {
+ logger.Debugw(ctx, "Store Vnet config", log.Fields{"Name": cfg.Name})
var vnetMap *util.ConcurrentMap
va.VnetsByTag.Store(VnetKey(cfg.SVlan, cfg.CVlan, cfg.UniVlan), vv)
@@ -280,6 +285,7 @@
// deleteVnetConfig to delete vnet config
func (va *VoltApplication) deleteVnetConfig(vnet *VoltVnet) {
+ logger.Debugw(ctx, "Delete Vnet config", log.Fields{"Name": vnet.Name})
va.VnetsByTag.Delete(VnetKey(vnet.SVlan, vnet.CVlan, vnet.UniVlan))
va.VnetsByName.Delete(vnet.Name)
@@ -292,6 +298,7 @@
// AddVnet to add a VNET to the list of VNETs configured.
func (va *VoltApplication) AddVnet(cntx context.Context, cfg VnetConfig, oper *VnetOper) error {
+ logger.Debugw(ctx, "Add Vnet config", log.Fields{"Name": cfg.Name})
AppMutex.VnetMutex.Lock()
var vv *VoltVnet
devicesToHandle := []string{}
@@ -301,7 +308,7 @@
for _, serialNum := range cfg.DevicesList {
if isDeviceInList(serialNum, vv.DevicesList) {
//This is backup restore scenario, just update the profile
- logger.Info(ctx, "Add Vnet : Profile Name already exists with OLT, update-the-profile")
+ logger.Infow(ctx, "Add Vnet : Profile Name already exists with OLT, update-the-profile", log.Fields{"SerialNum": serialNum})
continue
}
devicesToHandle = append(devicesToHandle, serialNum)
@@ -352,7 +359,7 @@
vnet.ForceWriteToDb(cntx)
vnet.VnetPortLock.RLock()
if len(vnet.PendingDeleteFlow) == 0 && !vnet.isAssociatedPortsPresent() {
- logger.Warnw(ctx, "Deleting Vnet", log.Fields{"Name": vnet.Name, "AssociatedPorts": vnet.AssociatedPorts, "PendingDelFlows": vnet.PendingDeleteFlow})
+ logger.Debugw(ctx, "Deleting Vnet", log.Fields{"Name": vnet.Name, "AssociatedPorts": vnet.AssociatedPorts, "PendingDelFlows": vnet.PendingDeleteFlow})
va.deleteVnetConfig(vnet)
_ = db.DelVnet(cntx, vnet.Name)
} else {
@@ -522,6 +529,7 @@
}
func (vpv *VoltPortVnet) setDevice(device string) {
+ logger.Debugw(ctx, "Set Device", log.Fields{"Device": device})
if vpv.Device != device && vpv.Device != "" {
GetApplication().DisassociateVpvsFromDevice(device, vpv)
// TEMP:
@@ -603,6 +611,7 @@
// GetNniVlans to get nni vlans
func (vpv *VoltPortVnet) GetNniVlans() (uint16, uint16) {
+ logger.Debugw(ctx, "Get Nni Vlans", log.Fields{"vpv.VlanControl": vpv.VlanControl})
switch vpv.VlanControl {
case ONUCVlanOLTSVlan,
OLTCVlanOLTSVlan:
@@ -618,6 +627,7 @@
// GetService to get service
func (vpv *VoltPortVnet) GetService(name string) (*VoltService, bool) {
+ logger.Debugw(ctx, "Get Service", log.Fields{"name": name})
service, ok := vpv.services.Load(name)
if ok {
return service.(*VoltService), ok
@@ -627,6 +637,7 @@
// AddService to add service
func (vpv *VoltPortVnet) AddService(cntx context.Context, service *VoltService) {
+ logger.Debugw(ctx, "Add Service", log.Fields{"ServiceName": service.Name})
vpv.services.Store(service.Name, service)
vpv.servicesCount.Inc()
logger.Infow(ctx, "Service added/updated to VPV", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "Service": service.Name, "Count": vpv.servicesCount.Load()})
@@ -634,6 +645,7 @@
// DelService to delete service
func (vpv *VoltPortVnet) DelService(cntx context.Context, service *VoltService) {
+ logger.Debugw(ctx, "Delete Service", log.Fields{"ServiceName": service.Name})
vpv.services.Delete(service.Name)
vpv.servicesCount.Dec()
@@ -651,6 +663,7 @@
// ProcessDhcpResult to process dhcp results
func (vpv *VoltPortVnet) ProcessDhcpResult(cntx context.Context, res *layers.DHCPv4) {
+ logger.Debug(ctx, "Process Dhcp Result")
msgType := DhcpMsgType(res)
if msgType == layers.DHCPMsgTypeAck {
vpv.ProcessDhcpSuccess(cntx, res)
@@ -671,10 +684,10 @@
// the services with the same. This also calls for adding flows
// for the services as the DHCP procedure is completed
func (vpv *VoltPortVnet) ProcessDhcpSuccess(cntx context.Context, res *layers.DHCPv4) {
+ logger.Info(ctx, "Process Dhcp Success")
vpv.DhcpStatus = DhcpStatusAcked
vpv.Ipv4Addr, _ = GetIpv4Addr(res)
- logger.Infow(ctx, "Received IPv4 Address", log.Fields{"IP Address": vpv.Ipv4Addr.String()})
- logger.Infow(ctx, "Services Configured", log.Fields{"Count": vpv.servicesCount.Load()})
+ logger.Debugw(ctx, "Received IPv4 Address and Services Configured", log.Fields{"IP Address": vpv.Ipv4Addr.String(), "Count": vpv.servicesCount.Load()})
vpv.RangeOnServices(cntx, vpv.updateIPv4AndProvisionFlows)
vpv.ProcessDhcpv4Options(res)
@@ -683,6 +696,7 @@
// ProcessDhcpv4Options : Currently we process lease time and store the validity of the
// IP address allocated.
func (vpv *VoltPortVnet) ProcessDhcpv4Options(res *layers.DHCPv4) {
+ logger.Debug(ctx, "Process Dhcp v4 Options")
for _, o := range res.Options {
switch o.Type {
case layers.DHCPOptLeaseTime:
@@ -698,6 +712,7 @@
// service is fetched all the associated information such as MAC address,
// IPv4 address and IPv6 addresses can be provided.
func (vpv *VoltPortVnet) ProcessDhcpv6Result(cntx context.Context, ipv6Addr net.IP, leaseTime uint32) {
+ logger.Debugw(ctx, "Process Dhcp v6 Result", log.Fields{"ipv6Addr": ipv6Addr, "leaseTime": leaseTime})
// TODO: Status based hanlding of flows
vpv.Dhcp6ExpiryTime = time.Now().Add((time.Duration(leaseTime) * time.Second))
vpv.Ipv6Addr = ipv6Addr
@@ -714,12 +729,13 @@
GetApplication().AddMeterToDevice(svc.Port, device.Name, svc.UsMeterID, 0)
return true
}
- logger.Errorw(ctx, "Dropping US Meter request: Device not found", log.Fields{"Service": svc})
+ logger.Warnw(ctx, "Dropping US Meter request: Device not found", log.Fields{"Service": svc})
return false
}
// PushFlowsForPortVnet - triggers flow construction and push for provided VPV
func (vpv *VoltPortVnet) PushFlowsForPortVnet(cntx context.Context, d *VoltDevice) {
+ logger.Debugw(ctx, "Push Flows For Port Vnet", log.Fields{"Port": vpv.Port})
vp := d.GetPort(vpv.Port)
//Ignore if UNI port is not found or not UP
@@ -743,12 +759,12 @@
// changed. Thus, a reboot of ONT forces the new configuration to get
// applied.
func (vpv *VoltPortVnet) PortUpInd(cntx context.Context, device *VoltDevice, port string) {
+ logger.Infow(ctx, "Port UP Ind, pushing flows for the port", log.Fields{"Device": device, "Port": port, "VnetDhcp": vpv.DhcpRelay, "McastService": vpv.McastService})
if vpv.DeleteInProgress {
- logger.Errorw(ctx, "Ignoring VPV Port UP Ind, VPV deleteion In-Progress", log.Fields{"Device": device, "Port": port, "Vnet": vpv.VnetName})
+ logger.Warnw(ctx, "Ignoring VPV Port UP Ind, VPV deleteion In-Progress", log.Fields{"Device": device, "Port": port, "Vnet": vpv.VnetName})
return
}
vpv.setDevice(device.Name)
- logger.Infow(ctx, "Port UP Ind, pushing flows for the port", log.Fields{"Device": device, "Port": port, "VnetDhcp": vpv.DhcpRelay, "McastService": vpv.McastService})
nni, _ := GetApplication().GetNniPort(device.Name)
if nni == "" {
@@ -761,14 +777,14 @@
devConfig := GetApplication().GetDeviceConfig(device.SerialNum)
if devConfig != nil {
if devConfig.UplinkPort != strconv.Itoa(int(nniPort.ID)) {
- logger.Errorw(ctx, "NNI port not configured from NB, not pushing flows", log.Fields{"NB NNI Port": devConfig.UplinkPort, "SB NNI port": nniPort.ID})
+ logger.Warnw(ctx, "NNI port not configured from NB, not pushing flows", log.Fields{"NB NNI Port": devConfig.UplinkPort, "SB NNI port": nniPort.ID})
return
}
}
}
if vpv.Blocked {
- logger.Errorw(ctx, "VPV Bocked for Processing. Ignoring flow push request", log.Fields{"Port": vpv.Port, "Vnet": vpv.VnetName})
+ logger.Warnw(ctx, "VPV Blocked for Processing. Ignoring flow push request", log.Fields{"Port": vpv.Port, "Vnet": vpv.VnetName})
return
}
@@ -852,6 +868,7 @@
// packets received from the network. Currently, DHCP packets are
// only packets we learn the MAC address from
func (vpv *VoltPortVnet) SetMacAddr(cntx context.Context, addr net.HardwareAddr) {
+ logger.Infow(ctx, "Set Mac Addr", log.Fields{"MAC addr": addr.String(), "Port": vpv.Port})
//Store Learnt MAC address and return if MACLearning is not enabled
vpv.LearntMacAddr = addr
if vpv.MacLearning == MacLearningNone || !NonZeroMacAddress(addr) ||
@@ -866,7 +883,7 @@
if !util.MacAddrsMatch(vpv.MacAddr, addr) {
expectedPort := GetApplication().GetMacInPortMap(addr)
if expectedPort != "" && expectedPort != vpv.Port {
- logger.Errorw(ctx, "mac-learnt-from-different-port-ignoring-setmacaddr",
+ logger.Warnw(ctx, "mac-learnt-from-different-port-ignoring-setmacaddr",
log.Fields{"ExpectedPort": expectedPort, "ReceivedPort": vpv.Port, "LearntMacAdrr": vpv.MacAddr, "NewMacAdrr": addr.String()})
return
}
@@ -896,7 +913,7 @@
_, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- logger.Warnw(ctx, "Not pushing Service Flows: Error Getting Device", log.Fields{"Reason": err.Error()})
+ logger.Errorw(ctx, "Not pushing Service Flows: Error Getting Device", log.Fields{"Reason": err.Error()})
statusCode, statusMessage := errorCodes.GetErrorInfo(err)
vpv.FlowInstallFailure("VGC processing failure", statusCode, statusMessage)
return
@@ -917,6 +934,7 @@
// MatchesVlans : If the VNET matches both S and C VLANs, return true. Else, return false
func (vpv *VoltPortVnet) MatchesVlans(svlan of.VlanType, cvlan of.VlanType, univlan of.VlanType) bool {
+ logger.Debugw(ctx, "Matches Vlans", log.Fields{"Svlan": svlan, "Cvlan": cvlan, "Univlan": univlan})
if vpv.SVlan != svlan || vpv.CVlan != cvlan || vpv.UniVlan != univlan {
return false
}
@@ -925,6 +943,7 @@
// MatchesCvlan : If the VNET matches CVLAN, return true. Else, return false
func (vpv *VoltPortVnet) MatchesCvlan(cvlan []of.VlanType) bool {
+ logger.Debugw(ctx, "Matches Cvlans", log.Fields{"Cvlan": cvlan})
if len(cvlan) != 1 && !vpv.AllowTransparent {
return false
}
@@ -936,6 +955,7 @@
// MatchesPriority : If the VNET matches priority of the incoming packet with any service, return true. Else, return false
func (vpv *VoltPortVnet) MatchesPriority(priority uint8) *VoltService {
+ logger.Debugw(ctx, "Matches Priority", log.Fields{"Priority": priority})
var service *VoltService
pbitFound := false
matchpbitsFunc := func(key, value interface{}) bool {
@@ -958,11 +978,12 @@
// GetRemarkedPriority : If the VNET matches priority of the incoming packet with any service, return true. Else, return false
func (vpv *VoltPortVnet) GetRemarkedPriority(priority uint8) uint8 {
+ logger.Debugw(ctx, "Get Remarked Priority", log.Fields{"Priority": priority})
dsPbit := uint8(0)
matchpbitsFunc := func(key, value interface{}) bool {
svc := value.(*VoltService)
if remarkPbit, ok := svc.DsRemarkPbitsMap[int(priority)]; ok {
- logger.Infow(ctx, "Pbit match found with service",
+ logger.Warnw(ctx, "Pbit match found with service",
log.Fields{"Pbit": priority, "serviceName": svc.Name, "remarkPbit": remarkPbit})
dsPbit = uint8(remarkPbit)
return false //Returning false to stop the Range loop
@@ -983,6 +1004,7 @@
// AddSvc adds a service on the VNET on a port. The addition is
// triggered when NB requests for service addition
func (vpv *VoltPortVnet) AddSvc(cntx context.Context, svc *VoltService) {
+ logger.Infow(ctx, "Add Service to VPV", log.Fields{"ServiceName": svc.Name})
//vpv.services = append(vpv.services, svc)
vpv.AddService(cntx, svc)
logger.Debugw(ctx, "Added Service to VPV", log.Fields{"Num of SVCs": vpv.servicesCount.Load(), "SVC": svc})
@@ -1047,7 +1069,7 @@
return
}
if !svc.IsActivated {
- logger.Warn(ctx, "Not pushing Service Flows: Service Not activated")
+ logger.Warnw(ctx, "Not pushing Service Flows: Service Not activated", log.Fields{"ServiceName": svc.Name})
return
}
@@ -1055,7 +1077,7 @@
devConfig := GetApplication().GetDeviceConfig(voltDevice.SerialNum)
if devConfig.UplinkPort != voltDevice.NniPort {
- logger.Errorw(ctx, "NNI port mismatch", log.Fields{"NB NNI Port": devConfig.UplinkPort, "SB NNI port": voltDevice.NniPort})
+ logger.Warnw(ctx, "NNI port mismatch", log.Fields{"NB NNI Port": devConfig.UplinkPort, "SB NNI port": voltDevice.NniPort})
return
}
// Push Service Flows if DHCP relay is not configured
@@ -1105,7 +1127,7 @@
// updateIPv4AndProvisionFlows to update ipv4 and provisional flows
func (vpv *VoltPortVnet) updateIPv4AndProvisionFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
- logger.Infow(ctx, "Updating Ipv4 address for service", log.Fields{"ServiceName": svc.Name})
+ logger.Debugw(ctx, "Updating Ipv4 address for service", log.Fields{"ServiceName": svc.Name})
svc.SetIpv4Addr(vpv.Ipv4Addr)
svc.WriteToDb(cntx)
@@ -1115,6 +1137,7 @@
// updateIPv6AndProvisionFlows to update ipv6 and provisional flow
func (vpv *VoltPortVnet) updateIPv6AndProvisionFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Updating Ipv6 address for service", log.Fields{"ServiceName": svc.Name})
svc.SetIpv6Addr(vpv.Ipv6Addr)
svc.WriteToDb(cntx)
@@ -1124,6 +1147,7 @@
// AddUsHsiaFlows to add upstream hsia flows
func AddUsHsiaFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Add US Hsia Flows", log.Fields{"ServiceName": svc.Name})
if err := svc.AddUsHsiaFlows(cntx); err != nil {
logger.Warnw(ctx, "Add US hsia flow failed", log.Fields{"service": svc.Name, "Error": err})
}
@@ -1133,6 +1157,7 @@
// AddDsHsiaFlows to add downstream hsia flows
func AddDsHsiaFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Add DS Hsia Flows", log.Fields{"ServiceName": svc.Name})
if err := svc.AddDsHsiaFlows(cntx); err != nil {
logger.Warnw(ctx, "Add DS hsia flow failed", log.Fields{"service": svc.Name, "Error": err})
}
@@ -1142,6 +1167,7 @@
// ClearFlagsInService to clear the flags used in service
func ClearFlagsInService(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Received Cleared Flow Flags for service", log.Fields{"name": svc.Name})
svc.ServiceLock.Lock()
svc.IgmpFlowsApplied = false
svc.DsDhcpFlowsApplied = false
@@ -1160,6 +1186,7 @@
// DelDsHsiaFlows to delete hsia flows
func DelDsHsiaFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Delete DS Hsia Flows", log.Fields{"ServiceName": svc.Name})
if err := svc.DelDsHsiaFlows(cntx); err != nil {
logger.Warnw(ctx, "Delete DS hsia flow failed", log.Fields{"service": svc.Name, "Error": err})
}
@@ -1169,6 +1196,7 @@
// DelUsHsiaFlows to delete upstream hsia flows
func DelUsHsiaFlows(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Delete US Hsia Flows", log.Fields{"ServiceName": svc.Name})
if err := svc.DelUsHsiaFlows(cntx); err != nil {
logger.Warnw(ctx, "Delete US hsia flow failed", log.Fields{"service": svc.Name, "Error": err})
}
@@ -1178,6 +1206,7 @@
// ClearServiceCounters to clear the service counters
func ClearServiceCounters(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Received Clear Service Counters", log.Fields{"ServiceName": svc.Name})
//Delete the per service counter too
GetApplication().ServiceCounters.Delete(svc.Name)
if svc.IgmpEnabled && svc.EnableMulticastKPI {
@@ -1189,6 +1218,7 @@
// AddMeterToDevice to add meter config to device, used in FTTB case
func AddMeterToDevice(cntx context.Context, key, value interface{}) bool {
svc := value.(*VoltService)
+ logger.Debugw(ctx, "Received Add Meter To Device", log.Fields{"ServiceName": svc.Name})
if err := svc.AddMeterToDevice(cntx); err != nil {
logger.Warnw(ctx, "Add Meter failed", log.Fields{"service": svc.Name, "Error": err})
}
@@ -1197,6 +1227,7 @@
// AddTrapFlows - Adds US & DS Trap flows
func (vpv *VoltPortVnet) AddTrapFlows(cntx context.Context) {
+ logger.Debugw(ctx, "Received Add US & DS DHCP, IGMP Trap Flows", log.Fields{"FlowsApplied": vpv.FlowsApplied, "VgcRebooted": vgcRebooted})
if !vpv.FlowsApplied || vgcRebooted {
if vpv.DhcpRelay {
if err := vpv.AddUsDhcpFlows(cntx); err != nil {
@@ -1233,6 +1264,7 @@
// DelTrapFlows - Removes all US & DS DHCP, IGMP trap flows.
func (vpv *VoltPortVnet) DelTrapFlows(cntx context.Context) {
+ logger.Debugw(ctx, "Received Delete US & DS DHCP, IGMP Trap Flows", log.Fields{"FlowsApplied": vpv.FlowsApplied, "VgcRebooted": vgcRebooted})
// Delete HSIA & DHCP flows before deleting IGMP flows
if vpv.FlowsApplied || vgcRebooted {
if vpv.DhcpRelay {
@@ -1273,6 +1305,7 @@
// DelHsiaFlows deletes the service flows
func (vpv *VoltPortVnet) DelHsiaFlows(cntx context.Context) {
+ logger.Infow(ctx, "Received Delete Hsia Flows", log.Fields{"McastService": vpv.McastService})
// no HSIA flows for multicast service
if !vpv.McastService {
vpv.RangeOnServices(cntx, DelUsHsiaFlows)
@@ -1290,6 +1323,7 @@
func (vpv *VoltPortVnet) AddUsDhcpFlows(cntx context.Context) error {
var vd *VoltDevice
device := vpv.Device
+ logger.Debugw(ctx, "Received Add US DHCP Flows", log.Fields{"Device": device})
if vd = GetApplication().GetDevice(device); vd != nil {
if vd.State != controller.DeviceStateUP {
@@ -1297,8 +1331,8 @@
return nil
}
} else {
- logger.Errorw(ctx, "US DHCP Flow Push Failed- Device not found", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("us dhcp flow push failed - device not found for Port %s, Svlan %d, Cvlan %d, UniVlan %d. Device %s : %w", vpv.Port, vpv.SVlan, vpv.CVlan, vpv.UniVlan, device, err)
}
flows, err := vpv.BuildUsDhcpFlows()
@@ -1322,6 +1356,7 @@
func (vpv *VoltPortVnet) AddDsDhcpFlows(cntx context.Context) error {
var vd *VoltDevice
device := vpv.Device
+ logger.Debugw(ctx, "Received Add DS DHCP Flows", log.Fields{"Device": device})
if vd = GetApplication().GetDevice(device); vd != nil {
if vd.State != controller.DeviceStateUP {
@@ -1329,8 +1364,8 @@
return nil
}
} else {
- logger.Errorw(ctx, "DS DHCP Flow Push Failed- Device not found", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("ds dhcp flow push failed - device not found for Port %s, Svlan %d, Cvlan %d, UniVlan %d. Device %s : %w", vpv.Port, vpv.SVlan, vpv.CVlan, vpv.UniVlan, device, err)
}
if vd.GlobalDhcpFlowAdded {
logger.Info(ctx, "Global Dhcp flow already exists")
@@ -1358,6 +1393,7 @@
// DelDhcpFlows deletes both US & DS DHCP flows applied for this Vnet instantiated on the port
func (vpv *VoltPortVnet) DelDhcpFlows(cntx context.Context) {
+ logger.Info(ctx, "Received Delete DHCP Flows")
if err := vpv.DelUsDhcpFlows(cntx); err != nil {
statusCode, statusMessage := errorCodes.GetErrorInfo(err)
vpv.FlowInstallFailure("VGC processing failure", statusCode, statusMessage)
@@ -1373,6 +1409,7 @@
// Write the status of the VPV to the DB once the delete is scheduled
// for dispatch
func (vpv *VoltPortVnet) DelUsDhcpFlows(cntx context.Context) error {
+ logger.Debugw(ctx, "Received Delete US DHCP Flows", log.Fields{"Port": vpv.Port})
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
return err
@@ -1388,18 +1425,19 @@
}
func (vpv *VoltPortVnet) delDhcp4Flows(cntx context.Context, device *VoltDevice) error {
+ logger.Debugw(ctx, "Received US Delete DHCP4 Flows", log.Fields{"DeviceName": device.Name})
flows, err := vpv.BuildUsDhcpFlows()
if err == nil {
return vpv.RemoveFlows(cntx, device, flows)
}
- logger.Errorw(ctx, "US DHCP Flow Delete Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("US DHCP Flow Delete Failed : %w", err)
}
// DelDsDhcpFlows delete the DHCP flows applied for this Vnet instantiated on the port
// Write the status of the VPV to the DB once the delete is scheduled
// for dispatch
func (vpv *VoltPortVnet) DelDsDhcpFlows(cntx context.Context) error {
+ logger.Debugw(ctx, "Received Delete DS DHCP Flows", log.Fields{"Port": vpv.Port})
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
return err
@@ -1419,12 +1457,12 @@
}
func (vpv *VoltPortVnet) delDsDhcp4Flows(cntx context.Context, device *VoltDevice) error {
+ logger.Debugw(ctx, "Received DS Delete DHCP4 Flows", log.Fields{"DeviceName": device.Name})
flows, err := vpv.BuildDsDhcpFlows()
if err == nil {
return vpv.RemoveFlows(cntx, device, flows)
}
- logger.Errorw(ctx, "DS DHCP Flow Delete Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("DS DHCP Flow Delete Failed : %w", err)
}
/*
@@ -1441,25 +1479,25 @@
func (vpv *VoltPortVnet) AddUsArpFlows(cntx context.Context) error {
var vd *VoltDevice
device := vpv.Device
+ logger.Debugw(ctx, "Received Add US Arp Flows", log.Fields{"DeviceName": device})
if vd = GetApplication().GetDevice(device); vd != nil {
if vd.State != controller.DeviceStateUP {
logger.Errorw(ctx, "Skipping US ARP Flow Push - Device state DOWN", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
return nil
}
} else {
- logger.Errorw(ctx, "US ARP Flow Push Failed- Device not found", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("US ARP Flow Push Failed- Device not found : Port %s : SVLAN %d : CVLAN %d : UNIVlan %d : device %s : %w", vpv.Port, vpv.SVlan, vpv.CVlan, vpv.UniVlan, device, err)
}
flows, err := vpv.BuildUsArpFlows()
if err == nil {
logger.Debugw(ctx, "Adding US ARP flows", log.Fields{"Device": device})
if err1 := vpv.PushFlows(cntx, vd, flows); err1 != nil {
- return err1
+ return fmt.Errorf("Pushing US ARP Flow Failed : %w", err1)
}
} else {
- logger.Errorw(ctx, "US ARP Flow Add Failed", log.Fields{"Reason": err.Error(), "Device": device})
- return err
+ return fmt.Errorf("US ARP Flow Add Failed : Device %s : %w", device, err)
}
return nil
}
@@ -1468,16 +1506,16 @@
// Write the status of the VPV to the DB once the delete is scheduled
// for dispatch
func (vpv *VoltPortVnet) DelUsArpFlows(cntx context.Context) error {
+ logger.Debugw(ctx, "Delete US ARP Flows", log.Fields{"Port": vpv.Port})
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- return err
+ return fmt.Errorf("US ARP Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
flows, err := vpv.BuildUsArpFlows()
if err == nil {
return vpv.RemoveFlows(cntx, device, flows)
}
- logger.Errorw(ctx, "US ARP Flow Delete Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("US ARP Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
// AddUsPppoeFlows pushes the PPPoE flows to the VOLTHA via the controller
@@ -1493,19 +1531,18 @@
return nil
}
} else {
- logger.Errorw(ctx, "US PPPoE Flow Push Failed- Device not found", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("US PPPoE Flow Push Failed- Device not found : Port %s : SVLAN %d : CVLAN %d : UNIVlan %d : device %s : %w", vpv.Port, vpv.SVlan, vpv.CVlan, vpv.UniVlan, device, err)
}
if flows, err := vpv.BuildUsPppoeFlows(); err == nil {
logger.Debugw(ctx, "Adding US PPPoE flows", log.Fields{"Device": device})
if err1 := vpv.PushFlows(cntx, vd, flows); err1 != nil {
- return err1
+ return fmt.Errorf("Pushing US PPPoE Flows Failed : %w", err1)
}
} else {
- logger.Errorw(ctx, "US PPPoE Flow Add Failed", log.Fields{"Reason": err.Error(), "Device": device})
- return err
+ return fmt.Errorf("US PPPoE Flow Add Failed : Device %s : %w", device, err)
}
return nil
}
@@ -1522,18 +1559,17 @@
return nil
}
} else {
- logger.Errorw(ctx, "DS PPPoE Flow Push Failed- Device not found", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan, "device": device})
- return errorCodes.ErrDeviceNotFound
+ err := errorCodes.ErrDeviceNotFound
+ return fmt.Errorf("DS PPPoE Flow Push Failed- Device not found : Port %s : SVLAN %d : CVLAN %d : UNIVlan %d : device %s : %w", vpv.Port, vpv.SVlan, vpv.CVlan, vpv.UniVlan, device, err)
}
flows, err := vpv.BuildDsPppoeFlows()
if err == nil {
if err1 := vpv.PushFlows(cntx, vd, flows); err1 != nil {
- return err1
+ return fmt.Errorf("Pushing DS PPPoE Flows Failed : %w", err1)
}
} else {
- logger.Errorw(ctx, "DS PPPoE Flow Add Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("DS PPPoE Flow Add Failed : Device %s : %w", device, err)
}
return nil
}
@@ -1545,14 +1581,13 @@
logger.Debugw(ctx, "Deleting US PPPoE flows", log.Fields{"STAG": vpv.SVlan, "CTAG": vpv.CVlan, "Device": vpv.Device})
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- return err
+ return fmt.Errorf("US PPPoE Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
flows, err := vpv.BuildUsPppoeFlows()
if err == nil {
return vpv.RemoveFlows(cntx, device, flows)
}
- logger.Errorw(ctx, "US PPPoE Flow Delete Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("US PPPoE Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
// DelDsPppoeFlows delete the PPPoE flows applied for this Vnet instantiated on the port
@@ -1562,27 +1597,26 @@
logger.Debugw(ctx, "Deleting DS PPPoE flows", log.Fields{"STAG": vpv.SVlan, "CTAG": vpv.CVlan, "Device": vpv.Device})
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- return err
+ return fmt.Errorf("DS PPPoE Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
flows, err := vpv.BuildDsPppoeFlows()
if err == nil {
return vpv.RemoveFlows(cntx, device, flows)
}
- logger.Errorw(ctx, "DS PPPoE Flow Delete Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("DS PPPoE Flow Delete Failed : DeviceName %s : %w", device.Name, err)
}
// AddIgmpFlows function pushes the IGMP flows to the VOLTHA via the controller
func (vpv *VoltPortVnet) AddIgmpFlows(cntx context.Context) error {
+ logger.Debugw(ctx, "Received Add Igmp Flows", log.Fields{"IgmpFlowsApplied": vpv.IgmpFlowsApplied, "VgcRebooted": vgcRebooted})
if !vpv.IgmpFlowsApplied || vgcRebooted {
if vpv.MvlanProfileName == "" {
- logger.Info(ctx, "Mvlan Profile not configured. Ignoring Igmp trap flow")
+ logger.Warn(ctx, "Mvlan Profile not configured. Ignoring Igmp trap flow")
return nil
}
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- logger.Errorw(ctx, "Error getting device from port", log.Fields{"Port": vpv.Port, "Reason": err.Error()})
- return err
+ return fmt.Errorf("Error getting device from port : Port %s : %w", vpv.Port, err)
} else if device.State != controller.DeviceStateUP {
logger.Warnw(ctx, "Device state Down. Ignoring US IGMP Flow Push", log.Fields{"Port": vpv.Port, "SVLAN": vpv.SVlan, "CVLAN": vpv.CVlan, "UNIVlan": vpv.UniVlan})
return nil
@@ -1604,8 +1638,7 @@
return err1
}
} else {
- logger.Errorw(ctx, "IGMP Flow Add Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("IGMP Flow Add Failed : %w", err)
}
vpv.IgmpFlowsApplied = true
vpv.WriteToDb(cntx)
@@ -1617,11 +1650,11 @@
// Write the status of the VPV to the DB once the delete is scheduled
// for dispatch
func (vpv *VoltPortVnet) DelIgmpFlows(cntx context.Context) error {
+ logger.Debugw(ctx, "Received Delete Igmp Flows", log.Fields{"IgmpFlowsApplied": vpv.IgmpFlowsApplied, "VgcRebooted": vgcRebooted})
if vpv.IgmpFlowsApplied || vgcRebooted {
device, err := GetApplication().GetDeviceFromPort(vpv.Port)
if err != nil {
- logger.Errorw(ctx, "Error getting device from port", log.Fields{"Port": vpv.Port, "Reason": err.Error()})
- return err
+ return fmt.Errorf("Error getting device from port : Port %s : %w", vpv.Port, err)
}
flows, err := vpv.BuildIgmpFlows()
if err == nil {
@@ -1629,8 +1662,7 @@
return err1
}
} else {
- logger.Errorw(ctx, "IGMP Flow Add Failed", log.Fields{"Reason": err.Error()})
- return err
+ return fmt.Errorf("IGMP Flow Delete Failed : %w", err)
}
vpv.IgmpFlowsApplied = false
vpv.WriteToDb(cntx)
@@ -1643,10 +1675,10 @@
// created either automatically by the VOLTHA or at the device level
// earlier
func (vpv *VoltPortVnet) BuildUsDhcpFlows() (*of.VoltFlow, error) {
+ logger.Infow(ctx, "Building US DHCP flow", log.Fields{"Port": vpv.Port})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
- logger.Infow(ctx, "Building US DHCP flow", log.Fields{"Port": vpv.Port})
subFlow := of.NewVoltSubFlow()
subFlow.SetTableID(0)
@@ -1665,8 +1697,7 @@
subFlow.SrcPort = 68
uniport, err := GetApplication().GetPortID(vpv.Port)
if err != nil {
- logger.Errorw(ctx, "Failed to fetch uni port from vpv", log.Fields{"error": err, "port": vpv.Port})
- return nil, err
+ return nil, fmt.Errorf("failed to fetch uni port %s from vpv : %w", vpv.Port, err)
}
subFlow.SetInPort(uniport)
// PortName and PortID to be used for validation of port before flow pushing
@@ -1724,11 +1755,11 @@
uniport, _ := GetApplication().GetPortID(vpv.Port)
nni, err := GetApplication().GetNniPort(vpv.Device)
if err != nil {
- return nil, err
+ return nil, fmt.Errorf("failed to fetch nni port %s from vpv : %w", nni, err)
}
nniport, err := GetApplication().GetPortID(nni)
if err != nil {
- return nil, err
+ return nil, fmt.Errorf("failed to fetch port id %d for nni : %w", nniport, err)
}
subFlow.SetInPort(nniport)
// PortName and PortID to be used for validation of port before flow pushing
@@ -1758,10 +1789,10 @@
// BuildUsDhcp6Flows to trap the DHCPv6 packets to be reported to the
// application.
func (vpv *VoltPortVnet) BuildUsDhcp6Flows() (*of.VoltFlow, error) {
+ logger.Infow(ctx, "Building US DHCPv6 flow", log.Fields{"Port": vpv.Port})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
- logger.Infow(ctx, "Building US DHCPv6 flow", log.Fields{"Port": vpv.Port})
subFlow := of.NewVoltSubFlow()
subFlow.SetTableID(0)
@@ -1772,7 +1803,7 @@
subFlow.DstPort = 547
uniport, err := GetApplication().GetPortID(vpv.Port)
if err != nil {
- return nil, err
+ return nil, fmt.Errorf("failed to fetch uni port %d from vpv : %w", uniport, err)
}
// Set techprofile, meterid of first service
vpv.services.Range(func(key, value interface{}) bool {
@@ -1822,10 +1853,12 @@
uniport, _ := GetApplication().GetPortID(vpv.Port)
nni, err := GetApplication().GetNniPort(vpv.Device)
if err != nil {
+ logger.Errorw(ctx, "Failed to fetch nni port from vpv", log.Fields{"error": err, "device": vpv.Device})
return nil, err
}
nniport, err := GetApplication().GetPortID(nni)
if err != nil {
+ logger.Errorw(ctx, "Failed to fetch port ID for nni", log.Fields{"error": err, "nni": nni})
return nil, err
}
subFlow.SetInPort(nniport)
@@ -1855,10 +1888,10 @@
// created either automatically by the VOLTHA or at the device level
// earlier
func (vpv *VoltPortVnet) BuildUsArpFlows() (*of.VoltFlow, error) {
+ logger.Infow(ctx, "Building US ARP flow", log.Fields{"Port": vpv.Port})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
- logger.Infow(ctx, "Building US ARP flow", log.Fields{"Port": vpv.Port})
subFlow := of.NewVoltSubFlow()
subFlow.SetTableID(0)
@@ -1873,7 +1906,7 @@
subFlow.SetArpMatch()
uniport, err := GetApplication().GetPortID(vpv.Port)
if err != nil {
- return nil, err
+ return nil, fmt.Errorf("failed to fetch uni port %d from vpv : %w", uniport, err)
}
subFlow.SetInPort(uniport)
// PortName and PortID to be used for validation of port before flow pushing
@@ -1898,6 +1931,7 @@
// setUsMatchVlan to set upstream match vlan
func (vpv *VoltPortVnet) setUsMatchVlan(flow *of.VoltSubFlow) error {
+ logger.Debugw(ctx, "Set Us Match Vlan", log.Fields{"Value": vpv.VlanControl})
switch vpv.VlanControl {
case None:
flow.SetMatchVlan(vpv.SVlan)
@@ -1920,9 +1954,9 @@
// BuildUsPppoeFlows to build upstream pppoe flows
func (vpv *VoltPortVnet) BuildUsPppoeFlows() (*of.VoltFlow, error) {
+ logger.Infow(ctx, "Building US PPPoE flow", log.Fields{"Port": vpv.Port})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
- logger.Infow(ctx, "Building US PPPoE flow", log.Fields{"Port": vpv.Port})
subFlow := of.NewVoltSubFlow()
subFlow.SetTableID(0)
@@ -2011,6 +2045,7 @@
// setDsMatchVlan to set downstream match vlan
func (vpv *VoltPortVnet) setDsMatchVlan(flow *of.VoltSubFlow) {
+ logger.Debugw(ctx, "Set Ds Match Vlan", log.Fields{"Vlan": vpv.VlanControl})
switch vpv.VlanControl {
case None:
flow.SetMatchVlan(vpv.SVlan)
@@ -2030,7 +2065,7 @@
logger.Infow(ctx, "Building US IGMP Flow", log.Fields{"Port": vpv.Port})
mvp := GetApplication().GetMvlanProfileByName(vpv.MvlanProfileName)
if mvp == nil {
- return nil, errors.New("Mvlan Profile configured not found")
+ return nil, errors.New("mvlan profile configured not found")
}
mvlan := mvp.GetUsMatchVlan()
flow := &of.VoltFlow{}
@@ -2053,7 +2088,7 @@
if vpv.MacLearning == MacLearningNone && NonZeroMacAddress(vpv.MacAddr) {
subFlow.SetMatchSrcMac(vpv.MacAddr)
}
- logger.Infow(ctx, "Mvlan", log.Fields{"mvlan": mvlan})
+ logger.Debugw(ctx, "Mvlan", log.Fields{"mvlan": mvlan})
// metadata := uint64(mvlan)
if vpv.McastService {
@@ -2125,6 +2160,7 @@
// ClearAllVpvFlags to clear all vpv flags
func (vpv *VoltPortVnet) ClearAllVpvFlags(cntx context.Context) {
+ logger.Debugw(ctx, "Clear All Vpv Flags", log.Fields{"Port": vpv.Port, "Device": vpv.Device})
vpv.PendingFlowLock.Lock()
vpv.FlowsApplied = false
vpv.IgmpFlowsApplied = false
@@ -2138,6 +2174,7 @@
// CreateVpvFromString to create vpv from string
func (va *VoltApplication) CreateVpvFromString(b []byte, hash string) {
+ logger.Info(ctx, "Create Vpv From String")
var vpv VoltPortVnet
if err := json.Unmarshal(b, &vpv); err == nil {
vnetsByPortsSliceIntf, ok := va.VnetsByPort.Load(vpv.Port)
@@ -2164,6 +2201,7 @@
// RestoreVpvsFromDb to restore vpvs from database
func (va *VoltApplication) RestoreVpvsFromDb(cntx context.Context) {
+ logger.Info(ctx, "Restore Vpvs From Db")
// VNETS must be learnt first
vpvs, _ := db.GetVpvs(cntx)
for hash, vpv := range vpvs {
@@ -2181,6 +2219,7 @@
// The identity of the VNET is the SVLAN and the CVLAN. Only if the both match the VLAN
// is assumed to have matched. TODO: 1:1 should be treated differently and needs to be addressed
func (va *VoltApplication) GetVnetByPort(port string, svlan of.VlanType, cvlan of.VlanType, univlan of.VlanType) *VoltPortVnet {
+ logger.Debugw(ctx, "Get Vnet By Port", log.Fields{"port": port, "svlan": svlan, "cvlan": cvlan, "univlan": univlan})
if _, ok := va.VnetsByPort.Load(port); !ok {
return nil
}
@@ -2233,7 +2272,7 @@
vpv.setDevice(d.Name)
p := d.GetPort(port)
if p != nil {
- logger.Infow(ctx, "Checking UNI port state", log.Fields{"State": p.State})
+ logger.Debugw(ctx, "Checking UNI port state", log.Fields{"State": p.State})
if d.State == controller.DeviceStateUP && p.State == PortStateUp {
vpv.PortUpInd(cntx, d, port)
}
@@ -2245,6 +2284,7 @@
// DelVnetFromPort for deleting vnet from port
func (va *VoltApplication) DelVnetFromPort(cntx context.Context, port string, vpv *VoltPortVnet) {
+ logger.Debugw(ctx, "Delete Vnet From Port", log.Fields{"Port": port, "VNET": vpv.Device})
// Delete DHCP Session
delDhcpSessions(vpv.LearntMacAddr, vpv.SVlan, vpv.CVlan, vpv.DHCPv6DUID)
@@ -2289,6 +2329,7 @@
// RestoreVnetsFromDb to restore vnet from port
func (va *VoltApplication) RestoreVnetsFromDb(cntx context.Context) {
+ logger.Info(ctx, "Restore Vnets From Db")
// VNETS must be learnt first
vnets, _ := db.GetVnets(cntx)
for _, net := range vnets {
@@ -2320,6 +2361,7 @@
// same port (essentially a UNI of ONU), the services must be separated by different
// CVLANs
func (va *VoltApplication) GetServiceFromCvlan(device, port string, vlans []of.VlanType, priority uint8) *VoltService {
+ logger.Debugw(ctx, "Get Service From Cvlan", log.Fields{"Device": device, "Port": port, "VLANs": vlans, "Priority": priority})
// Fetch the device first to make sure the device exists
dIntf, ok := va.DevicesDisc.Load(device)
if !ok {
@@ -2368,7 +2410,7 @@
return service
}
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vnet.VlanControl})
+ logger.Warnw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vnet.VlanControl})
}
}
return nil
@@ -2380,6 +2422,7 @@
// CVLANs
func (va *VoltApplication) GetVnetFromFields(device string, port string, vlans []of.VlanType, priority uint8) (*VoltPortVnet, *VoltService) {
// Fetch the device first to make sure the device exists
+ logger.Debugw(ctx, "Get Vnet From Fields", log.Fields{"Device": device, "Port": port, "VLANs": vlans, "Priority": priority})
dIntf, ok := va.DevicesDisc.Load(device)
if !ok {
return nil, nil
@@ -2420,7 +2463,7 @@
return vnet, service
}
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vnet.VlanControl})
+ logger.Warnw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vnet.VlanControl})
}
}
}
@@ -2432,6 +2475,7 @@
// same port (essentially a UNI of ONU), the services must be separated by different
// CVLANs
func (va *VoltApplication) GetVnetFromPkt(device string, port string, pkt gopacket.Packet) (*VoltPortVnet, *VoltService) {
+ logger.Debugw(ctx, "Get Vnet From Pkt", log.Fields{"Device": device, "Port": port})
vlans := GetVlans(pkt)
priority := GetPriority(pkt)
return va.GetVnetFromFields(device, port, vlans, priority)
@@ -2439,19 +2483,19 @@
// PushDevFlowForVlan to push icmpv6 flows for vlan
func (va *VoltApplication) PushDevFlowForVlan(cntx context.Context, vnet *VoltVnet) {
- logger.Infow(ctx, "PushDevFlowForVlan", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
+ logger.Debugw(ctx, "PushDevFlowForVlan", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
pushflow := func(key interface{}, value interface{}) bool {
device := value.(*VoltDevice)
if !isDeviceInList(device.SerialNum, vnet.DevicesList) {
- logger.Infow(ctx, "Device not present in vnet device list", log.Fields{"Device": device.SerialNum})
+ logger.Warnw(ctx, "Device not present in vnet device list", log.Fields{"Device": device.SerialNum})
return true
}
if device.State != controller.DeviceStateUP {
- logger.Errorw(ctx, "Push Dev Flows Failed - Device state DOWN", log.Fields{"Port": device.NniPort, "Vlan": vnet.SVlan, "device": device})
+ logger.Warnw(ctx, "Push Dev Flows Failed - Device state DOWN", log.Fields{"Port": device.NniPort, "Vlan": vnet.SVlan, "device": device})
return true
}
if applied, ok := device.VlanPortStatus.Load(uint16(vnet.SVlan)); !ok || !applied.(bool) {
- logger.Errorw(ctx, "Push Dev Flows Failed - Vlan not enabled yet", log.Fields{"Port": device.NniPort, "Vlan": vnet.SVlan})
+ logger.Warnw(ctx, "Push Dev Flows Failed - Vlan not enabled yet", log.Fields{"Port": device.NniPort, "Vlan": vnet.SVlan})
return true
}
@@ -2503,9 +2547,7 @@
// PushDevFlowForDevice to push icmpv6 flows for device
func (va *VoltApplication) PushDevFlowForDevice(cntx context.Context, device *VoltDevice) {
- logger.Infow(ctx, "PushDevFlowForDevice", log.Fields{"device": device})
-
- logger.Debugw(ctx, "Configuring ICMPv6 Group for device ", log.Fields{"Device": device.Name})
+ logger.Debugw(ctx, "PushDevFlowForDevice", log.Fields{"device": device.Name})
err := ProcessIcmpv6McGroup(device.Name, false)
if err != nil {
logger.Warnw(ctx, "Configuring ICMPv6 Group for device failed ", log.Fields{"Device": device.Name, "err": err})
@@ -2554,7 +2596,7 @@
// DeleteDevFlowForVlan to delete icmpv6 flow for vlan
func (va *VoltApplication) DeleteDevFlowForVlan(cntx context.Context, vnet *VoltVnet) {
- logger.Infow(ctx, "DeleteDevFlowForVlan", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
+ logger.Debugw(ctx, "DeleteDevFlowForVlan", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
delflows := func(key interface{}, value interface{}) bool {
device := value.(*VoltDevice)
@@ -2601,7 +2643,7 @@
// DeleteDevFlowForDevice to delete icmpv6 flow for device
func (va *VoltApplication) DeleteDevFlowForDevice(cntx context.Context, device *VoltDevice) {
- logger.Infow(ctx, "DeleteDevFlowForDevice", log.Fields{"Device": device})
+ logger.Debugw(ctx, "DeleteDevFlowForDevice", log.Fields{"Device": device})
delicmpv6 := func(key, value interface{}) bool {
vnet := value.(*VoltVnet)
if vnetListIntf, ok := device.ConfiguredVlanForDeviceFlows.Get(VnetKey(vnet.SVlan, vnet.CVlan, 0)); ok {
@@ -2651,7 +2693,7 @@
// DeleteDevFlowForVlanFromDevice to delete icmpv6 flow for vlan from device
func (va *VoltApplication) DeleteDevFlowForVlanFromDevice(cntx context.Context, vnet *VoltVnet, deviceSerialNum string) {
- logger.Infow(ctx, "DeleteDevFlowForVlanFromDevice", log.Fields{"Device-serialNum": deviceSerialNum, "SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
+ logger.Debugw(ctx, "DeleteDevFlowForVlanFromDevice", log.Fields{"Device-serialNum": deviceSerialNum, "SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
delflows := func(key interface{}, value interface{}) bool {
device := value.(*VoltDevice)
if device.SerialNum != deviceSerialNum {
@@ -2705,7 +2747,7 @@
// BuildICMPv6Flow to Build DS flow for ICMPv6
func BuildICMPv6Flow(inport uint32, vnet *VoltVnet) *of.VoltFlow {
- logger.Infow(ctx, "Building ICMPv6 MC Flow", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
+ logger.Debugw(ctx, "Building ICMPv6 MC Flow", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
subFlow := of.NewVoltSubFlow()
@@ -2734,7 +2776,7 @@
// BuildDSArpFlow Builds DS flow for ARP
func BuildDSArpFlow(inport uint32, vnet *VoltVnet) *of.VoltFlow {
- logger.Infow(ctx, "Building ARP MC Flow", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
+ logger.Debugw(ctx, "Building ARP MC Flow", log.Fields{"SVlan": vnet.SVlan, "CVlan": vnet.CVlan})
flow := &of.VoltFlow{}
flow.SubFlows = make(map[uint64]*of.VoltSubFlow)
@@ -2797,7 +2839,7 @@
group.Device = device
if delete {
if !vd.icmpv6GroupAdded {
- logger.Info(ctx, "ICMPv6 MC Group is already deleted. Ignoring icmpv6 group Delete")
+ logger.Debug(ctx, "ICMPv6 MC Group is already deleted. Ignoring icmpv6 group Delete")
return nil //TODO
}
vd.icmpv6GroupAdded = false
@@ -2805,7 +2847,7 @@
group.ForceAction = true
} else {
if vd.icmpv6GroupAdded {
- logger.Info(ctx, "ICMPv6 MC Group is already added. Ignoring icmpv6 group Add")
+ logger.Debug(ctx, "ICMPv6 MC Group is already added. Ignoring icmpv6 group Add")
return nil //TODO
}
vd.icmpv6GroupAdded = true
@@ -2821,6 +2863,7 @@
// isVlanMatching - checks is vlans matches with vpv based on vlan control
func (vpv *VoltPortVnet) isVlanMatching(cvlan of.VlanType, svlan of.VlanType) bool {
+ logger.Debugw(ctx, "Is Vlan Matching", log.Fields{"cvlan": cvlan, "svlan": svlan})
switch vpv.VlanControl {
case ONUCVlanOLTSVlan,
OLTCVlanOLTSVlan:
@@ -2834,13 +2877,14 @@
return true
}
default:
- logger.Errorw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vpv.VlanControl})
+ logger.Warnw(ctx, "Invalid Vlan Control Option", log.Fields{"Value": vpv.VlanControl})
}
return false
}
// PushFlows - Triggers flow addition after registering for flow indication event
func (vpv *VoltPortVnet) PushFlows(cntx context.Context, device *VoltDevice, flow *of.VoltFlow) error {
+ logger.Debugw(ctx, "Push Flows", log.Fields{"DeviceName": device.Name, "Flow port": flow.PortID})
for cookie := range flow.SubFlows {
cookie := strconv.FormatUint(cookie, 10)
fe := &FlowEvent{
@@ -2855,6 +2899,7 @@
// FlowInstallFailure - Process flow failure indication and triggers HSIA failure for all associated services
func (vpv *VoltPortVnet) FlowInstallFailure(cookie string, errorCode uint32, errReason string) {
+ logger.Debugw(ctx, "Flow Install Failure", log.Fields{"Cookie": cookie, "ErrorCode": errorCode, "ErrReason": errReason})
sendFlowFailureInd := func(key, value interface{}) bool {
//svc := value.(*VoltService)
//TODO-COMM: svc.triggerServiceFailureInd(errorCode, errReason)
@@ -2866,6 +2911,7 @@
// RemoveFlows - Triggers flow deletion after registering for flow indication event
func (vpv *VoltPortVnet) RemoveFlows(cntx context.Context, device *VoltDevice, flow *of.VoltFlow) error {
+ logger.Debugw(ctx, "Remove Flows", log.Fields{"DeviceName": device.Name, "Flow port": flow.PortID})
vpv.PendingFlowLock.Lock()
defer vpv.PendingFlowLock.Unlock()
@@ -2885,13 +2931,15 @@
// CheckAndDeleteVpv - remove VPV from DB is there are no pending flows to be removed
func (vpv *VoltPortVnet) CheckAndDeleteVpv(cntx context.Context) {
+ logger.Debugw(ctx, "Check And Delete Vpv", log.Fields{"VPV Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
vpv.PendingFlowLock.RLock()
defer vpv.PendingFlowLock.RUnlock()
if !vpv.DeleteInProgress {
+ logger.Warnw(ctx, "Skipping removing VPV from DB as VPV delete is in progress", log.Fields{"VPV Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
return
}
if len(vpv.PendingDeleteFlow) == 0 && !vpv.FlowsApplied {
- logger.Infow(ctx, "All Flows removed for VPV. Triggering VPV Deletion from DB", log.Fields{"VPV Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
+ logger.Debugw(ctx, "All Flows removed for VPV. Triggering VPV Deletion from DB", log.Fields{"VPV Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
vpv.DelFromDb(cntx)
logger.Infow(ctx, "Deleted VPV from DB/Cache successfully", log.Fields{"VPV Port": vpv.Port, "Device": vpv.Device, "Vnet": vpv.VnetName})
}
@@ -2900,7 +2948,7 @@
// FlowRemoveSuccess - Process flow success indication
func (vpv *VoltPortVnet) FlowRemoveSuccess(cntx context.Context, cookie string, device string) {
vpv.PendingFlowLock.Lock()
- logger.Infow(ctx, "VPV Flow Remove Success Notification", log.Fields{"Port": vpv.Port, "Cookie": cookie, "Device": device})
+ logger.Debugw(ctx, "VPV Flow Remove Success Notification", log.Fields{"Port": vpv.Port, "Cookie": cookie, "Device": device})
delete(vpv.PendingDeleteFlow, cookie)
vpv.PendingFlowLock.Unlock()
@@ -2912,7 +2960,7 @@
func (vpv *VoltPortVnet) FlowRemoveFailure(cntx context.Context, cookie string, device string, errorCode uint32, errReason string) {
vpv.PendingFlowLock.Lock()
- logger.Errorw(ctx, "VPV Flow Remove Failure Notification", log.Fields{"Port": vpv.Port, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason, "Device": device})
+ logger.Debugw(ctx, "VPV Flow Remove Failure Notification", log.Fields{"Port": vpv.Port, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason, "Device": device})
sendFlowFailureInd := func(key, value interface{}) bool {
svc := value.(*VoltService)
@@ -2934,6 +2982,7 @@
// RemoveFlows - Triggers flow deletion after registering for flow indication event
func (vv *VoltVnet) RemoveFlows(cntx context.Context, device *VoltDevice, flow *of.VoltFlow) error {
+ logger.Debugw(ctx, "Remove Flows", log.Fields{"PortName": flow.PortName, "DeviceName": device.Name})
vv.VnetLock.Lock()
defer vv.VnetLock.Unlock()
@@ -2961,7 +3010,9 @@
// CheckAndDeleteVnet - remove Vnet from DB is there are no pending flows to be removed
func (vv *VoltVnet) CheckAndDeleteVnet(cntx context.Context, device string) {
+ logger.Debugw(ctx, "Check And Delete Vnet", log.Fields{"Device": device, "Vnet": vv.Name})
if !vv.DeleteInProgress {
+ logger.Warnw(ctx, "Skipping removing Vnet from DB as Vnet delete is in progress", log.Fields{"Name": vv.Name, "AssociatedPorts": vv.AssociatedPorts, "Device": device})
return
}
vv.VnetPortLock.RLock()
@@ -2981,7 +3032,7 @@
vv.VnetLock.Lock()
defer vv.VnetLock.Unlock()
- logger.Infow(ctx, "Vnet Flow Remove Success Notification", log.Fields{"VnetProfile": vv.Name, "Cookie": cookie, "Device": device})
+ logger.Debugw(ctx, "Vnet Flow Remove Success Notification", log.Fields{"VnetProfile": vv.Name, "Cookie": cookie, "Device": device})
if _, ok := vv.PendingDeleteFlow[device]; ok {
delete(vv.PendingDeleteFlow[device], cookie)
@@ -3001,10 +3052,11 @@
func (vv *VoltVnet) FlowRemoveFailure(cntx context.Context, cookie string, device string, errorCode uint32, errReason string) {
vv.VnetLock.Lock()
defer vv.VnetLock.Unlock()
+ logger.Debugw(ctx, "Vnet Flow Remove Failure Notification", log.Fields{"VnetProfile": vv.Name, "Cookie": cookie, "Device": device, "ErrorCode": errorCode, "ErrorReason": errReason})
if flowMap, ok := vv.PendingDeleteFlow[device]; ok {
if _, ok := flowMap[cookie]; ok {
- logger.Errorw(ctx, "Device Flow Remove Failure Notification", log.Fields{"Vnet": vv.Name, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason, "Device": device})
+ logger.Debugw(ctx, "Device Flow Remove Failure Notification", log.Fields{"Vnet": vv.Name, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason, "Device": device})
if vv.DeleteInProgress {
delete(vv.PendingDeleteFlow[device], cookie)
@@ -3013,13 +3065,14 @@
return
}
}
- logger.Errorw(ctx, "Device Flow Remove Failure Notification for Unknown cookie", log.Fields{"Vnet": vv.Name, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason})
+ logger.Debugw(ctx, "Device Flow Remove Failure Notification for Unknown cookie", log.Fields{"Vnet": vv.Name, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason})
}
// IgmpFlowInstallFailure - Process flow failure indication and triggers HSIA failure for Igmp enabled services
func (vpv *VoltPortVnet) IgmpFlowInstallFailure(cookie string, errorCode uint32, errReason string) {
// Note: Current implementation supports only for single service with Igmp Enabled for a subscriber
// When multiple Igmp-suported service enabled, comment "return false"
+ logger.Debugw(ctx, "Igmp Flow Install Failure", log.Fields{"Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason})
sendFlowFailureInd := func(key, value interface{}) bool {
svc := value.(*VoltService)
@@ -3029,12 +3082,13 @@
}
return true
}
- logger.Errorw(ctx, "US IGMP Flow Failure Notification", log.Fields{"uniPort": vpv.Port, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason})
+ logger.Debugw(ctx, "US IGMP Flow Failure Notification", log.Fields{"uniPort": vpv.Port, "Cookie": cookie, "ErrorCode": errorCode, "ErrorReason": errReason})
vpv.services.Range(sendFlowFailureInd)
}
// GetMatchingMcastService to get matching multicast service
func (va *VoltApplication) GetMatchingMcastService(port string, device string, cvlan of.VlanType) *VoltService {
+ logger.Debugw(ctx, "Get Matching Mcast Service", log.Fields{"Port": port, "Device": device, "Cvlan": cvlan})
var service *VoltService
dIntf, ok := va.DevicesDisc.Load(device)
if !ok {
@@ -3082,6 +3136,7 @@
// TriggerAssociatedFlowDelete - Re-trigger delete for pending delete flows
func (vv *VoltVnet) TriggerAssociatedFlowDelete(cntx context.Context, device string) bool {
+ logger.Infow(ctx, "Trigger Associated Flow Delete", log.Fields{"Device": device})
vv.VnetLock.Lock()
cookieList := []uint64{}
flowMap := vv.PendingDeleteFlow[device]
@@ -3174,6 +3229,7 @@
}
func (vpv *VoltPortVnet) IsServiceActivated(cntx context.Context) bool {
+ logger.Debugw(ctx, "Is Service Activated", log.Fields{"Name": vpv.Port})
isActivated := false
vpv.services.Range(func(key, value interface{}) bool {
svc := value.(*VoltService)