Logging improvement for VGC-APPLICATION
Change-Id: I35c10b43917d5f962484f05c3fb9d9aad67e63f5
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)