[Appsody debug scenario documentation] Attach Debugger must be run a second time for microprofile project extensions

[keithchong]

Codewind version: latest
OS: Mac
IDE extension version: latest VS Code Extension
IDE version: 1.36.1

Description: When restarting an extension project in debug mode, the first debug attach attempt fails (Currently, there is no delay for project extensions). Users then have to run the Attach Debugger action 'manually' after.

Steps to reproduce:

1. Set up project extension environment and create a Microprofile project
2. Restart in debug
   --> You will get an error message:
   Failed to attach to remote debuggee VM
   or
   Failed to attach debugger to at ipaddress:

Workaround:
Workaround is to run the Attach Debugger action manually.

[sghung]

Documented as part of eclipse-archived/codewind-docs#71. Can close once that gets in

[sishida]

@sghung I have added a new section to the Troubleshooting doc in this commit: eclipse-archived/codewind-docs@fd33944 Please let me know if you'd like any additional changes. Thanks!

[keithchong]

Just to clarify, the bug still needs to be addressed. We're just documenting that the Attach Debugger action needs to be run again since it fails the first time

[jagraj]

Is it possible to address this issue in 0.3 release.? Is it risky to deliver fix at this time of the release.?
Looks like we have workaround if it is not addressed in 0.3 release.

[sghung]

I had incorrectly removed the area/eclipse-ide label. We had documented it in appsody docs, but the proper fix is on the eclipse-ide team. Also, since it is documented, this isn't a stop ship

[tetchel]

what's there still to be done on this?

[keithchong]

@tetchel , I'm still getting this message while testing 0.6.0:

Failed to attach debugger to appsEclipseMp01 at 127.0.0.1:32788.

I had to use the workaround described here to get it to work:

https://www.eclipse.org/codewind/troubleshooting.html#starting-in-debug-mode-results-in-failure-to-attach-the-debugger

[makandre]

We documented this right? Can we close the issue?

[sishida]

Here is a link to the documented section on our website: https://www.eclipse.org/codewind/troubleshooting.html#attempts-fail-to-attach-the-debugger

However, I was under the impression that development eventually wanted to fix the issue, and I would remove this documented section on the website?

[tetchel]

I tried fixing this ancient issue but I think the issue is with the Appsody extension emitting the restart result way too soon, not the IDE.

PFE logs:

[21/02/20 22:26:28 apps-mpp] [INFO] Request to restart project in debug mode
restarting with operation {"operationId":"8fd24f5edfc30ae616f309d9f56f715c","type":"","projectInfo":{"projectID":"c27fe0f0-54f6-11ea-a588-231bd32b0ee5","projectType":"appsodyExtension","location":"/mounted-workspace/apps-mpp","autoBuildEnabled":true,"startMode":"debug","appPorts":["9080"],"extensionID":"/codewind-workspace/.extensions/codewind-appsody-extension","language":"java","debugPort":"7777","statusPingTimeout":150,"isHttps":false,"ignoredPaths":["*/.idea/*","*.iml","/.project","/load-test*","*/*.swp","*/*.swx","*/.gitignore","*/node_modules*","*/4913","*/.git/*","*/.DS_Store","*/.dockerignore","*/*~","/.settings","/.classpath","/.options","/.vscode/*"],"buildRequest":false,"sentProjectInfo":true}}

restarting with start mode debug

restarting with eventName projectRestartResult

[21/02/20 22:26:28 apps-mpp] [INFO] The log name for c27fe0f0-54f6-11ea-a588-231bd32b0ee5 is cw-c27fe0f0-54f6-11ea-a588-231bd32b0ee5-972103c5f307fb953e66b4b0f24772a54c91d9ff
[21/02/20 22:26:32 apps-mpp] [INFO] Project stop for restart was successful
[21/02/20 22:26:32 User.js] [INFO] Updating status for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5.
[21/02/20 22:26:32 apps-mpp] [INFO] Application state changed for project: c27fe0f0-54f6-11ea-a588-231bd32b0ee5 from: started, to: stopping
[21/02/20 22:26:32 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "stopping"
}
[21/02/20 22:26:33 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "stopped"
}
[21/02/20 22:26:33 apps-mpp] [INFO] pingInTransitApplications: Application state for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5 has changed from stopping to stopped
[21/02/20 22:26:34 apps-mpp] [INFO] The log name for c27fe0f0-54f6-11ea-a588-231bd32b0ee5 is cw-c27fe0f0-54f6-11ea-a588-231bd32b0ee5-972103c5f307fb953e66b4b0f24772a54c91d9ff
[21/02/20 22:26:34 User.js] [INFO] Updating status for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5.
[21/02/20 22:26:35 apps-mpp] [INFO] pingApplications: Application state error message: Http request is failed due to timeout error
[21/02/20 22:26:36 User.js] [INFO] Updating status for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5.
[21/02/20 22:26:36 apps-mpp] [INFO] Application state changed for project: c27fe0f0-54f6-11ea-a588-231bd32b0ee5 from: stopped, to: starting
[21/02/20 22:26:36 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "starting"
}
[21/02/20 22:26:37 apps-mpp] [INFO] Application state changed for project: c27fe0f0-54f6-11ea-a588-231bd32b0ee5 from: starting, to: starting, with message: Pinging http://172.18.0.6:9080/health and http://172.18.0.6:9080/
[21/02/20 22:26:37 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "starting",
  "detailedAppStatus": {
    "severity": "INFO",
    "message": "Pinging http://172.18.0.6:9080/health and http://172.18.0.6:9080/",
    "notify": false,
    "notificationID": ""
  }
}
[21/02/20 22:26:37 apps-mpp] [INFO] pingInTransitApplications: Application state error message: Failed to get application status: connect ECONNREFUSED 172.18.0.6:9080
[21/02/20 22:27:06 apps-mpp] [INFO] Project start for restart was successful
[21/02/20 22:27:06 apps-mpp] [INFO] Internal port: 9080
[21/02/20 22:27:06 apps-mpp] [INFO] Exposed port: 32791
[21/02/20 22:27:06 apps-mpp] [INFO] Internal debug port: 7777
[21/02/20 22:27:06 apps-mpp] [INFO] Exposed debug port: 32792
[21/02/20 22:27:06 apps-mpp] [INFO] All the exposed container ports: ["7777","9080","9443"]
[21/02/20 22:27:06 apps-mpp] [INFO] All the host ports: ["32792","32791","32790"]
[21/02/20 22:27:06 apps-mpp] [INFO] Emitting event
 message: projectRestartResult
 data: {
  "operationId": "8fd24f5edfc30ae616f309d9f56f715c",
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "status": "success",
  "startMode": "debug",
  "ports": {
    "exposedPort": "32791",
    "internalPort": "9080",
    "exposedDebugPort": "32792",
    "internalDebugPort": "7777"
  },
  "containerId": "6a2572aaaede8d34f07094a0c2f62db01e0bfa5802ba96593cee895dec21801b"
}
[21/02/20 22:29:12 /portal/modules/ProjectList.js] [INFO] Project apps-mpp started (project ID: c27fe0f0-54f6-11ea-a588-231bd32b0ee5)
[21/02/20 22:29:12 apps-mpp] [INFO] pingInTransitApplications: Application state for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5 has changed from starting to started
[21/02/20 22:29:12 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "started",
  "detailedAppStatus": {
    "severity": "INFO",
    "message": "",
    "notify": false,
    "notificationID": ""
  }
}
[21/02/20 22:29:25 apps-mpp] [INFO] pingApplications: Application state error message: Http request is failed due to timeout error
[21/02/20 22:29:25 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "stopped"
}
[21/02/20 22:29:25 apps-mpp] [INFO] pingApplications: Application state for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5 has changed from started to stopped
[21/02/20 22:29:25 /portal/modules/ProjectList.js] [INFO] Project apps-mpp started (project ID: c27fe0f0-54f6-11ea-a588-231bd32b0ee5)
[21/02/20 22:29:25 apps-mpp] [INFO] pingApplications: Application state for project c27fe0f0-54f6-11ea-a588-231bd32b0ee5 has changed from stopped to started
[21/02/20 22:29:25 apps-mpp] [INFO] Emitting event
 message: projectStatusChanged
 data: {
  "projectID": "c27fe0f0-54f6-11ea-a588-231bd32b0ee5",
  "appStatus": "started",
  "detailedAppStatus": {
    "severity": "INFO",
    "message": "",
    "notify": false,
    "notificationID": ""
  }
}

Since the appsody logs aren't read by PFE the above aren't too useful, but I can see that the restart success event comes while the Appsody project is still downloading its dependencies.

If I wait ~2 minutes for the app to actually be starting (this message: [Container] [INFO] Listening for transport dt_socket at address: 7777) then I can successfully attach the debugger.

[makandre]

From what I can tell, projectRestartResult is emitted by Turbine after project is restarted and the container is up, but it doesn't wait/guarantee the application has reached running state (that is still up to the pinging code)

I think this never was a problem for Codewind projects because the app start up relatively quickly after the container is up (it's the build part that takes long), whereas for Appsody the build occurs as part of running the app.

[eharris369]

I can reproduce this problem with the Eclipse IDE and Appsody MicroProfile projects. The debugger does eventually connect after a really long time. This doesn't seem right though because the debugger connect timeout is set to 3 seconds. I will investigate why it keeps trying to connect for much longer than that. Anyway, it is all the same issue where it tries to attach the debugger long before the app is ready.