Node JS (Hello World) iterative debugging fails on the first attempt in iterative development

[sivakku]

From cloud-code-vscode-internal created by sivakku: GoogleCloudPlatform/cloud-code-vscode-internal#4671

• Download K8, Node JS(Hello world) application.
• Set minikube as current context.
• Choose debug on K8 from cloud status bar.
• Put a breakpoint at line 32 in index.js
• You hit breakpoint.
• Make a code change at line 35 to error message "Internal Server Error test cloud code"
• Save it and see the deployment kicked off.
• Refresh the browser once the deployment completed.
• The breakpoint doesn't hit
• Refresh the browser again the breakpoint is hit.
• i see on first attempt the debug bar points to "Run on kubernetes", on subsequent refreshes it hits the breakpoint.

[sivakku]

@tejal29 - Creating a tracking issue on your side, the iterative debugging on plugins is waiting to be released and waiting on this issue.

[briandealwis]

@quoctruong @sivakku Isn't this a dupe of #5704 and fixed with #5804?

[tejal29]

I can't reproduce this on v1.25.0 On every iteration, the breakpoint was hit.
Probably #5804 fixed this issue.

See details here. https://github.com/GoogleCloudPlatform/cloud-code-vscode-internal/issues/4671#issuecomment-853327431

@quoctruong mentioned 1:1, there is a connection added in the call stack which is not expected.
Can you please mention what is the expected behavior?

[tejal29]

From Chat,

hey tejal so i think the flow is like this

1. Make changes.
2. Rebuild and Redeployment.
3. Portforwarding got established.
4. Debugger Connect.
5. Works!

However currently it is like this

1. Make changes.
2. Rebuild and Redeployment.
3. Portforwarding got established.
4. Debugger Connect.
5. Portforwarding got torn down when the old pod got recycled even though it is not coming from the old pod.
6. Debugger Disconnected.
7. Portforwarding got reestablished.
8. Debugger Connect.
9. Works!

[tejal29]

@tejal29 to paste the skaffold actual event stream Vs expected.

[tejal29]

Event stream

Before making the change:

kubectl get pods
NAME                                  READY   STATUS    RESTARTS   AGE
nodejs-hello-world-5bffb46d66-j4s7g   1/1     Running   0          78s

{
	"result":{
		"timestamp":"2021-06-02T21:40:54.183667Z",
		"event":{
			"devLoopEvent":{
				"iteration":2,
				"status":"In Progress",
				"err":null
			}
		},
		"entry":"Update initiated"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:40:54.190010Z",
		"event":{
			"buildEvent":{
				"artifact":"nodejs-hello-world",
				"status":"In Progress",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Build started for artifact nodejs-hello-world"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:04.366096Z",
		"event":{
			"buildEvent":{
				"artifact":"nodejs-hello-world",
				"status":"Complete",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Build completed for artifact nodejs-hello-world"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:04.420939Z",
		"event":{
			"deployEvent":{
				"status":"In Progress",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Deploy started"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:06.113776Z",
		"event":{
			"deployEvent":{
				"status":"Complete",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Deploy completed"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:06.113810Z",
		"event":{
			"statusCheckEvent":{
				"status":"Started",
				"message":"",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Status check started"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:07.926876Z",
		"event":{
			"resourceStatusCheckEvent":{
				"resource":"pod/nodejs-hello-world-5bffb46d66-j4s7g",
				"status":"Succeeded",
				"message":"Succeeded",
				"err":"",
				"statusCode":"STATUSCHECK_SUCCESS",
				"actionableErr":null
			}
		},
		"entry":"Resource pod/nodejs-hello-world-5bffb46d66-j4s7g status completed successfully"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:07.926893Z",
		"event":{
			"resourceStatusCheckEvent":{
				"resource":"pod/nodejs-hello-world-6d66884b55-rrv94",
				"status":"In Progress",
				"message":"waiting for init container install-nodejs-debug-support to start",
				"err":"",
				"statusCode":"STATUSCHECK_POD_INITIALIZING",
				"actionableErr":{
					"errCode":"STATUSCHECK_POD_INITIALIZING",
					"message":"waiting for init container install-nodejs-debug-support to start",
					"suggestions":[
						
					]
				}
			}
		},
		"entry":"Resource pod/nodejs-hello-world-6d66884b55-rrv94 status updated to In Progress"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:09.529353Z",
		"event":{
			"debuggingContainerEvent":{
				"status":"Started",
				"podName":"nodejs-hello-world-6d66884b55-rrv94",
				"containerName":"server",
				"namespace":"default",
				"artifact":"nodejs-hello-world",
				"runtime":"nodejs",
				"workingDir":"/hello-world",
				"debugPorts":{
					"devtools":9229
				}
			}
		},
		"entry":"Debuggable container started pod/nodejs-hello-world-6d66884b55-rrv94:server (default)"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:09.679691Z",
		"event":{
			"resourceStatusCheckEvent":{
				"resource":"pod/nodejs-hello-world-6d66884b55-rrv94",
				"status":"Succeeded",
				"message":"Succeeded",
				"err":"",
				"statusCode":"STATUSCHECK_SUCCESS",
				"actionableErr":null
			}
		},
		"entry":"Resource pod/nodejs-hello-world-6d66884b55-rrv94 status completed successfully"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:10.659225Z",
		"event":{
			"portEvent":{
				"localPort":9229,
				"remotePort":9229,
				"podName":"nodejs-hello-world-6d66884b55-rrv94",
				"containerName":"server",
				"namespace":"default",
				"portName":"devtools",
				"resourceType":"pod",
				"resourceName":"nodejs-hello-world-6d66884b55-rrv94",
				"address":"127.0.0.1",
				"targetPort":{
					"type":0,
					"intVal":9229,
					"strVal":""
				}
			}
		},
		"entry":"Forwarding container server to local port 9229"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:11.173398Z",
		"event":{
			"resourceStatusCheckEvent":{
				"resource":"deployment/nodejs-hello-world",
				"status":"In Progress",
				"message":"waiting for rollout to finish: 1 old replicas are pending termination...\n",
				"err":"",
				"statusCode":"STATUSCHECK_DEPLOYMENT_ROLLOUT_PENDING",
				"actionableErr":{
					"errCode":"STATUSCHECK_DEPLOYMENT_ROLLOUT_PENDING",
					"message":"waiting for rollout to finish: 1 old replicas are pending termination...\n",
					"suggestions":[
						
					]
				}
			}
		},
		"entry":"Resource deployment/nodejs-hello-world status updated to In Progress"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:14.990974Z",
		"event":{
			"resourceStatusCheckEvent":{
				"resource":"deployment/nodejs-hello-world",
				"status":"Succeeded",
				"message":"Succeeded",
				"err":"",
				"statusCode":"STATUSCHECK_SUCCESS",
				"actionableErr":null
			}
		},
		"entry":"Resource deployment/nodejs-hello-world status completed successfully"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:14.991057Z",
		"event":{
			"statusCheckEvent":{
				"status":"Succeeded",
				"message":"",
				"err":"",
				"errCode":"OK",
				"actionableErr":null
			}
		},
		"entry":"Status check succeeded"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:15.100173Z",
		"event":{
			"devLoopEvent":{
				"iteration":2,
				"status":"Succeeded",
				"err":null
			}
		},
		"entry":"Update succeeded"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:16.164303Z",
		"event":{
			"portEvent":{
				"localPort":4503,
				"remotePort":81,
				"podName":"",
				"containerName":"",
				"namespace":"default",
				"portName":"",
				"resourceType":"service",
				"resourceName":"nodejs-hello-world-external",
				"address":"127.0.0.1",
				"targetPort":{
					"type":0,
					"intVal":81,
					"strVal":""
				}
			}
		},
		"entry":"Forwarding container  to local port 4503"
	}
}{
	"result":{
		"timestamp":"2021-06-02T21:41:20.757446Z",
		"event":{
			"portEvent":{
				"localPort":9229,
				"remotePort":9229,
				"podName":"nodejs-hello-world-6d66884b55-rrv94",
				"containerName":"server",
				"namespace":"default",
				"portName":"devtools",
				"resourceType":"pod",
				"resourceName":"nodejs-hello-world-6d66884b55-rrv94",
				"address":"127.0.0.1",
				"targetPort":{
					"type":0,
					"intVal":9229,
					"strVal":""
				}
			}
		},
		"entry":"Forwarding container server to local port 9229"
	}
}

If you see, there is a debugging event when a new pod is created. This is because the debug container manager is listening for events with a pod selector. We need to stop the debug container like we do for PortForwarder and then start again at the end of each loop.
PR coming up