Application logs are showing twice on stdout and new v2/applicationLogs endpoint.

[tejal29]

Steps to reproduce.

1. On latest master

$cd examples/microservices
$ ../../out/skaffold dev

Starting deploy...
 - deployment.apps/leeroy-web configured
Waiting for deployments to stabilize...
 - deployment/leeroy-app is ready. [1/2 deployment(s) still pending]
 - deployment/leeroy-web is ready.
Deployments stabilized in 5.396 seconds
Watching for changes...
Port forwarding deployment/leeroy-web in namespace default, remote port 8080 -> 127.0.0.1:9000
Port forwarding deployment/leeroy-app in namespace default, remote port http -> 127.0.0.1:9001
[leeroy-app] 2021/06/04 22:26:52 leeroy app server ready
[leeroy-web] 2021/06/04 22:26:52 leeroy web server ready

2. Add a log line to the frontend in the handler function.

+++ b/examples/microservices/leeroy-web/web.go
@@ -9,6 +9,7 @@ import (
 
 func handler(w http.ResponseWriter, r *http.Request) {
        resp, err := http.Get("http://leeroy-app:50051")
+       log.Print("got a request")
        if err != nil {
                panic(err)
        }
(END)

3. See the dev iteration kick off and then curl http://localhost:9000/
4. You will see log lines on std out

Port forwarding deployment/leeroy-app in namespace default, remote port http -> 127.0.0.1:9001
[leeroy-web] 2021/06/04 22:30:52 got a request
[leeroy-web] 2021/06/04 22:30:52 got a request
[leeroy-web] 2021/06/04 22:31:12 got a request
[leeroy-web] 2021/06/04 22:31:12 got a request



[leeroy-web] 2021/06/04 22:34:58 got a request
[leeroy-web] 2021/06/04 22:34:58 got a request

5. you will also see 2 events for the same pod.

curl localhost:50052/v2/applicationLogs   
{"result":{"timestamp":"2021-06-04T22:26:55.808551Z","applicationLogEvent":{"containerName":"leeroy-app-64579d8f58-6trd7","podName":"leeroy-app","message":"2021/06/04 22:26:52 leeroy app server ready\n"}}}
{"result":{"timestamp":"2021-06-04T22:26:55.808663Z","applicationLogEvent":{"containerName":"leeroy-web-d55d7b679-5kqt4","podName":"leeroy-web","message":"2021/06/04 22:26:52 leeroy web server ready\n"}}}
{"result":{"timestamp":"2021-06-04T22:30:02.917308Z","applicationLogEvent":{"containerName":"leeroy-web-7dc4c5db88-4knmz","podName":"leeroy-web","message":"2021/06/04 22:30:02 leeroy web server ready\n"}}}
{"result":{"timestamp":"2021-06-04T22:30:37.996914Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:30:36 leeroy web server ready\n"}}}
{"result":{"timestamp":"2021-06-04T22:30:52.671148Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:30:52 got a request\n"}}}
{"result":{"timestamp":"2021-06-04T22:30:52.754828Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:30:52 got a request\n"}}}

{"result":{"timestamp":"2021-06-04T22:31:12.297496Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:31:12 got a request\n"}}}
{"result":{"timestamp":"2021-06-04T22:31:12.378177Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:31:12 got a request\n"}}}

{"result":{"timestamp":"2021-06-04T22:34:58.732013Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:34:58 got a request\n"}}}
{"result":{"timestamp":"2021-06-04T22:34:58.810362Z","applicationLogEvent":{"containerName":"leeroy-web-857894bc86-4nmhk","podName":"leeroy-web","message":"2021/06/04 22:34:58 got a request\n"}}}

[tejal29]

Verifying if this happens on older version.

With version v1.24.0, i see the same issue.

./skaffold version
v1.24.0
➜   ./skaffold dev -d gcr.io/tejal-gke1 


[leeroy-web] 2021/06/04 22:49:28 got a request
[leeroy-web] 2021/06/04 22:49:28 got a request

Verified the application log end point was not implemeneted then

curl localhost:50052/v2/applicationLogs
{"error":"Not Implemented"}

[tejal29]

Turns out it just the way sample is written