Skip to content

chore: improve IPAM logging #3049

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Oct 7, 2024
Merged

chore: improve IPAM logging #3049

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions cns/ipampool/v2/monitor.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -124,6 +124,7 @@ func (pm *Monitor) reconcile(ctx context.Context) error {
pm.z.Info("calculated new request", zap.Int64("demand", pm.demand), zap.Int64("batch", s.batch), zap.Int64("max", s.max), zap.Float64("buffer", s.buffer), zap.Int64("target", target))
delta := target - pm.request
if delta == 0 {
pm.z.Info("NNC already at target IPs, no scaling required")
return nil
}
pm.z.Info("scaling pool", zap.Int64("delta", delta))
Expand Down
4 changes: 2 additions & 2 deletions cns/kubecontroller/pod/reconciler.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,11 +61,11 @@ type limiter interface {
// any events.
// listeners are called with the new Pod list.
func (p *watcher) NewNotifierFunc(listOpts *client.ListOptions, limiter limiter, listeners ...func([]v1.Pod)) reconcile.Func {
p.z.Debug("adding notified for listeners", zap.Int("listeners", len(listeners)))
p.z.Info("adding notifier for listeners", zap.Int("listeners", len(listeners)))
return func(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
if !limiter.Allow() {
// rate limit exceeded, requeue
p.z.Debug("rate limit exceeded")
p.z.Info("rate limit exceeded")
return ctrl.Result{Requeue: true}, nil
}
podList := &v1.PodList{}
Expand Down
1 change: 0 additions & 1 deletion cns/restserver/internalapi.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -563,7 +563,6 @@ func (service *HTTPRestService) CreateOrUpdateNetworkContainerInternal(req *cns.
// If the NC was created successfully, log NC snapshot.
if returnCode == 0 {
logNCSnapshot(*req)

publishIPStateMetrics(service.buildIPState())
} else {
logger.Errorf(returnMessage)
Expand Down
70 changes: 39 additions & 31 deletions cns/restserver/ipam.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -196,10 +196,10 @@ func (service *HTTPRestService) updatePodInfoWithInterfaces(ctx context.Context,

// RequestIPConfigHandler requests an IPConfig from the CNS state
func (service *HTTPRestService) RequestIPConfigHandler(w http.ResponseWriter, r *http.Request) {
opName := "requestIPConfigHandler"
var ipconfigRequest cns.IPConfigRequest
err := common.Decode(w, r, &ipconfigRequest)
operationName := "requestIPConfigHandler"
logger.Request(service.Name+operationName, ipconfigRequest, err)
logger.Request(opName, ipconfigRequest, err)
if err != nil {
return
}
Expand All @@ -215,7 +215,7 @@ func (service *HTTPRestService) RequestIPConfigHandler(w http.ResponseWriter, r
}
w.Header().Set(cnsReturnCode, reserveResp.Response.ReturnCode.String())
err = common.Encode(w, &reserveResp)
logger.ResponseEx(service.Name+operationName, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
return
}

Expand All @@ -240,7 +240,7 @@ func (service *HTTPRestService) RequestIPConfigHandler(w http.ResponseWriter, r
}
w.Header().Set(cnsReturnCode, reserveResp.Response.ReturnCode.String())
err = common.Encode(w, &reserveResp)
logger.ResponseEx(service.Name+operationName, ipconfigsRequest, reserveResp, reserveResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, reserveResp, reserveResp.Response.ReturnCode, err)
return
}

Expand All @@ -256,7 +256,7 @@ func (service *HTTPRestService) RequestIPConfigHandler(w http.ResponseWriter, r
}
w.Header().Set(cnsReturnCode, reserveResp.Response.ReturnCode.String())
err = common.Encode(w, &reserveResp)
logger.ResponseEx(service.Name+operationName, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
return
}
// As this API is expected to return IPConfigResponse, generate it from the IPConfigsResponse returned above.
Expand All @@ -266,15 +266,15 @@ func (service *HTTPRestService) RequestIPConfigHandler(w http.ResponseWriter, r
}
w.Header().Set(cnsReturnCode, reserveResp.Response.ReturnCode.String())
err = common.Encode(w, &reserveResp)
logger.ResponseEx(service.Name+operationName, ipconfigsRequest, reserveResp, reserveResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, reserveResp, reserveResp.Response.ReturnCode, err)
}

// RequestIPConfigsHandler requests multiple IPConfigs from the CNS state
func (service *HTTPRestService) RequestIPConfigsHandler(w http.ResponseWriter, r *http.Request) {
opName := "requestIPConfigsHandler"
var ipconfigsRequest cns.IPConfigsRequest
err := common.Decode(w, r, &ipconfigsRequest)
operationName := "requestIPConfigsHandler"
logger.Request(service.Name+operationName, ipconfigsRequest, err)
logger.Request(opName, ipconfigsRequest, err)
if err != nil {
return
}
Expand All @@ -300,13 +300,13 @@ func (service *HTTPRestService) RequestIPConfigsHandler(w http.ResponseWriter, r
if err != nil {
w.Header().Set(cnsReturnCode, ipConfigsResp.Response.ReturnCode.String())
err = common.Encode(w, &ipConfigsResp)
logger.ResponseEx(service.Name+operationName, ipconfigsRequest, ipConfigsResp, ipConfigsResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, ipConfigsResp, ipConfigsResp.Response.ReturnCode, err)
return
}

w.Header().Set(cnsReturnCode, ipConfigsResp.Response.ReturnCode.String())
err = common.Encode(w, &ipConfigsResp)
logger.ResponseEx(service.Name+operationName, ipconfigsRequest, ipConfigsResp, ipConfigsResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, ipConfigsResp, ipConfigsResp.Response.ReturnCode, err)
}

func (service *HTTPRestService) updateEndpointState(ipconfigsRequest cns.IPConfigsRequest, podInfo cns.PodInfo, podIPInfo []cns.PodIpInfo) error {
Expand Down Expand Up @@ -414,9 +414,10 @@ func (service *HTTPRestService) ReleaseIPConfigHandlerHelper(ctx context.Context

// ReleaseIPConfigHandler frees the IP assigned to a pod from CNS
func (service *HTTPRestService) ReleaseIPConfigHandler(w http.ResponseWriter, r *http.Request) {
opName := "releaseIPConfigHandler"
var ipconfigRequest cns.IPConfigRequest
err := common.Decode(w, r, &ipconfigRequest)
logger.Request(service.Name+"releaseIPConfigHandler", ipconfigRequest, err)
logger.Request(opName, ipconfigRequest, err)
if err != nil {
resp := cns.Response{
ReturnCode: types.UnexpectedError,
Expand All @@ -425,7 +426,7 @@ func (service *HTTPRestService) ReleaseIPConfigHandler(w http.ResponseWriter, r
logger.Errorf("releaseIPConfigHandler decode failed becase %v, release IP config info %s", resp.Message, ipconfigRequest)
w.Header().Set(cnsReturnCode, resp.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigRequest, resp, resp.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, resp, resp.ReturnCode, err)
return
}

Expand All @@ -439,7 +440,7 @@ func (service *HTTPRestService) ReleaseIPConfigHandler(w http.ResponseWriter, r
}
w.Header().Set(cnsReturnCode, reserveResp.Response.ReturnCode.String())
err = common.Encode(w, &reserveResp)
logger.ResponseEx(service.Name, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, reserveResp, reserveResp.Response.ReturnCode, err)
return
}

Expand All @@ -457,19 +458,20 @@ func (service *HTTPRestService) ReleaseIPConfigHandler(w http.ResponseWriter, r
if err != nil {
w.Header().Set(cnsReturnCode, resp.Response.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigRequest, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, resp, resp.Response.ReturnCode, err)
}

w.Header().Set(cnsReturnCode, resp.Response.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigRequest, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigRequest, resp, resp.Response.ReturnCode, err)
}

// ReleaseIPConfigsHandler frees multiple IPConfigs from the CNS state
func (service *HTTPRestService) ReleaseIPConfigsHandler(w http.ResponseWriter, r *http.Request) {
opName := "releaseIPConfigsHandler"
var ipconfigsRequest cns.IPConfigsRequest
err := common.Decode(w, r, &ipconfigsRequest)
logger.Request(service.Name+"releaseIPConfigsHandler", ipconfigsRequest, err)
logger.Request("releaseIPConfigsHandler", ipconfigsRequest, err)
if err != nil {
resp := cns.Response{
ReturnCode: types.UnexpectedError,
Expand All @@ -478,20 +480,20 @@ func (service *HTTPRestService) ReleaseIPConfigsHandler(w http.ResponseWriter, r
logger.Errorf("releaseIPConfigsHandler decode failed because %v, release IP config info %+v", resp.Message, ipconfigsRequest)
w.Header().Set(cnsReturnCode, resp.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigsRequest, resp, resp.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, resp, resp.ReturnCode, err)
return
}

resp, err := service.ReleaseIPConfigHandlerHelper(r.Context(), ipconfigsRequest)
if err != nil {
w.Header().Set(cnsReturnCode, resp.Response.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigsRequest, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, resp, resp.Response.ReturnCode, err)
}

w.Header().Set(cnsReturnCode, resp.Response.ReturnCode.String())
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, ipconfigsRequest, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, ipconfigsRequest, resp, resp.Response.ReturnCode, err)
}

func (service *HTTPRestService) removeEndpointState(podInfo cns.PodInfo) error {
Expand Down Expand Up @@ -672,16 +674,18 @@ func (service *HTTPRestService) GetPodIPConfigState() map[string]cns.IPConfigura
}

func (service *HTTPRestService) HandleDebugPodContext(w http.ResponseWriter, r *http.Request) { //nolint
opName := "handleDebugPodContext"
service.RLock()
defer service.RUnlock()
resp := cns.GetPodContextResponse{
PodContext: service.PodIPIDByPodInterfaceKey,
}
err := common.Encode(w, &resp)
logger.Response(service.Name, resp, resp.Response.ReturnCode, err)
logger.Response(opName, resp, resp.Response.ReturnCode, err)
}

func (service *HTTPRestService) HandleDebugRestData(w http.ResponseWriter, r *http.Request) { //nolint
opName := "handleDebugRestData"
service.RLock()
defer service.RUnlock()
resp := GetHTTPServiceDataResponse{
Expand All @@ -691,10 +695,11 @@ func (service *HTTPRestService) HandleDebugRestData(w http.ResponseWriter, r *ht
},
}
err := common.Encode(w, &resp)
logger.Response(service.Name, resp, resp.Response.ReturnCode, err)
logger.Response(opName, resp, resp.Response.ReturnCode, err)
}

func (service *HTTPRestService) HandleDebugIPAddresses(w http.ResponseWriter, r *http.Request) {
opName := "handleDebugIPAddresses"
var req cns.GetIPAddressesRequest
if err := common.Decode(w, r, &req); err != nil {
resp := cns.GetIPAddressStatusResponse{
Expand All @@ -704,15 +709,15 @@ func (service *HTTPRestService) HandleDebugIPAddresses(w http.ResponseWriter, r
},
}
err = common.Encode(w, &resp)
logger.ResponseEx(service.Name, req, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, req, resp, resp.Response.ReturnCode, err)
return
}
// Get all IPConfigs matching a state and return in the response
resp := cns.GetIPAddressStatusResponse{
IPConfigurationStatus: filter.MatchAnyIPConfigState(service.PodIPConfigState, filter.PredicatesForStates(req.IPConfigStateFilter...)...),
}
err := common.Encode(w, &resp)
logger.ResponseEx(service.Name, req, resp, resp.Response.ReturnCode, err)
logger.ResponseEx(opName, req, resp, resp.Response.ReturnCode, err)
}

// GetAssignedIPConfigs returns a filtered list of IPs which are in
Expand Down Expand Up @@ -1093,6 +1098,7 @@ func validateDesiredIPAddresses(desiredIPs []string) error {

// EndpointHandlerAPI forwards the endpoint related APIs to GetEndpointHandler or UpdateEndpointHandler based on the http method
func (service *HTTPRestService) EndpointHandlerAPI(w http.ResponseWriter, r *http.Request) {
opName := "endpointHandler"
logger.Printf("[EndpointHandlerAPI] EndpointHandlerAPI received request with http Method %s", r.Method)
service.Lock()
defer service.Unlock()
Expand All @@ -1103,7 +1109,7 @@ func (service *HTTPRestService) EndpointHandlerAPI(w http.ResponseWriter, r *htt
Message: fmt.Sprintf("[EndpointHandlerAPI] EndpointHandlerAPI failed with error: %s", ErrOptManageEndpointState),
}
err := common.Encode(w, &response)
logger.Response(service.Name, response, response.ReturnCode, err)
logger.Response(opName, response, response.ReturnCode, err)
return
}
switch r.Method {
Expand All @@ -1118,6 +1124,7 @@ func (service *HTTPRestService) EndpointHandlerAPI(w http.ResponseWriter, r *htt

// GetEndpointHandler handles the incoming GetEndpoint requests with http Get method
func (service *HTTPRestService) GetEndpointHandler(w http.ResponseWriter, r *http.Request) {
opName := "getEndpointState"
logger.Printf("[GetEndpointState] GetEndpoint for %s", r.URL.Path)
endpointID := strings.TrimPrefix(r.URL.Path, cns.EndpointPath)
endpointInfo, err := service.GetEndpointHelper(endpointID)
Expand All @@ -1139,7 +1146,7 @@ func (service *HTTPRestService) GetEndpointHandler(w http.ResponseWriter, r *htt
}
w.Header().Set(cnsReturnCode, response.Response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.Response.ReturnCode, err)
logger.Response(opName, response, response.Response.ReturnCode, err)
return
}
response := GetEndpointResponse{
Expand All @@ -1151,7 +1158,7 @@ func (service *HTTPRestService) GetEndpointHandler(w http.ResponseWriter, r *htt
}
w.Header().Set(cnsReturnCode, response.Response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.Response.ReturnCode, err)
logger.Response(opName, response, response.Response.ReturnCode, err)
}

// GetEndpointHelper returns the state of the given endpointId
Expand Down Expand Up @@ -1192,12 +1199,13 @@ func (service *HTTPRestService) GetEndpointHelper(endpointID string) (*EndpointI

// UpdateEndpointHandler handles the incoming UpdateEndpoint requests with http Patch method
func (service *HTTPRestService) UpdateEndpointHandler(w http.ResponseWriter, r *http.Request) {
opName := "UpdateEndpointHandler"
logger.Printf("[updateEndpoint] updateEndpoint for %s", r.URL.Path)

var req map[string]*IPInfo
err := common.Decode(w, r, &req)
endpointID := strings.TrimPrefix(r.URL.Path, cns.EndpointPath)
logger.Request(service.Name, &req, err)
logger.Request(opName, &req, err)
// Check if the request is valid
if err != nil {
response := cns.Response{
Expand All @@ -1206,7 +1214,7 @@ func (service *HTTPRestService) UpdateEndpointHandler(w http.ResponseWriter, r *
}
w.Header().Set(cnsReturnCode, response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.ReturnCode, err)
logger.Response(opName, response, response.ReturnCode, err)
return
}
if err = verifyUpdateEndpointStateRequest(req); err != nil {
Expand All @@ -1216,7 +1224,7 @@ func (service *HTTPRestService) UpdateEndpointHandler(w http.ResponseWriter, r *
}
w.Header().Set(cnsReturnCode, response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.ReturnCode, err)
logger.Response(opName, response, response.ReturnCode, err)
return
}
// Update the endpoint state
Expand All @@ -1228,7 +1236,7 @@ func (service *HTTPRestService) UpdateEndpointHandler(w http.ResponseWriter, r *
}
w.Header().Set(cnsReturnCode, response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.ReturnCode, err)
logger.Response(opName, response, response.ReturnCode, err)
return
}
response := cns.Response{
Expand All @@ -1237,7 +1245,7 @@ func (service *HTTPRestService) UpdateEndpointHandler(w http.ResponseWriter, r *
}
w.Header().Set(cnsReturnCode, response.ReturnCode.String())
err = common.Encode(w, &response)
logger.Response(service.Name, response, response.ReturnCode, err)
logger.Response(opName, response, response.ReturnCode, err)
}

// UpdateEndpointHelper updates the state of the given endpointId with HNSId, VethName or other InterfaceInfo fields
Expand Down
2 changes: 1 addition & 1 deletion cns/restserver/metrics.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -143,7 +143,7 @@ func stateTransitionMiddleware(i *cns.IPConfigurationStatus, s types.IPState) {
}

func publishIPStateMetrics(state *ipState) {
labels := []string{} // TODO. ragasthya Add dimensions to the IP Usage metrics.
labels := []string{}
allocatedIPCount.WithLabelValues(labels...).Set(float64(state.allocatedIPs))
assignedIPCount.WithLabelValues(labels...).Set(float64(state.assignedIPs))
availableIPCount.WithLabelValues(labels...).Set(float64(state.availableIPs))
Expand Down