Fix log which let log to show more readable info. #803

csfmomo · 2021-02-25T04:51:19Z

fix: repair 3 logs.

Reason for Change:
3 not-readable logs as following

// Should use body info instead of its address
Response body is [123 34 104 116 116 112 83 116 97 116 117 115 67 111 100 101 34 58 34 50 48 48 34 44 34 110 101 116 119 111 114 107 67 111 110 116 97 105 110 101 114 115 34 58 91 93 125]
// Should expose pod info for debugging
SetIPConfigAsAvailable failed to release, no allocation found for pod
// Should use decoded message
[azure-cns] Received *cns.IPConfigRequest &{DesiredIPAddress: OrchestratorContext:[123 34 80 111 100 78 97 109 101 34 58 34 109 101 116 114 105 99 115 45 115 101 114 118 101 114 45 53 56 102 100 99 56 55 53 100 53 45 104 57 109 107 107 34 44 34 80 111 100 78 97 109 101 115 112 97 99 101 34 58 34 107 117 98 101 45 115 121 115 116 101 109 34 125]}.

Issue Fixed:
Non-readable log.

Requirements:

uses conventional commit messages

codecov · 2021-02-25T05:02:54Z

Codecov Report

Merging #803 (974303e) into master (bfbd945) will decrease coverage by 0.14%.
The diff coverage is 43.75%.

@@            Coverage Diff             @@
##           master     #803      +/-   ##
==========================================
- Coverage   42.05%   41.91%   -0.15%     
==========================================
  Files         144      152       +8     
  Lines       14051    14401     +350     
==========================================
+ Hits         5909     6036     +127     
- Misses       7427     7633     +206     
- Partials      715      732      +17

neaggarwMS · 2021-02-25T22:58:01Z

logger.Response(service.Name, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)

Can you add Request context to this response message otherwise it is hard to correlate

Refers to: cns/restserver/ipam.go:53 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

cns/restserver/ipam.go

neaggarwMS · 2021-02-25T22:59:42Z

  returnMessage = err.Error()

CAn you add log for the failure

Refers to: cns/restserver/ipam.go:89 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

neaggarwMS · 2021-02-25T23:00:52Z

  	logger.Printf("Released IP %+v for pod %+v", ipconfig.IPAddress, podInfo)

Why this log is missing in Geneva? Also can you move this log before marking the ip as available

Refers to: cns/restserver/ipam.go:304 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

neaggarwMS · 2021-02-25T23:01:24Z

  	logger.Errorf("Failed to get release ipconfig. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt")

Can you add context (Pod and IP details)

Refers to: cns/restserver/ipam.go:307 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

neaggarwMS · 2021-02-25T23:02:37Z

service.PodIPConfigState[ipconfig.ID] = ipconfig

Can you add log for which IP is allocate with pod context

Refers to: cns/restserver/ipam.go:280 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

neaggarwMS · 2021-02-25T23:03:09Z

delete(service.PodIPIDByOrchestratorContext, podInfo.GetOrchestratorContextKey())

Can you add log here as well for when IP is released with podcontext

Refers to: cns/restserver/ipam.go:289 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

neaggarwMS

🕐

csfmomo · 2021-02-26T05:52:33Z

delete(service.PodIPIDByOrchestratorContext, podInfo.GetOrchestratorContextKey())

Can you add log here as well for when IP is released with podcontext

Refers to: cns/restserver/ipam.go:289 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

releaseIPConfig already have it's log. Added log in setIPConfigAsAvailable

csfmomo · 2021-02-26T05:56:26Z

  	logger.Errorf("Failed to get release ipconfig. Pod to IPID exists, but IPID to IPConfig doesn't exist, CNS State potentially corrupt")
Can you add context (Pod and IP details)

Refers to: cns/restserver/ipam.go:307 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

Added

csfmomo · 2021-02-26T06:00:10Z

service.PodIPConfigState[ipconfig.ID] = ipconfig

Added.

csfmomo · 2021-02-26T06:02:18Z

logger.Printf("Released IP %+v for pod %+v", ipconfig.IPAddress, podInfo)

Moved.

csfmomo · 2021-02-26T06:07:14Z

  returnMessage = err.Error()
CAn you add log for the failure

Refers to: cns/restserver/ipam.go:89 in e40eb49. [](commit_id = e40eb49, deletion_comment = False)

Added

csfmomo · 2021-02-26T06:11:33Z

logger.Response(service.Name, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)

Added.

pjohnst5

LGTM

cns/restserver/ipam.go

csfmomo · 2021-02-27T05:14:58Z

cns/restserver/ipam.go

-	logger.Request(service.Name, &ipconfigRequest, err)
+	operationName := "requestIPConfigHandler"
+	desiredIPAddress := ipconfigRequest.DesiredIPAddress
+	orchestratorContest := string(ipconfigRequest.OrchestratorContext)


The test for why string can works
https://play.golang.org/p/rMJJrhnhCNP
From this test, we can see, if we don't use string but use unmarshall to change it to readable, the type of unmarshalled object is KubernetesPodInfo type instead of string. Then we can't add both string and KubernetesPodInfo into logger request.

import ( "encoding/json" "fmt" ) type IPConfigRequest struct { DesiredIPAddress string OrchestratorContext json.RawMessage } type KubernetesPodInfo struct { PodName string PodNamespace string } func main() { testPod1Info := KubernetesPodInfo{ PodName: "testpod1", PodNamespace: "testpod1namespace", } req := IPConfigRequest{} b, _ := json.Marshal(testPod1Info) req.OrchestratorContext = b req.DesiredIPAddress = "1.1.1.1" // string translate can work. fmt.Println(req.DesiredIPAddress + string(b)) fmt.Println(b) var podInfo KubernetesPodInfo err := json.Unmarshal(b, &podInfo) if err != nil { panic(err) } fmt.Printf("%v\n", podInfo) fmt.Printf("%+v\n", podInfo) fmt.Printf("%v\n", b) }

cns/nmagentclient/nmagentclient.go

cns/restserver/ipam.go

neaggarwMS · 2021-03-09T18:29:05Z

logger.Response(service.Name, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)

We are printing double logs that could lead to noise. Can you update logger.Response method to accept Request and Response interface and print it at one place

In reply to: 786283821 [](ancestors = 786283821)

Refers to: cns/restserver/ipam.go:53 in add15bd. [](commit_id = add15bd, deletion_comment = False)

neaggarwMS · 2021-03-09T18:29:28Z

logger.Response(service.Name, reserveResp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)

Also expose a string function to IPConfigResponse like we have exposed it for IpConfigRequest

In reply to: 794273976 [](ancestors = 794273976,786283821)

Refers to: cns/restserver/ipam.go:53 in add15bd. [](commit_id = add15bd, deletion_comment = False)

cns/restserver/ipam.go

neaggarwMS · 2021-03-09T18:32:00Z

cns/restserver/ipam.go

 	}

 	service.PodIPIDByOrchestratorContext[podInfo.GetOrchestratorContextKey()] = ipconfig.ID
+	logger.Printf("Set PodIPIDByOrchestratorContext item %s with ID %s and IP is %s", podInfo.GetOrchestratorContextKey(), ipconfig.ID, ipconfig.IPAddress)


Can you prefix it with [setIPConfigAsAllocated]

I think updateIPConfigState already logs, do we need to duplicate it here?

In reply to: 590618862 [](ancestors = 590618862)

It's not a duplication if we want to ensure line 319 got executed.

revoking review

neaggarwMS

🕐

neaggarwMS · 2021-03-16T22:22:27Z

cns/restserver/ipam.go

 	err = service.Listener.Decode(w, r, &ipconfigRequest)
-	logger.Request(service.Name, &ipconfigRequest, err)
+	operationName := "requestIPConfigHandler"
+	logger.Request(service.Name+operationName, ipconfigRequest.String(), err)


You dont have to add String()

I need add String, otherwise, the OrchestratorContext part is binary and not readable. String() function translate the binary to string for OrchestratorContext part.

Tested, no need to call .String specifically. Let me remove it.

neaggarwMS · 2021-03-16T22:25:29Z

cns/logger/log.go

+		msg = fmt.Sprintf("[%s] Code:%s, %+v, %+v.", tag, returnStr, request, response)
+	}
+
+	sendTraceInternal(msg)


Why do we need this? Log.logger.ResponseEx will print to AI too, right?

I didn't see either Log.logger.ResponseEx or Log.logger.Response prints to AI.

After offline sync up, we'll keep it as it is for now. I'll make a separate PR to remove duplicate AI telemetry log populating issue.

neaggarwMS · 2021-03-16T22:26:04Z

cns/restserver/ipam.go


 		err = service.Listener.Encode(w, &resp)
-		logger.Response(service.Name, resp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)
+		logger.ResponseEx(service.Name, req.String(), resp, resp.ReturnCode, ReturnCodeToString(resp.ReturnCode), err)


Again API accepts interface, you dont need to pass String()

Address feedback.

neaggarwMS

csfmomo force-pushed the fixLog branch from 8643726 to e40eb49 Compare February 25, 2021 04:52

neaggarwMS reviewed Feb 25, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS previously requested changes Feb 25, 2021

View reviewed changes

csfmomo force-pushed the fixLog branch from c100650 to 221a0bc Compare February 26, 2021 06:14

csfmomo requested review from matmerr, neaggarwMS and pjohnst5 February 26, 2021 06:14

pjohnst5 previously approved these changes Feb 26, 2021

View reviewed changes

neaggarwMS reviewed Feb 26, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Feb 26, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Feb 26, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Feb 26, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Feb 26, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

csfmomo commented Feb 27, 2021

View reviewed changes

csfmomo dismissed pjohnst5’s stale review via c722afe February 27, 2021 05:16

csfmomo force-pushed the fixLog branch from 221a0bc to c722afe Compare February 27, 2021 05:16

csfmomo requested a review from neaggarwMS February 27, 2021 05:17

csfmomo force-pushed the fixLog branch 2 times, most recently from f694a1b to add15bd Compare March 8, 2021 07:31

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

cns/nmagentclient/nmagentclient.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

cns/restserver/ipam.go Outdated Show resolved Hide resolved

neaggarwMS reviewed Mar 9, 2021

View reviewed changes

neaggarwMS requested changes Mar 9, 2021

View reviewed changes

csfmomo force-pushed the fixLog branch from add15bd to 2e0f7f6 Compare March 10, 2021 02:16

csfmomo requested a review from neaggarwMS March 10, 2021 18:01

csfmomo force-pushed the fixLog branch from 2e0f7f6 to b84ad06 Compare March 10, 2021 18:57

neaggarwMS reviewed Mar 16, 2021

View reviewed changes

csfmomo requested a review from neaggarwMS March 16, 2021 22:25

neaggarwMS reviewed Mar 16, 2021

View reviewed changes

Fix log which let log to show more readable info.

974303e

Address feedback.

csfmomo force-pushed the fixLog branch from b84ad06 to 974303e Compare March 17, 2021 18:17

csfmomo requested a review from neaggarwMS March 17, 2021 20:16

neaggarwMS approved these changes Mar 17, 2021

View reviewed changes

csfmomo merged commit dc7ff48 into master Mar 18, 2021

csfmomo deleted the fixLog branch March 18, 2021 00:10

Fix log which let log to show more readable info. #803

Fix log which let log to show more readable info. #803

Uh oh!

Conversation

csfmomo commented Feb 25, 2021

Uh oh!

codecov bot commented Feb 25, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

neaggarwMS commented Feb 25, 2021

Uh oh!

neaggarwMS left a comment

Choose a reason for hiding this comment

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

csfmomo commented Feb 26, 2021

Uh oh!

pjohnst5 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

csfmomo Feb 27, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

neaggarwMS commented Mar 9, 2021

Uh oh!

neaggarwMS commented Mar 9, 2021

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

neaggarwMS left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

codecov bot commented Feb 25, 2021 •

edited

Loading

csfmomo Feb 27, 2021 •

edited

Loading