Make order of ConfigurationDoneRequest and LaunchRequest deterministic

[weinand]

Currently the order of ConfigurationDoneRequest and LaunchRequest is not deterministic, that means it is possible that a ConfigurationDoneRequest comes after the LaunchRequest. This is problematic because only a ConfigurationDoneRequest indicates that all breakpoints have been registered and that a LaunchRequest is able to hit all those breakpoints. If the ConfigurationDoneRequest comes after the LaunchRequest some breakpoints might be missed.

There are two scenarios to consider:

1. An InitializedEvent is sent early (after the InitializeRequest has been processed but before the LaunchRequest). This is used in mono-debug and mock-debug where breakpoints can be registered before launching the debuggee.
2. An InitializedEvent is sent late (while the LaunchRequest is being processed). This is used in node-debug where node.js has to be launched first before breakpoints can be registered).

From the first case it looks like the frontend could always wait with calling LaunchRequest until ConfigurationDoneRequest has been ended. But this would not work with the second case.

/cc @isidorn

[weinand]

@andrewcrawley here is the corresponding issue from 2016!

I've moved it to the February milestone.

[andrewcrawley]

vsdbg is another example of an adapter that sends the "initialized" event during processing of the "launch" request, and I believe MIEngine + OpenDebugAD7 also exhibits this behavior.

If an adapter advertises that it supports "configurationDone", but begins executing the debuggee before receiving that request, it seems pretty clear to me that this is a bug in the adapter. Running the debugee obviously requires complete configuration information, so if configuration is still ongoing, the debuggee should not be running. I would expect that in the case that the debug adapter receives "launch" before "configurationDone", it would:

• Validate the "launch" parameters as much as possible and return failure if (e.g.) the debuggee does not exist.
• Launch the process in a "suspended" state, or cache the information for later
• Once the "configurationDone" request is received, either resume the process (if it was launched and suspended), or launch it directly using the cached info

CC: @gregg-miskelly @caslan @richardstanton

[gregg-miskelly]

I am not following how the first scenario above could work reliably. If I am reading the following bolded section of the protocol documentation for InitializedEvent correctly --

A debug adapter is expected to send this event when it is ready to accept configuration requests (but not before the InitializeRequest has finished)

Then to me that means that a debug adapter isn't allowed to send the InitializedEvent before it sends InitializeResponse.

If I am reading things correctly -- there would be a race in scenario 1 since just because the debug adapter sent the InitializedEvent right away doesn't mean the client will actually get that event in time to know that it needs to delay sending launch until all the breakpoints and other configuration options have been sent.

[weinand]

@gregg-miskelly thanks for adding the excerpt from the InitializedEvent spec.

I had hoped that the implementation of mock-debug would actually stick to the spec, but it does not. It failed the "(but not before the InitializeRequest has finished)".

Moving the line that emits the InitializedEvent to the end of initializeRequest (after the this.sendResponse(response)) made mock-debug fail (which confirmed my speculation that mock-debug was just lucky being able to run with VS Code).

Trying to delay the launchRequest until the response of the configurationDone request has been received would only work for the "early" case but obviously not for the "late" case because there the InitializedEvent is emitted in the launchRequest.

Making this approach work for the "late" case, would require that the frontend receives the information whether it is dealing with the "early" or the "late" case. This would require another capability... which I don't like.

@andrewcrawley this means that I've (finally!) arrived at the same conclusion as you did already a while ago: the problem cannot be (easily) solved on the frontend side but must be fixed in mock-debug.

So today I tried various approaches to delay the launch request until the configurationDone request has been received. Most of them were really ugly (and they were actually the motivation for my quest for trying to fix it in the frontend).

But in the end I found a wait/notify-based fix that is small and simple: https://github.com/Microsoft/vscode-mock-debug/blob/9d378d6aa00982c565b9c19323a7882538a6063a/src/mockDebug.ts#L111-L134

@andrewcrawley Please try whether the latest version of mock-debug works for you now.

[andrewcrawley]

No, it still doesn't work in the VS host. We wait for a response to the "launch" request before we proceed with initialization, so with your fix, the launch request blocks for 1000ms, then continues anyway, still before the "configurationDone" request.

Would it work to send the response, then do your wait before starting the runtime?

Here's the log from our side:

 1> 02/06/2018 13:27:38.448: [DebugAdapter] --> C (initialize-1): {"command":"initialize","arguments":{"clientID":"visualstudio","adapterID":"mock","locale":"en-US","linesStartAt1":true,"columnsStartAt1":true,"pathFormat":"path","supportsVariableType":true,"supportsRunInTerminalRequest":true,"supportsHandshakeRequest":true},"seq":1,"type":"request"}
 1> 02/06/2018 13:27:58.921: [DebugAdapter] <--   R (initialize-1): {"seq":1,"type":"response","request_seq":1,"command":"initialize","success":true,"body":{"supportsConfigurationDoneRequest":true,"supportsEvaluateForHovers":true,"supportsStepBack":true}}
 1> 02/06/2018 13:27:58.926: [DebugAdapter] <--   E (initialized): {"seq":2,"type":"event","event":"initialized"}
 1> 02/06/2018 13:27:58.988: [DebugAdapter] --> C (launch-2): {"command":"launch","arguments":{"noDebug":false,"type":"mock","request":"launch","program":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt"},"seq":2,"type":"request"}
 1> 02/06/2018 13:27:59.992: [DebugAdapter] <--   R (launch-2): {"seq":3,"type":"response","request_seq":2,"command":"launch","success":true}
 1> 02/06/2018 13:27:59.995: [DebugAdapter] <--   E (stopped): {"seq":4,"type":"event","event":"stopped","body":{"reason":"exception","threadId":1}}
 1> 02/06/2018 13:28:00.084: [DebugAdapter] --> C (threads-3): {"command":"threads","arguments":{},"seq":3,"type":"request"}
 1> 02/06/2018 13:28:00.085: [DebugAdapter] --> C (setBreakpoints-4): {"command":"setBreakpoints","arguments":{"source":{"path":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt","checksums":[]},"breakpoints":[{"line":4,"column":1}],"lines":[4]},"seq":4,"type":"request"}
 1> 02/06/2018 13:28:00.105: [DebugAdapter] <--   R (threads-3): {"seq":5,"type":"response","request_seq":3,"command":"threads","success":true,"body":{"threads":[{"id":1,"name":"thread 1"}]}}
 1> 02/06/2018 13:28:00.134: [DebugAdapter] --> C (setExceptionBreakpoints-5): {"command":"setExceptionBreakpoints","arguments":{"filters":[]},"seq":5,"type":"request"}
 1> 02/06/2018 13:28:00.196: [DebugAdapter] --> C (stackTrace-6): {"command":"stackTrace","arguments":{"threadId":1,"startFrame":0,"levels":1000},"seq":6,"type":"request"}
 1> 02/06/2018 13:28:00.219: [DebugAdapter] <--   R (setBreakpoints-4): {"seq":6,"type":"response","request_seq":4,"command":"setBreakpoints","success":true,"body":{"breakpoints":[{"verified":true,"line":4,"id":1}]}}
 1> 02/06/2018 13:28:00.225: [DebugAdapter] <--   E (breakpoint): {"seq":7,"type":"event","event":"breakpoint","body":{"reason":"changed","breakpoint":{"verified":true,"id":1}}}
 1> 02/06/2018 13:28:00.227: [DebugAdapter] <--   R (setExceptionBreakpoints-5): {"seq":8,"type":"response","request_seq":5,"command":"setExceptionBreakpoints","success":true}
 1> 02/06/2018 13:28:00.228: [DebugAdapter] --> C (configurationDone-7): {"command":"configurationDone","arguments":{},"seq":7,"type":"request"}
 1> 02/06/2018 13:28:00.229: [DebugAdapter] <--   R (stackTrace-6): {"seq":9,"type":"response","request_seq":6,"command":"stackTrace","success":true,"body":{"stackFrames":[{"id":0,"source":{"name":"MockDebug.txt","path":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt","sourceReference":0,"adapterData":"mock-adapter-data"},"line":6,"column":0,"name":"Throw(0)"},{"id":1,"source":{"name":"MockDebug.txt","path":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt","sourceReference":0,"adapterData":"mock-adapter-data"},"line":6,"column":0,"name":"an(1)"},{"id":2,"source":{"name":"MockDebug.txt","path":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt","sourceReference":0,"adapterData":"mock-adapter-data"},"line":6,"column":0,"name":"exception(2)"},{"id":3,"source":{"name":"MockDebug.txt","path":"c:\\Users\\andrewcr\\source\\repos\\MockDebugTest\\MockDebug.txt","sourceReference":0,"adapterData":"mock-adapter-data"},"line":6,"column":0,"name":"here.(3)"}],"totalFrames":4}}
 1> 02/06/2018 13:28:00.231: [DebugAdapter] <--   R (configurationDone-7): {"seq":10,"type":"response","request_seq":7,"command":"configurationDone","success":true}
 1> 02/06/2018 13:28:03.922: [DebugAdapter] --> C (continue-8): {"command":"continue","arguments":{"threadId":1},"seq":8,"type":"request"}
 1> 02/06/2018 13:28:03.939: [DebugAdapter] <--   R (continue-8): {"seq":11,"type":"response","request_seq":8,"command":"continue","success":true}
 1> 02/06/2018 13:28:03.951: [DebugAdapter] <--   E (terminated): {"seq":12,"type":"event","event":"terminated"}
 1> 02/06/2018 13:28:03.957: [DebugAdapter] --> C (disconnect-9): {"command":"disconnect","arguments":{},"seq":9,"type":"request"}
 1> 02/06/2018 13:28:03.959: [DebugAdapter] <--   R (disconnect-9): {"seq":13,"type":"response","request_seq":9,"command":"disconnect","success":true}