FTTH-50632 [log modification of controller and vpagent package]
Change-Id: Ib46bd1dbd7ba759a1b25f22b377dcefa3a289919
diff --git a/internal/pkg/controller/addflows.go b/internal/pkg/controller/addflows.go
index b303947..7524d00 100644
--- a/internal/pkg/controller/addflows.go
+++ b/internal/pkg/controller/addflows.go
@@ -122,7 +122,7 @@
portName, _ := aft.device.GetPortName(aft.flow.PortID)
if aft.flow.PortName != portName && portName != "" {
for _, flow := range aft.flow.SubFlows {
- logger.Errorw(ctx, "Skip Flow Update", log.Fields{"Reason": "Port Deleted", "PortName": aft.flow.PortName, "PortNo": aft.flow.PortID, "Cookie": flow.Cookie, "Operation": aft.flow.Command})
+ logger.Warnw(ctx, "Skip Flow Update", log.Fields{"Reason": "Port Deleted", "PortName": aft.flow.PortName, "PortNo": aft.flow.PortID, "Cookie": flow.Cookie, "Operation": aft.flow.Command})
if aft.flow.Command == of.CommandDel {
aft.device.triggerFlowNotification(ctx, flow.Cookie, aft.flow.Command, of.BwAvailDetails{}, nil)
}
@@ -133,7 +133,7 @@
if !aft.device.isSBOperAllowed(aft.flow.ForceAction) {
for _, flow := range aft.flow.SubFlows {
- logger.Errorw(ctx, "Skipping Flow Table Update", log.Fields{"Reason": "Device State not UP", "State": aft.device.State, "Cookie": flow.Cookie, "Operation": aft.flow.Command})
+ logger.Warnw(ctx, "Skipping Flow Table Update", log.Fields{"Reason": "Device State not UP", "State": aft.device.State, "Cookie": flow.Cookie, "Operation": aft.flow.Command})
}
return nil
}
@@ -151,7 +151,7 @@
// Do NOT retry incase of failure with reason: Entry Not Found
if aft.flow.Command == of.CommandDel && statusCode != uint32(infraerrorcode.ErrNotExists) {
if attempt != MaxRetryCount {
- logger.Errorw(ctx, "Retrying Flow Delete", log.Fields{"Cookie": flow.GetFlowMod().Cookie, "Attempt": attempt})
+ logger.Warnw(ctx, "Retrying Flow Delete", log.Fields{"Cookie": flow.GetFlowMod().Cookie, "Attempt": attempt})
attempt++
continue
}
diff --git a/internal/pkg/controller/auditdevice.go b/internal/pkg/controller/auditdevice.go
index b322737..fd2e8c8 100644
--- a/internal/pkg/controller/auditdevice.go
+++ b/internal/pkg/controller/auditdevice.go
@@ -84,7 +84,7 @@
// Start to start the task
func (ad *AuditDevice) Start(ctx context.Context, taskID uint8) error {
- logger.Warnw(ctx, "Audit Device Task Triggered", log.Fields{"Context": ctx, "taskId": taskID, "Device": ad.device.ID})
+ logger.Infow(ctx, "Audit Device Task Triggered", log.Fields{"Context": ctx, "taskId": taskID, "Device": ad.device.ID})
ad.taskID = taskID
ad.ctx = ctx
@@ -107,6 +107,7 @@
missingPorts := make(map[uint32]*ofp.OfpPort)
for _, ofpp := range ofpps.Items {
missingPorts[ofpp.OfpPort.PortNo] = ofpp.OfpPort
+ logger.Infow(ctx, "Missing Ports", log.Fields{"Ports": ofpp.OfpPort, "missingPorts": missingPorts})
}
var excessPorts []uint32
@@ -138,7 +139,7 @@
// 1st process the NNI port before all other ports so that the device state can be updated.
if vgcPort, ok := ad.device.PortsByID[NNIPortID]; ok {
- logger.Info(ctx, "Processing NNI port state")
+ logger.Infow(ctx, "Processing NNI port state", log.Fields{"PortNo": vgcPort.ID, "PortName": vgcPort.Name, "PortState": vgcPort.State})
processPortState(NNIPortID, vgcPort)
}
@@ -161,13 +162,13 @@
ad.AddMissingPorts(ctx, missingPorts)
ad.DelExcessPorts(ctx, excessPorts)
ad.device.deviceAuditInProgress = false
- logger.Warnw(ctx, "Audit Device Task Completed", log.Fields{"Context": ctx, "taskId": taskID, "Device": ad.device.ID})
+ logger.Infow(ctx, "Audit Device Task Completed", log.Fields{"Context": ctx, "taskId": taskID, "Device": ad.device.ID})
return nil
}
// AddMissingPorts to add the missing ports
func (ad *AuditDevice) AddMissingPorts(cntx context.Context, mps map[uint32]*ofp.OfpPort) {
- logger.Debugw(ctx, "Device Audit - Add Missing Ports", log.Fields{"NumPorts": len(mps)})
+ logger.Infow(ctx, "Device Audit - Add Missing Ports", log.Fields{"NumPorts": len(mps), "Ports": mps})
addMissingPort := func(mp *ofp.OfpPort) {
logger.Debugw(ctx, "Process Port Add Ind", log.Fields{"Port No": mp.PortNo, "Port Name": mp.Name})
@@ -175,7 +176,7 @@
// Error is ignored as it only drops duplicate ports
logger.Infow(ctx, "Calling AddPort", log.Fields{"No": mp.PortNo, "Name": mp.Name})
if err := ad.device.AddPort(cntx, mp); err != nil {
- logger.Warnw(ctx, "AddPort Failed", log.Fields{"No": mp.PortNo, "Name": mp.Name, "Reason": err})
+ logger.Warnw(ctx, "AddPort Failed", log.Fields{"Port No": mp.PortNo, "Port Name": mp.Name, "Reason": err})
}
if mp.State == uint32(ofp.OfpPortState_OFPPS_LIVE) {
ad.device.ProcessPortState(cntx, mp.PortNo, mp.State)
@@ -185,7 +186,7 @@
// 1st process the NNI port before all other ports so that the flow provisioning for UNIs can be enabled
if mp, ok := mps[NNIPortID]; ok {
- logger.Info(ctx, "Adding Missing NNI port")
+ logger.Debugw(ctx, "Adding Missing NNI port", log.Fields{"PortNo": mp.PortNo, "Port Name": mp.Name, "Port Status": mp.State})
addMissingPort(mp)
}
diff --git a/internal/pkg/controller/audittables.go b/internal/pkg/controller/audittables.go
index 26b250e..30e52f6 100644
--- a/internal/pkg/controller/audittables.go
+++ b/internal/pkg/controller/audittables.go
@@ -79,7 +79,7 @@
// Start is called by the framework and is responsible for implementing
// the actual task.
func (att *AuditTablesTask) Start(ctx context.Context, taskID uint8) error {
- logger.Warnw(ctx, "Audit Table Task Triggered", log.Fields{"Context": ctx, "taskId": taskID, "Device": att.device.ID})
+ logger.Infow(ctx, "Audit Table Task Triggered", log.Fields{"Context": ctx, "taskId": taskID, "Device": att.device.ID})
att.taskID = taskID
att.ctx = ctx
var errInfo error
@@ -111,9 +111,9 @@
// Triggering deletion of excess groups from device after the corresponding flows are removed
// to avoid flow dependency error during group deletion
- logger.Infow(ctx, "Excess Groups", log.Fields{"Groups": rcvdGroups})
+ logger.Debugw(ctx, "Excess Groups", log.Fields{"Groups": rcvdGroups})
att.DelExcessGroups(rcvdGroups)
- logger.Warnw(ctx, "Audit Table Task Completed", log.Fields{"Context": ctx, "taskId": taskID, "Device": att.device.ID})
+ logger.Infow(ctx, "Audit Table Task Completed", log.Fields{"Context": ctx, "taskId": taskID, "Device": att.device.ID})
return errInfo
}
@@ -576,7 +576,7 @@
}
// 1st process the NNI port before all other ports so that the device state can be updated.
if vgcPort, ok := att.device.PortsByID[NNIPortID]; ok {
- logger.Info(ctx, "Processing NNI port state")
+ logger.Debugw(ctx, "Processing NNI port state", log.Fields{"Port ID": vgcPort.ID, "Port Name": vgcPort.Name})
processPortState(NNIPortID, vgcPort)
}
@@ -592,7 +592,7 @@
}
if att.stop {
- logger.Errorw(ctx, "Audit Device Task Canceled", log.Fields{"Context": att.ctx, "Task": att.taskID})
+ logger.Warnw(ctx, "Audit Device Task Canceled", log.Fields{"Context": att.ctx, "Task": att.taskID})
return tasks.ErrTaskCancelError
}
att.AddMissingPorts(ctx, missingPorts)
@@ -602,7 +602,7 @@
// AddMissingPorts to add the missing ports
func (att *AuditTablesTask) AddMissingPorts(cntx context.Context, mps map[uint32]*ofp.OfpPort) {
- logger.Debugw(ctx, "Device Audit - Add Missing Ports", log.Fields{"NumPorts": len(mps)})
+ logger.Infow(ctx, "Device Audit - Add Missing Ports", log.Fields{"NumPorts": len(mps)})
addMissingPort := func(mp *ofp.OfpPort) {
logger.Debugw(ctx, "Process Port Add Ind", log.Fields{"Port No": mp.PortNo, "Port Name": mp.Name})
@@ -620,7 +620,7 @@
// 1st process the NNI port before all other ports so that the flow provisioning for UNIs can be enabled
if mp, ok := mps[NNIPortID]; ok {
- logger.Info(ctx, "Adding Missing NNI port")
+ logger.Debugw(ctx, "Adding Missing NNI port", log.Fields{"PortNo": mp.PortNo})
addMissingPort(mp)
}
diff --git a/internal/pkg/controller/changeevent.go b/internal/pkg/controller/changeevent.go
index 77e7e68..ae744d6 100644
--- a/internal/pkg/controller/changeevent.go
+++ b/internal/pkg/controller/changeevent.go
@@ -86,7 +86,7 @@
} else if status.PortStatus.Reason == ofp.OfpPortReason_OFPPR_MODIFY {
cet.device.ProcessPortUpdate(ctx, portName, portNo, state)
}
- logger.Infow(ctx, "Processed Port Change Event", log.Fields{"Port No": portNo, "Port Name": portName, "State": state, "Reason": status.PortStatus.Reason})
+ logger.Debugw(ctx, "Processed Port Change Event", log.Fields{"Port No": portNo, "Port Name": portName, "State": state, "Reason": status.PortStatus.Reason})
return nil
}
return errors.New("Invalid message received")
diff --git a/internal/pkg/controller/controller.go b/internal/pkg/controller/controller.go
index ffead2b..4e2c4eb 100644
--- a/internal/pkg/controller/controller.go
+++ b/internal/pkg/controller/controller.go
@@ -105,7 +105,7 @@
d.ConnectInd(context.TODO(), intf.DeviceDisc)
d.packetOutChannel = config.PacketOutChannel
- logger.Warnw(ctx, "Added device", log.Fields{"Device": config.DeviceID, "SerialNo": d.SerialNum, "State": d.State})
+ logger.Debugw(ctx, "Added device", log.Fields{"Device": config.DeviceID, "SerialNo": d.SerialNum, "State": d.State})
return d
}
@@ -119,7 +119,7 @@
}
v.app.DelDevice(cntx, id)
d.cancel() // To stop the device tables sync routine
- logger.Warnw(ctx, "Deleted device", log.Fields{"Device": id})
+ logger.Debugw(ctx, "Deleted device", log.Fields{"Device": id})
}
// AddControllerTask - add task to controller queue
@@ -568,11 +568,11 @@
logger.Info(ctx, "Entering into GetAllMeterInfo method")
meters := map[string][]*of.Meter{}
for _, device := range v.devices {
- logger.Infow(ctx, "Inside GetAllMeterInfo method", log.Fields{"deviceId": device.ID})
+ logger.Debugw(ctx, "Inside GetAllMeterInfo method", log.Fields{"deviceId": device.ID, "southbound": device.SouthBoundID, "serial no": device.SerialNum})
for _, meter := range device.meters {
meters[device.ID] = append(meters[device.ID], meter)
}
- logger.Infow(ctx, "Inside GetAllMeterInfo method", log.Fields{"meters": meters})
+ logger.Debugw(ctx, "Inside GetAllMeterInfo method", log.Fields{"meters": meters})
}
return meters, nil
}
@@ -581,14 +581,14 @@
logger.Info(ctx, "Entering into GetMeterInfo method")
meters := map[string]*of.Meter{}
for _, device := range v.devices {
- logger.Infow(ctx, "Inside GetMeterInfo method", log.Fields{"deviceId": device.ID})
+ logger.Debugw(ctx, "Inside GetMeterInfo method", log.Fields{"deviceId": device.ID})
meter, err := device.GetMeter(id)
if err != nil {
logger.Errorw(ctx, "Failed to fetch the meter", log.Fields{"Reason": err.Error()})
return nil, err
}
meters[device.ID] = meter
- logger.Infow(ctx, "Inside GetAllMeterInfo method", log.Fields{"Meter": meters})
+ logger.Debugw(ctx, "meters", log.Fields{"Meter": meters})
}
return meters, nil
}
@@ -599,7 +599,7 @@
for _, device := range v.devices {
device.groups.Range(func(key, value interface{}) bool {
groupID := key.(uint32)
- logger.Infow(ctx, "Inside GetGroupList method", log.Fields{"groupID": groupID})
+ logger.Debugw(ctx, "Inside GetGroupList method", log.Fields{"groupID": groupID})
//Obtain all groups associated with the device
grps, ok := device.groups.Load(groupID)
if !ok {
@@ -618,7 +618,7 @@
logger.Info(ctx, "Entering into GetGroupList method")
var groups *of.Group
for _, device := range v.devices {
- logger.Infow(ctx, "Inside GetGroupList method", log.Fields{"groupID": id})
+ logger.Debugw(ctx, "Inside GetGroupList method", log.Fields{"groupID": id})
grps, ok := device.groups.Load(id)
if !ok {
return nil, errors.New("Group not found")
diff --git a/internal/pkg/controller/controllertasks.go b/internal/pkg/controller/controllertasks.go
index ddffac2..1a2b26d 100644
--- a/internal/pkg/controller/controllertasks.go
+++ b/internal/pkg/controller/controllertasks.go
@@ -70,7 +70,7 @@
device := GetController().AddDevice(ctx, adt.config)
vpagent.GetVPAgent().AddClientToClientMap(adt.config.DeviceID, device)
- logger.Infow(ctx, "Add Device Task Completed", log.Fields{"Device": adt.config.DeviceID, "SerialNum": adt.config.SerialNum})
+ logger.Infow(ctx, "Add Device Task Completed", log.Fields{"Device": adt.config.DeviceID, "SerialNum": adt.config.SerialNum, "SouthBoundId": adt.config.SouthBoundID})
return nil
}
diff --git a/internal/pkg/controller/device.go b/internal/pkg/controller/device.go
index 3ac5600..0bafca7 100644
--- a/internal/pkg/controller/device.go
+++ b/internal/pkg/controller/device.go
@@ -170,7 +170,7 @@
var hash uint32
err = json.Unmarshal([]byte(flowHash), &hash)
if err != nil {
- logger.Error(ctx, "Failed to unmarshall flowhash")
+ logger.Errorw(ctx, "Failed to unmarshall flowhash", log.Fields{"data": flowHash})
} else {
device.flowHash = hash
}
@@ -191,7 +191,7 @@
func (d *Device) GetFlow(cookie uint64) (*of.VoltSubFlow, bool) {
d.flowLock.RLock()
defer d.flowLock.RUnlock()
- logger.Infow(ctx, "Get Flow", log.Fields{"Cookie": cookie})
+ logger.Debugw(ctx, "Get Flow", log.Fields{"Cookie": cookie})
flow, ok := d.flows[cookie]
return flow, ok
}
@@ -201,7 +201,7 @@
d.flowLock.RLock()
defer d.flowLock.RUnlock()
var flows []*of.VoltSubFlow
- logger.Infow(ctx, "Get All Flows", log.Fields{"deviceID": d.ID})
+ logger.Debugw(ctx, "Get All Flows", log.Fields{"deviceID": d.ID})
for _, f := range d.flows {
flows = append(flows, f)
}
@@ -213,7 +213,7 @@
d.flowLock.RLock()
defer d.flowLock.RUnlock()
var flows []*of.VoltSubFlow
- logger.Infow(ctx, "Get All Pending Flows", log.Fields{"deviceID": d.ID})
+ logger.Debugw(ctx, "Get All Pending Flows", log.Fields{"deviceID": d.ID})
for _, f := range d.flows {
if f.State == of.FlowAddPending {
flows = append(flows, f)
@@ -226,7 +226,7 @@
func (d *Device) AddFlow(cntx context.Context, flow *of.VoltSubFlow) error {
d.flowLock.Lock()
defer d.flowLock.Unlock()
- logger.Infow(ctx, "AddFlow to device", log.Fields{"Cookie": flow.Cookie})
+ logger.Debugw(ctx, "AddFlow to device", log.Fields{"Cookie": flow.Cookie})
if _, ok := d.flows[flow.Cookie]; ok {
return errors.New(ErrDuplicateFlow)
}
@@ -269,7 +269,7 @@
return false
} else if flow.OldCookie != 0 && flow.Cookie != flow.OldCookie {
if _, ok := d.flows[flow.OldCookie]; ok {
- logger.Infow(ctx, "Flow present with old cookie", log.Fields{"OldCookie": flow.OldCookie})
+ logger.Debugw(ctx, "Flow present with old cookie", log.Fields{"OldCookie": flow.OldCookie})
return true
}
}
@@ -281,7 +281,7 @@
d.flowLock.Lock()
defer d.flowLock.Unlock()
if _, ok := d.flows[flow.OldCookie]; ok {
- logger.Infow(ctx, "Flow was added before vgc upgrade. Trying to delete with old cookie",
+ logger.Debugw(ctx, "Flow was added before vgc upgrade. Trying to delete with old cookie",
log.Fields{"OldCookie": flow.OldCookie})
delete(d.flows, flow.OldCookie)
d.DelFlowFromDb(cntx, flow.OldCookie)
@@ -324,7 +324,7 @@
// UpdateGroupEntry - Adds/Updates the group to the device and also to the database
func (d *Device) UpdateGroupEntry(cntx context.Context, group *of.Group) {
- logger.Infow(ctx, "Update Group to device", log.Fields{"ID": group.GroupID})
+ logger.Debugw(ctx, "Update Group to device", log.Fields{"ID": group.GroupID})
d.groups.Store(group.GroupID, group)
d.AddGroupToDb(cntx, group)
}
@@ -332,7 +332,7 @@
// AddGroupToDb - Utility to add the group to the device DB
func (d *Device) AddGroupToDb(cntx context.Context, group *of.Group) {
if b, err := json.Marshal(group); err == nil {
- logger.Infow(ctx, "Adding Group to DB", log.Fields{"grp": group, "Json": string(b)})
+ logger.Debugw(ctx, "Adding Group to DB", log.Fields{"grp": group, "Json": string(b)})
if err = db.PutGroup(cntx, d.ID, group.GroupID, string(b)); err != nil {
logger.Errorw(ctx, "Write Group to DB failed", log.Fields{"device": d.ID, "groupID": group.GroupID, "Reason": err})
}
@@ -466,7 +466,7 @@
logger.Warnw(ctx, "Duplicate Meter", log.Fields{"ID": meter.ID})
}
} else {
- logger.Warn(ctx, "Unmarshal failed")
+ logger.Warnw(ctx, "Unmarshal failed", log.Fields{"error": err, "meter": string(b)})
}
}
@@ -636,7 +636,7 @@
logger.Warnw(ctx, "Duplicate Port", log.Fields{"ID": port.ID})
}
} else {
- logger.Warn(ctx, "Unmarshal failed")
+ logger.Warnw(ctx, "Unmarshal failed", log.Fields{"port": string(b)})
}
}
@@ -660,12 +660,12 @@
d.ctx = ctx1
d.Tasks.Initialize(ctx1)
- logger.Warnw(ctx, "Device State change Ind: UP", log.Fields{"Device": d.ID})
+ logger.Debugw(ctx, "Device State change Ind: UP", log.Fields{"Device": d.ID})
d.State = DeviceStateUP
d.TimeStamp = time.Now()
GetController().DeviceUpInd(d.ID)
- logger.Warnw(ctx, "Device State change Ind: UP, trigger Audit Tasks", log.Fields{"Device": d.ID})
+ logger.Debugw(ctx, "Device State change Ind: UP, trigger Audit Tasks", log.Fields{"Device": d.ID})
t := NewAuditDevice(d, AuditEventDeviceDisc)
d.Tasks.AddTask(t)
@@ -771,7 +771,7 @@
for _, port := range d.PortsByID {
if port.State != PortStateDown {
- logger.Infow(ctx, "Resetting Port State to DOWN and Write to DB", log.Fields{"Device": d.ID, "Port": port})
+ logger.Debugw(ctx, "Resetting Port State to DOWN and Write to DB", log.Fields{"Device": d.ID, "Port": port})
port.State = PortStateDown
d.WritePortToDb(cntx, port)
}
@@ -1025,11 +1025,11 @@
func (d *Device) writeFlowHashToDB(cntx context.Context) {
hash, err := json.Marshal(d.flowHash)
if err != nil {
- logger.Errorw(ctx, "failed to marshal flow hash", log.Fields{"hash": d.flowHash})
+ logger.Errorw(ctx, "failed to marshal flow hash", log.Fields{"hash": d.flowHash, "error": err})
return
}
if err := db.PutFlowHash(cntx, d.ID, string(hash)); err != nil {
- logger.Errorw(ctx, "Failed to add flow hash to DB", log.Fields{"device": d.ID, "hash": d.flowHash})
+ logger.Errorw(ctx, "Failed to add flow hash to DB", log.Fields{"device": d.ID, "hash": d.flowHash, "error": err})
}
}
diff --git a/internal/pkg/controller/modgroup.go b/internal/pkg/controller/modgroup.go
index 9fdb478..aca6440 100644
--- a/internal/pkg/controller/modgroup.go
+++ b/internal/pkg/controller/modgroup.go
@@ -87,7 +87,7 @@
log.Fields{"groupId": grp.group.GroupID, "groupOp": grp.group.Command, "Status": statusCode, "errorReason": statusMsg})
return false
}
- logger.Infow(ctx, "Group Mod Result", log.Fields{"groupID": grp.group.GroupID, "Error Code": statusCode})
+ logger.Debugw(ctx, "Group Mod Result", log.Fields{"groupID": grp.group.GroupID, "Error Code": statusCode})
return true
}
@@ -99,7 +99,7 @@
}
if !grp.device.isSBOperAllowed(grp.group.ForceAction) {
- logger.Errorw(ctx, "Skipping Group Table Update", log.Fields{"Reason": "Device State not UP", "State": grp.device.State, "GroupID": grp.group.GroupID, "Operation": grp.group.Command})
+ logger.Warnw(ctx, "Skipping Group Table Update", log.Fields{"Reason": "Device State not UP", "State": grp.device.State, "GroupID": grp.group.GroupID, "Operation": grp.group.Command})
return nil
}