Visual Studio UI Tests fail when using latest master

[karthiknadig]

Environment data

• PTVSD version: master
• OS and version: windows
• Python version (& distribution if applicable, e.g. Anaconda): 3.7
• Using VS Code or Visual Studio: Visual Studio

Actual behavior

VS extension UI tests fail with following stack:

Test Name:      Breakpoints
Test FullName:  Test Detail Summary
Test Source:    C:\Projects\GitHub\huguesv\PTVS\Python\Tests\DebuggerUITestsRunner\DebugProjectUITests.cs : line 167
Test Outcome:   Failed
Test Duration:  0:00:00

Test Name:      Breakpoints
Test Outcome:   Failed
Result StackTrace:      
Assert.IsNotNull failed. 
   at Project DebuggerUITests.DebugProjectUITests.OpenProjectAndBreak(VisualStudioApp app, string projName, string filename, int lineNo, bool setStartupItem) in C:\Projects\GitHub\huguesv\PTVS\Python\Tests\DebuggerUITests\DebugProjectUITests.cs:line 993
   at Project DebuggerUITests.DebugProjectUITests.OpenDebuggerProjectAndBreak(VisualStudioApp app, string startItem, int lineNo, bool setStartupItem) in C:\Projects\GitHub\huguesv\PTVS\Python\Tests\DebuggerUITests\DebugProjectUITests.cs:line 959
   at void DebuggerUITests.DebugProjectUITests.Breakpoints(PythonVisualStudioApp app, bool useVsCodeDebugger, string interpreter, DotNotWaitOnNormalExit optionSetter) in C:\Projects\GitHub\huguesv\PTVS\Python\Tests\DebuggerUITests\DebugProjectUITests.cs:line 561
Result Message: 
Test method DebuggerUITestsRunner.DebugProjectUITestsExperimental37.Breakpoints threw exception: 
TestRunnerInterop.TestFailedException: AssertFailedException: Assert.IsNotNull failed.
Result StandardOutput:   
Executing command DebugAdapterHost.Logging /On 
Successfully executed command DebugAdapterHost.Logging /On 
Creating temp directory for test at C:\Projects\GitHub\huguesv\PTVS\Python\Deploy_huvalo 2019-07-16 15_23_44\Out\Temp\gpyu3m5t.yke\
Copying C:\Projects\GitHub\huguesv\PTVS\Python\Tests\TestData\DebuggerProject.sln to C:\Projects\GitHub\huguesv\PTVS\Python\Deploy_huvalo 2019-07-16 15_23_44\Out\Temp\gpyu3m5t.yke\DebuggerProject.sln
Copying C:\Projects\GitHub\huguesv\PTVS\Python\Tests\TestData\DebuggerProject to C:\Projects\GitHub\huguesv\PTVS\Python\Deploy_huvalo 2019-07-16 15_23_44\Out\Temp\gpyu3m5t.yke\DebuggerProject
Closing 
Opening C:\Projects\GitHub\huguesv\PTVS\Python\Deploy_huvalo 2019-07-16 15_23_44\Out\Temp\gpyu3m5t.yke\DebuggerProject.sln

Expected behavior

UI tests should succeed.

Steps to reproduce:

1. Use the latest master and run the Debugger UI test in PTVS.

Logs:

 1> 07/16/2019 15:24:22.007: DebugAdapterHost version: 16.3.30627.2 commit:5c9d20bede8fa7e147280ac764b7fe62bd55cac0
 1> 07/16/2019 15:24:25.046: [DebugAdapter] <--   E (output): {"type": "event", "seq": 0, "event": "output", "body": {"category": "telemetry", "output": "ptvsd", "data": {"version": "4.3.0b1"}}}
 1> 07/16/2019 15:24:25.124: [DebugAdapter] --> C (initialize-1): {"type":"request","command":"initialize","arguments":{"pathFormat":"path","clientID":"visualstudio","clientName":"Visual Studio","adapterID":null,"locale":"en-US","linesStartAt1":true,"columnsStartAt1":true,"supportsVariableType":true,"supportsRunInTerminalRequest":true,"supportsMemoryReferences":true,"supportsHandshakeRequest":true,"AdditionalProperties":{}},"seq":1}
 1> 07/16/2019 15:24:25.150: [DebugAdapter] --> C (ptvsd_systemInfo-2): {"type":"request","command":"ptvsd_systemInfo","arguments":{},"seq":2}
 1> 07/16/2019 15:24:25.283: [DebugAdapter] <--   R (initialize-1) [243 ms]: {"type": "response", "seq": 1, "request_seq": 1, "success": true, "command": "initialize", "message": "", "body": {"supportsCompletionsRequest": true, "supportsConditionalBreakpoints": true, "supportsConfigurationDoneRequest": true, "supportsDebuggerProperties": true, "supportsDelayedStackTraceLoading": true, "supportsEvaluateForHovers": true, "supportsExceptionInfoRequest": true, "supportsExceptionOptions": true, "supportsHitConditionalBreakpoints": true, "supportsLogPoints": true, "supportsModulesRequest": true, "supportsSetExpression": true, "supportsSetVariable": true, "supportsValueFormattingOptions": true, "supportTerminateDebuggee": true, "supportsGotoTargetsRequest": true, "exceptionBreakpointFilters": [{"filter": "raised", "label": "Raised Exceptions", "default": false}, {"filter": "uncaught", "label": "Uncaught Exceptions", "default": true}]}}
 1> 07/16/2019 15:24:25.324: [DebugAdapter] --> C (launch-3): {"type":"request","command":"launch","arguments":{"noDebug":false,"ConfigurationProperties":{"exe":"C:\\Program Files (x86)\\Python37-32\\python.exe","cwd":"C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\","remoteMachine":"","args":"\"C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py\"","options":"STOP_ON_ENTRY=True;WAIT_ON_ABNORMAL_EXIT=True;REDIRECT_OUTPUT=True;SHOW_RETURN_VALUE=True;VERSION=3.7;INTERPRETER_OPTIONS=","env":[]},"seq":3}
 1> 07/16/2019 15:24:25.331: [DebugAdapter] <--   E (initialized): {"type": "event", "seq": 2, "event": "initialized", "body": {}}
 1> 07/16/2019 15:24:25.338: [DebugAdapter] <--   R (ptvsd_systemInfo-2) [188 ms]: {"type": "response", "seq": 3, "request_seq": 2, "success": true, "command": "ptvsd_systemInfo", "message": "", "body": {"ptvsd": {"version": "4.3.0b1"}, "python": {"version": "3.7.3final0", "implementation": {"name": "cpython", "version": "3.7.3final0", "description": "CPython"}}, "platform": {"name": "win32"}, "process": {"pid": 17580, "executable": "C:\\Program Files (x86)\\Python37-32\\python.exe", "bitness": 32}}}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-4): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"AllowOutOfProcessSymbols":1},"AllowOutOfProcessSymbols":1},"seq":4}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-5): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"AllowOutOfProcessSymbols":1},"AllowOutOfProcessSymbols":1},"seq":5}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-6): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"DisableJITOptimization":0},"DisableJITOptimization":0},"seq":6}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-7): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"EnableFastEvaluate":1},"EnableFastEvaluate":1},"seq":7}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-8): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"InterpreterOptions":1},"InterpreterOptions":1},"seq":8}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-9): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"JustMyCodeStepping":1},"JustMyCodeStepping":1},"seq":9}
 1> 07/16/2019 15:24:25.352: [DebugAdapter] --> C (setDebuggerProperty-10): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"StopOnExceptionCrossingManagedBoundary":0},"StopOnExceptionCrossingManagedBoundary":0},"seq":10}
 1> 07/16/2019 15:24:25.353: [DebugAdapter] --> C (setDebuggerProperty-11): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"WarnIfNoUserCodeOnLaunch":1},"WarnIfNoUserCodeOnLaunch":1},"seq":11}
 1> 07/16/2019 15:24:25.353: [DebugAdapter] --> C (setDebuggerProperty-12): {"type":"request","command":"setDebuggerProperty","arguments":{"DebuggerProperties":{"EnableStepFiltering":true},"EnableStepFiltering":true},"seq":12}
 1> 07/16/2019 15:24:25.378: [DebugAdapter] <--   R (launch-3) [56 ms]: {"type": "response", "seq": 4, "request_seq": 3, "success": true, "command": "launch", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.405: [DebugAdapter] --> C (setBreakpoints-13): {"type":"request","command":"setBreakpoints","arguments":{"source":{"path":"c:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py","sources":[],"checksums":[]},"breakpoints":[{"line":3,"column":1}],"lines":[3]},"seq":13}
 1> 07/16/2019 15:24:25.407: [DebugAdapter] --> C (setBreakpoints-14): {"type":"request","command":"setBreakpoints","arguments":{"source":{"path":"c:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py","sources":[],"checksums":[]},"breakpoints":[{"line":3,"column":1}],"lines":[3]},"seq":14}
 1> 07/16/2019 15:24:25.417: [DebugAdapter] <--   E (process): {"type": "event", "seq": 5, "event": "process", "body": {"name": "C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py", "systemProcessId": 17580, "isLocalProcess": true, "startMethod": "launch"}}
 1> 07/16/2019 15:24:25.448: [DebugAdapter] --> C (setExceptionBreakpoints-15): {"type":"request","command":"setExceptionBreakpoints","arguments":{"filters":[],"exceptionOptions":[{"breakMode":"userUnhandled","path":[{"names":["Python Exceptions"]}]},{"breakMode":"unhandled","path":[{"names":["Python Exceptions"]},{"names":["GeneratorExit","IndexError","StopIteration","AttributeError","KeyError"]}]}]},"seq":15}
 1> 07/16/2019 15:24:25.453: [DebugAdapter] <--   R (setDebuggerProperty-4) [113 ms]: {"type": "response", "seq": 6, "request_seq": 4, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.456: [DebugAdapter] <--   R (setDebuggerProperty-5) [103 ms]: {"type": "response", "seq": 7, "request_seq": 5, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.457: [DebugAdapter] <--   R (setDebuggerProperty-6) [105 ms]: {"type": "response", "seq": 8, "request_seq": 6, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.458: [DebugAdapter] <--   R (setDebuggerProperty-7) [106 ms]: {"type": "response", "seq": 9, "request_seq": 7, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.458: [DebugAdapter] <--   R (setDebuggerProperty-8) [106 ms]: {"type": "response", "seq": 10, "request_seq": 8, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.459: [DebugAdapter] <--   R (setDebuggerProperty-9) [107 ms]: {"type": "response", "seq": 11, "request_seq": 9, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.459: [DebugAdapter] <--   R (setDebuggerProperty-10) [107 ms]: {"type": "response", "seq": 12, "request_seq": 10, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.460: [DebugAdapter] <--   R (setDebuggerProperty-11) [108 ms]: {"type": "response", "seq": 13, "request_seq": 11, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.460: [DebugAdapter] <--   R (setDebuggerProperty-12) [107 ms]: {"type": "response", "seq": 14, "request_seq": 12, "success": true, "command": "setDebuggerProperty", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.462: [DebugAdapter] <--   R (setBreakpoints-13) [76 ms]: {"type": "response", "seq": 15, "request_seq": 13, "success": true, "command": "setBreakpoints", "message": "", "body": {"breakpoints": [{"verified": true, "id": 0, "source": {}, "line": 3}]}}
 1> 07/16/2019 15:24:25.469: ERROR: Source does not specify 'name' or 'path'.
 1> 07/16/2019 15:24:25.471: [DebugAdapter] <--   R (setBreakpoints-14) [63 ms]: {"type": "response", "seq": 16, "request_seq": 14, "success": true, "command": "setBreakpoints", "message": "", "body": {"breakpoints": [{"verified": true, "id": 1, "source": {}, "line": 3}]}}
 1> 07/16/2019 15:24:25.482: [DebugAdapter] <--   R (setExceptionBreakpoints-15) [50 ms]: {"type": "response", "seq": 17, "request_seq": 15, "success": true, "command": "setExceptionBreakpoints", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.485: [DebugAdapter] --> C (configurationDone-16): {"type":"request","command":"configurationDone","arguments":{},"seq":16}
 1> 07/16/2019 15:24:25.486: [DebugAdapter] <--   R (configurationDone-16) [0 ms]: {"type": "response", "seq": 18, "request_seq": 16, "success": true, "command": "configurationDone", "message": "", "body": {}}
 1> 07/16/2019 15:24:25.520: [DebugAdapter] <--   E (thread): {"type": "event", "seq": 19, "event": "thread", "body": {"reason": "started", "threadId": 1}}
 1> 07/16/2019 15:24:25.525: [DebugAdapter] <--   E (stopped): {"type": "event", "seq": 20, "event": "stopped", "body": {"reason": "entry", "threadId": 1, "preserveFocusHint": false, "allThreadsStopped": true}}
 1> 07/16/2019 15:24:25.540: [DebugAdapter] --> C (threads-17): {"type":"request","command":"threads","arguments":{},"seq":17}
 1> 07/16/2019 15:24:25.543: [DebugAdapter] <--   R (threads-17) [9 ms]: {"type": "response", "seq": 21, "request_seq": 17, "success": true, "command": "threads", "message": "", "body": {"threads": [{"id": 1, "name": "MainThread"}]}}
 1> 07/16/2019 15:24:25.553: [DebugAdapter] --> C (continue-18): {"type":"request","command":"continue","arguments":{"threadId":1},"seq":18}
 1> 07/16/2019 15:24:25.554: [DebugAdapter] <--   R (continue-18) [1 ms]: {"type": "response", "seq": 22, "request_seq": 18, "success": true, "command": "continue", "message": "", "body": {"allThreadsContinued": true}}
 1> 07/16/2019 15:24:25.562: [DebugAdapter] <--   E (stopped): {"type": "event", "seq": 23, "event": "stopped", "body": {"reason": "breakpoint", "threadId": 1, "preserveFocusHint": false, "allThreadsStopped": true}}
 1> 07/16/2019 15:24:25.562: [DebugAdapter] --> C (threads-19): {"type":"request","command":"threads","arguments":{},"seq":19}
 1> 07/16/2019 15:24:25.563: [DebugAdapter] <--   R (threads-19) [1 ms]: {"type": "response", "seq": 24, "request_seq": 19, "success": true, "command": "threads", "message": "", "body": {"threads": [{"id": 1, "name": "MainThread"}]}}
 1> 07/16/2019 15:24:25.571: [DebugAdapter] --> C (stackTrace-20): {"type":"request","command":"stackTrace","arguments":{"threadId":1,"startFrame":0,"levels":1,"format":{"includeAll":true}},"seq":20}
 1> 07/16/2019 15:24:25.574: [DebugAdapter] <--   E (module): {"type": "event", "seq": 25, "event": "module", "body": {"reason": "new", "module": {"id": 0, "name": "__main__", "path": "C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py"}}}
 1> 07/16/2019 15:24:25.582: [DebugAdapter] <--   E (module): {"type": "event", "seq": 26, "event": "module", "body": {"reason": "new", "module": {"id": 1, "name": "runpy", "path": "C:\\Program Files (x86)\\Python37-32\\Lib\\runpy.py"}}}
 1> 07/16/2019 15:24:25.583: [DebugAdapter] <--   R (stackTrace-20) [16 ms]: {"type": "response", "seq": 27, "request_seq": 20, "success": true, "command": "stackTrace", "message": "", "body": {"stackFrames": [{"id": 2, "name": "f", "line": 3, "column": 1, "source": {"path": "C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py", "sourceReference": 0}}], "totalFrames": 2}}
 1> 07/16/2019 15:24:25.610: [DebugAdapter] --> C (stackTrace-21): {"type":"request","command":"stackTrace","arguments":{"threadId":1,"startFrame":0,"levels":1000,"format":{"parameters":true,"parameterTypes":true,"parameterNames":true,"line":true,"module":true}},"seq":21}
 1> 07/16/2019 15:24:25.612: [DebugAdapter] <--   R (stackTrace-21) [1 ms]: {"type": "response", "seq": 28, "request_seq": 21, "success": true, "command": "stackTrace", "message": "", "body": {"stackFrames": [{"id": 2, "name": "__main__.f : 3", "line": 3, "column": 1, "source": {"path": "C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py", "sourceReference": 0}}, {"id": 3, "name": "__main__ : 5", "line": 5, "column": 1, "source": {"path": "C:\\Projects\\GitHub\\huguesv\\PTVS\\Python\\Deploy_huvalo 2019-07-16 15_23_44\\Out\\Temp\\gpyu3m5t.yke\\DebuggerProject\\BreakpointTest2.py", "sourceReference": 0}}], "totalFrames": 2}}
 1> 07/16/2019 15:24:26.376: [DebugAdapter] --> C (scopes-22): {"type":"request","command":"scopes","arguments":{"frameId":2},"seq":22}
 1> 07/16/2019 15:24:26.377: [DebugAdapter] <--   R (scopes-22) [1 ms]: {"type": "response", "seq": 29, "request_seq": 22, "success": true, "command": "scopes", "message": "", "body": {"scopes": [{"name": "Locals", "variablesReference": 2, "expensive": false, "source": {}}]}}
 1> 07/16/2019 15:24:26.424: [DebugAdapter] --> C (variables-23): {"type":"request","command":"variables","arguments":{"variablesReference":2,"timeout":1000},"seq":23}
 1> 07/16/2019 15:24:26.588: [DebugAdapter] <--   R (variables-23) [168 ms]: {"type": "response", "seq": 30, "request_seq": 23, "success": true, "command": "variables", "message": "", "body": {"variables": [{"name": "i", "value": "0", "type": "int", "evaluateName": "i", "variablesReference": 0}]}}
 1> 07/16/2019 15:24:26.933: [DebugAdapter] --> C (disconnect-24): {"type":"request","command":"disconnect","arguments":{"terminateDebuggee":true},"seq":24}
 1> 07/16/2019 15:24:26.947: Debug adapter process exited.