Skip to content

Commit dc7ff48

Browse files
authored
Fix log which let log to show more readable info. (#803)
Address feedback.
1 parent 580eb0c commit dc7ff48

File tree

4 files changed

+54
-13
lines changed

4 files changed

+54
-13
lines changed

cns/logger/log.go

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -164,6 +164,26 @@ func Response(tag string, response interface{}, returnCode int, returnStr string
164164
sendTraceInternal(msg)
165165
}
166166

167+
// ResponseEx put request and response info together to help easier debug.
168+
func ResponseEx(tag string, request interface{}, response interface{}, returnCode int, returnStr string, err error) {
169+
Log.logger.ResponseEx(tag, request, response, returnCode, returnStr, err)
170+
171+
if Log.th == nil || Log.DisableTraceLogging {
172+
return
173+
}
174+
175+
var msg string
176+
if err == nil && returnCode == 0 {
177+
msg = fmt.Sprintf("[%s] Sent %T %+v %T %+v.", tag, request, request, response, response)
178+
} else if err != nil {
179+
msg = fmt.Sprintf("[%s] Code:%s, %+v, %+v, %s.", tag, returnStr, request, response, err.Error())
180+
} else {
181+
msg = fmt.Sprintf("[%s] Code:%s, %+v, %+v.", tag, returnStr, request, response)
182+
}
183+
184+
sendTraceInternal(msg)
185+
}
186+
167187
// Send AI telemetry metric
168188
func SendMetric(metric aitelemetry.Metric) {
169189
if Log.th == nil || Log.DisableMetricLogging {

cns/nmagentclient/nmagentclient.go

Lines changed: 3 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -200,12 +200,11 @@ func (nmagentclient *NMAgentClient) GetNcVersionListWithOutToken(ncNeedUpdateLis
200200

201201
var nmaNcListResponse NMANetworkContainerListResponse
202202
rBytes, _ := ioutil.ReadAll(response.Body)
203-
logger.Printf("Response body is %v", rBytes)
204-
json.Unmarshal(rBytes, &nmaNcListResponse)
205-
if nmaNcListResponse.ResponseCode != strconv.Itoa(http.StatusOK) {
206-
logger.Printf("[NMAgentClient][Response] GetNcVersionListWithOutToken unmarshal failed with %s", rBytes)
203+
if err := json.Unmarshal(rBytes, &nmaNcListResponse); err != nil {
204+
logger.Printf("[NMAgentClient][Response] GetNcVersionListWithOutToken unmarshal failed with %s", err)
207205
return nil
208206
}
207+
logger.Printf("NMAgent NC List Response is %s", nmaNcListResponse)
209208

210209
var receivedNcVersionListInMap = make(map[string]string)
211210
for _, containers := range nmaNcListResponse.Containers {

cns/restserver/ipam.go

Lines changed: 20 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,8 @@ func (service *HTTPRestService) requestIPConfigHandler(w http.ResponseWriter, r
2525
)
2626

2727
err = service.Listener.Decode(w, r, &ipconfigRequest)
28-
logger.Request(service.Name, &ipconfigRequest, err)
28+
operationName := "requestIPConfigHandler"
29+
logger.Request(service.Name+operationName, ipconfigRequest, err)
2930
if err != nil {
3031
return
3132
}
@@ -35,7 +36,7 @@ func (service *HTTPRestService) requestIPConfigHandler(w http.ResponseWriter, r
3536
if returnCode == Success {
3637
if podIpInfo, err = requestIPConfigHelper(service, ipconfigRequest); err != nil {
3738
returnCode = FailedToAllocateIpConfig
38-
returnMessage = fmt.Sprintf("AllocateIPConfig failed: %v", err)
39+
returnMessage = fmt.Sprintf("AllocateIPConfig failed: %v, IP config request is %s", err, ipconfigRequest)
3940
}
4041
}
4142

@@ -50,7 +51,7 @@ func (service *HTTPRestService) requestIPConfigHandler(w http.ResponseWriter, r
5051
reserveResp.PodIpInfo = podIpInfo
5152

5253
err = service.Listener.Encode(w, &reserveResp)
53-
logger.Response(service.Name, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)
54+
logger.ResponseEx(service.Name+operationName, ipconfigRequest, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)
5455
}
5556

5657
func (service *HTTPRestService) releaseIPConfigHandler(w http.ResponseWriter, r *http.Request) {
@@ -62,6 +63,7 @@ func (service *HTTPRestService) releaseIPConfigHandler(w http.ResponseWriter, r
6263
)
6364

6465
statusCode = UnexpectedError
66+
operationName := "releaseIPConfigHandler"
6567

6668
defer func() {
6769
resp := cns.Response{}
@@ -72,13 +74,15 @@ func (service *HTTPRestService) releaseIPConfigHandler(w http.ResponseWriter, r
7274
}
7375

7476
err = service.Listener.Encode(w, &resp)
75-
logger.Response(service.Name, resp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)
77+
logger.ResponseEx(service.Name, req, resp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)
7678
}()
7779

7880
err = service.Listener.Decode(w, r, &req)
79-
logger.Request(service.Name, &req, err)
81+
logger.Request(service.Name+operationName, req, err)
8082
if err != nil {
8183
returnMessage = err.Error()
84+
logger.Errorf("releaseIPConfigHandler decode failed becase %v, release IP config info %s",
85+
returnMessage, req)
8286
return
8387
}
8488

@@ -87,6 +91,7 @@ func (service *HTTPRestService) releaseIPConfigHandler(w http.ResponseWriter, r
8791
if err = service.releaseIPConfig(podInfo); err != nil {
8892
statusCode = NotFound
8993
returnMessage = err.Error()
94+
logger.Errorf("releaseIPConfigHandler releaseIPConfig failed because %v, release IP config info %s", returnMessage, req)
9095
return
9196
}
9297
return
@@ -212,12 +217,14 @@ func (service *HTTPRestService) getIPAddressesHandler(w http.ResponseWriter, r *
212217
}
213218

214219
err = service.Listener.Encode(w, &resp)
215-
logger.Response(service.Name, resp, resp.Response.ReturnCode, ReturnCodeToString(resp.Response.ReturnCode), err)
220+
logger.ResponseEx(service.Name, req, resp, resp.Response.ReturnCode, ReturnCodeToString(resp.Response.ReturnCode), err)
216221
}()
217222

218223
err = service.Listener.Decode(w, r, &req)
219224
if err != nil {
220225
returnMessage = err.Error()
226+
logger.Errorf("getIPAddressesHandler decode failed because %v, GetIPAddressesRequest is %v",
227+
returnMessage, req)
221228
return
222229
}
223230

@@ -311,6 +318,8 @@ func (service *HTTPRestService) setIPConfigAsAvailable(ipconfig cns.IPConfigurat
311318
}
312319

313320
delete(service.PodIPIDByOrchestratorContext, podInfo.GetOrchestratorContextKey())
321+
logger.Printf("[setIPConfigAsAvailable] Deleted outdated pod info %s from PodIPIDByOrchestratorContext since IP %s with ID %s will be released and set as Available",
322+
podInfo.GetOrchestratorContextKey(), ipconfig.IPAddress, ipconfig.ID)
314323
return ipconfig, nil
315324
}
316325

@@ -324,15 +333,17 @@ func (service *HTTPRestService) releaseIPConfig(podInfo cns.KubernetesPodInfo) e
324333
ipID := service.PodIPIDByOrchestratorContext[podInfo.GetOrchestratorContextKey()]
325334
if ipID != "" {
326335
if ipconfig, isExist := service.PodIPConfigState[ipID]; isExist {
336+
logger.Printf("[releaseIPConfig] Releasing IP %+v for pod %+v", ipconfig.IPAddress, podInfo)
327337
_, err := service.setIPConfigAsAvailable(ipconfig, podInfo)
328338
if err != nil {
329339
return fmt.Errorf("[releaseIPConfig] failed to mark IPConfig [%+v] as Available. err: %v", ipconfig, err)
330340
}
331341
logger.Printf("[releaseIPConfig] Released IP %+v for pod %+v", ipconfig.IPAddress, podInfo)
332-
333342
} else {
334-
logger.Errorf("[releaseIPConfig] Failed to get release ipconfig. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt")
335-
return fmt.Errorf("[releaseIPConfig] releaseIPConfig failed. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt")
343+
logger.Errorf("[releaseIPConfig] Failed to get release ipconfig %+v and pod info is %+v. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt",
344+
ipconfig.IPAddress, podInfo)
345+
return fmt.Errorf("[releaseIPConfig] releaseIPConfig failed. IPconfig %+v and pod info is %+v. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt",
346+
ipconfig.IPAddress, podInfo)
336347
}
337348
} else {
338349
logger.Errorf("[releaseIPConfig] SetIPConfigAsAvailable failed to release, no allocation found for pod [%+v]", podInfo)

log/logger.go

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -189,6 +189,17 @@ func (logger *Logger) Response(tag string, response interface{}, returnCode int,
189189
}
190190
}
191191

192+
// ResponseEx logs a structured response and the request associate with it.
193+
func (logger *Logger) ResponseEx(tag string, request interface{}, response interface{}, returnCode int, returnStr string, err error) {
194+
if err == nil && returnCode == 0 {
195+
logger.Printf("[%s] Sent %T %+v %T %+v.", tag, request, request, response, response)
196+
} else if err != nil {
197+
logger.Errorf("[%s] Code:%s, %+v, %+v %s.", tag, returnStr, request, response, err.Error())
198+
} else {
199+
logger.Errorf("[%s] Code:%s, %+v, %+v.", tag, returnStr, request, response)
200+
}
201+
}
202+
192203
// logf logs a formatted string.
193204
func (logger *Logger) logf(format string, args ...interface{}) {
194205
if logger.callCount%rotationCheckFrq == 0 {

0 commit comments

Comments
 (0)