microsoft / vscode-mono-debug

A simple VS Code debug adapter for mono
Other
159 stars 173 forks source link

Unable to set breakpoints "Cannot perform runtime binding on a null reference" #70

Open puremourning opened 3 years ago

puremourning commented 3 years ago

Setting breakpoints is failing using this test program and vscode-mono-debug v0.16.2 and a non-vscode client vimspector

The failure response is:

2020-11-16 21:20:28,333 - DEBUG - Message received: {'success': False, 'message': "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)", 'request_seq': 2, 'command': 'setBreakpoints', 'body': {'error': {'id': 1104, 'format': "error while processing request '{_request}' (exception: {_exception})", 'variables': {'_request': 'setBreakpoints', '_exception': 'Cannot perform runtime binding on a null reference'}, 'showUser': True, 'sendTelemetry': False}}, 'seq': 5, 'type': 'response'}

To break down the flow:

So far so good.

This is where it starts to go wrong.

First, we receive a duplicate response to the initialize request:

2020-11-16 21:20:28,133 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 0, 'command': 'initialize', 'body': {'supportsConfigurationDoneRequest': False, 'supportsFunctionBreakpoints': False, 'supportsConditionalBreakpoints': False, 'supportsEvaluateForHovers': False, 'exceptionBreakpointFilters': []}, 'seq': 1, 'type': 'response'}
2020-11-16 21:20:28,133 - INFO - User Msg: Protocol error: duplicate response for request 0

This is bad, but the client just ignores it, so whatever.

That's all fine, and we get a response to the launch request:

But then we get rejections for the breakpoints request from earlier:

But then we get a duplicate of that message:

2020-11-16 21:20:28,333 - DEBUG - Message received: {'success': False, 'message': "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)", 'request_seq': 2, 'command': 'setBreakpoints', 'body': {'error': {'id': 1104, 'format': "error while processing request '{_request}' (exception: {_exception})", 'variables': {'_request': 'setBreakpoints', '_exception': 'Cannot perform runtime binding on a null reference'}, 'showUser': True, 'sendTelemetry': False}}, 'seq': 5, 'type': 'response'}
2020-11-16 21:20:28,333 - INFO - User Msg: Protocol error: duplicate response for request 2

And finally the exception breakpoints request is accepted: 2020-11-16 21:20:28,336 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 3, 'command': 'setExceptionBreakpoints', 'body': None, 'seq': 6, 'type': 'response'}

Subsequently there are other problems like duplicate responses to the threads request and such, but the inability to set breakpoints seems the most severe.

Full log including DAP trace:

2020-11-16 21:20:23,379 - INFO - **** INITIALISING NEW VIMSPECTOR SESSION ****
2020-11-16 21:20:23,380 - INFO - API is: 
2020-11-16 21:20:23,380 - INFO - VIMSPECTOR_HOME = /Users/ben/.vim/vimspector-conf
2020-11-16 21:20:23,380 - INFO - gadgetDir = /Users/ben/.vim/vimspector-conf/gadgets/macos
2020-11-16 21:20:24,803 - INFO - User requested start debug session with {}
2020-11-16 21:20:24,810 - DEBUG - Reading configurations from: None
2020-11-16 21:20:24,811 - DEBUG - Reading configurations from: /Users/ben/.vim/bundle/vimspector/support/test/csharp/.vimspector.json
2020-11-16 21:20:24,813 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.json
2020-11-16 21:20:24,869 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.d/lldb-vscode.json
2020-11-16 21:20:24,872 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.d/netcoredbg.json
2020-11-16 21:20:24,873 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.d/vim-debug-adapter.json
2020-11-16 21:20:24,875 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.d/vscode-cpptools.json
2020-11-16 21:20:24,877 - DEBUG - Reading gadget config: /Users/ben/.vim/vimspector-conf/gadgets/macos/.gadgets.d/vscode-javac.json
2020-11-16 21:20:24,879 - DEBUG - Reading gadget config: None
2020-11-16 21:20:27,439 - INFO - Configuration: {"adapter": "vscode-mono-debug", "configuration": {"request": "launch", "program": "/Users/ben/.vim/bundle/vimspector/support/test/csharp/Program.exe", "console": "integratedTerminal", "cwd": "/Users/ben/.vim/bundle/vimspector/support/test/csharp", "args": [], "env": {}}}
2020-11-16 21:20:27,440 - INFO - Adapter: {"attach": {"pidSelect": "none"}, "command": ["mono", "/Users/ben/.vim/vimspector-conf/gadgets/macos/vscode-mono-debug/bin/Release/mono-debug.exe"], "name": "mono-debug"}
2020-11-16 21:20:27,552 - INFO - Starting debug adapter with: {"attach": {"pidSelect": "none"}, "command": ["mono", "/Users/ben/.vim/vimspector-conf/gadgets/macos/vscode-mono-debug/bin/Release/mono-debug.exe"], "name": "mono-debug"}
2020-11-16 21:20:27,564 - INFO - Debug Adapter Started
2020-11-16 21:20:27,565 - DEBUG - Sending Message: {"command": "initialize", "arguments": {"adapterID": "mono-debug", "clientID": "vimspector", "clientName": "vimspector", "linesStartAt1": true, "columnsStartAt1": true, "locale": "en_GB", "pathFormat": "path", "supportsVariableType": true, "supportsVariablePaging": false, "supportsRunInTerminalRequest": true}, "seq": 0, "type": "request"}
2020-11-16 21:20:28,113 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 0, 'command': 'initialize', 'body': {'supportsConfigurationDoneRequest': False, 'supportsFunctionBreakpoints': False, 'supportsConditionalBreakpoints': False, 'supportsEvaluateForHovers': False, 'exceptionBreakpointFilters': []}, 'seq': 1, 'type': 'response'}
2020-11-16 21:20:28,113 - DEBUG - LAUNCH!
2020-11-16 21:20:28,114 - DEBUG - Sending Message: {"command": "launch", "arguments": {"request": "launch", "program": "/Users/ben/.vim/bundle/vimspector/support/test/csharp/Program.exe", "console": "integratedTerminal", "cwd": "/Users/ben/.vim/bundle/vimspector/support/test/csharp", "args": [], "env": {}, "name": "test"}, "seq": 1, "type": "request"}
2020-11-16 21:20:28,118 - DEBUG - Message received: {'seq': 2, 'type': 'event', 'event': 'initialized', 'body': None}
2020-11-16 21:20:28,119 - DEBUG - Sending Message: {"command": "setBreakpoints", "arguments": {"source": {"name": "Program.cs", "path": "/Users/ben/.vim/bundle/vimspector/support/test/csharp/Program.cs"}, "breakpoints": [{"line": 31}]}, "sourceModified": false, "seq": 2, "type": "request"}
2020-11-16 21:20:28,119 - DEBUG - Sending Message: {"command": "setExceptionBreakpoints", "arguments": {"filters": []}, "seq": 3, "type": "request"}
2020-11-16 21:20:28,133 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 0, 'command': 'initialize', 'body': {'supportsConfigurationDoneRequest': False, 'supportsFunctionBreakpoints': False, 'supportsConditionalBreakpoints': False, 'supportsEvaluateForHovers': False, 'exceptionBreakpointFilters': []}, 'seq': 1, 'type': 'response'}
2020-11-16 21:20:28,133 - INFO - User Msg: Protocol error: duplicate response for request 0
2020-11-16 21:20:28,134 - ERROR - Duplicate response: {'success': True, 'message': None, 'request_seq': 0, 'command': 'initialize', 'body': {'supportsConfigurationDoneRequest': False, 'supportsFunctionBreakpoints': False, 'supportsConditionalBreakpoints': False, 'supportsEvaluateForHovers': False, 'exceptionBreakpointFilters': []}, 'seq': 1, 'type': 'response'}
Traceback (most recent call last):
  File "/Users/ben/.vim/bundle/vimspector/python3/vimspector/debug_adapter_connection.py", line 245, in _OnMessageReceived
    request = self._outstanding_requests.pop( message[ 'request_seq' ] )
KeyError: 0
2020-11-16 21:20:28,296 - DEBUG - Message received: {'command': 'runInTerminal', 'arguments': {'kind': 'integrated', 'title': 'Node Debug Console', 'cwd': '/Users/ben/.vim/bundle/vimspector/support/test/csharp', 'args': ['mono', '--debug', '--debugger-agent=transport=dt_socket,server=y,address=127.0.0.1:57681', 'Program.exe'], 'env': None}, 'seq': 3, 'type': 'request'}
2020-11-16 21:20:28,309 - DEBUG - Sending Message: {"seq": 4, "type": "response", "request_seq": 3, "command": "runInTerminal", "body": {"processId": 74070}, "success": true}
2020-11-16 21:20:28,310 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 1, 'command': 'launch', 'body': None, 'seq': 4, 'type': 'response'}
2020-11-16 21:20:28,332 - DEBUG - Message received: {'success': False, 'message': "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)", 'request_seq': 2, 'command': 'setBreakpoints', 'body': {'error': {'id': 1104, 'format': "error while processing request '{_request}' (exception: {_exception})", 'variables': {'_request': 'setBreakpoints', '_exception': 'Cannot perform runtime binding on a null reference'}, 'showUser': True, 'sendTelemetry': False}}, 'seq': 5, 'type': 'response'}
2020-11-16 21:20:28,332 - ERROR - Request failed: error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)
2020-11-16 21:20:28,332 - WARNING - User Msg: Unable to set breakpoint: error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)
2020-11-16 21:20:28,333 - DEBUG - Message received: {'success': False, 'message': "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)", 'request_seq': 2, 'command': 'setBreakpoints', 'body': {'error': {'id': 1104, 'format': "error while processing request '{_request}' (exception: {_exception})", 'variables': {'_request': 'setBreakpoints', '_exception': 'Cannot perform runtime binding on a null reference'}, 'showUser': True, 'sendTelemetry': False}}, 'seq': 5, 'type': 'response'}
2020-11-16 21:20:28,333 - INFO - User Msg: Protocol error: duplicate response for request 2
2020-11-16 21:20:28,333 - ERROR - Duplicate response: {'success': False, 'message': "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)", 'request_seq': 2, 'command': 'setBreakpoints', 'body': {'error': {'id': 1104, 'format': "error while processing request '{_request}' (exception: {_exception})", 'variables': {'_request': 'setBreakpoints', '_exception': 'Cannot perform runtime binding on a null reference'}, 'showUser': True, 'sendTelemetry': False}}, 'seq': 5, 'type': 'response'}
Traceback (most recent call last):
  File "/Users/ben/.vim/bundle/vimspector/python3/vimspector/debug_adapter_connection.py", line 245, in _OnMessageReceived
    request = self._outstanding_requests.pop( message[ 'request_seq' ] )
KeyError: 2
2020-11-16 21:20:28,336 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 3, 'command': 'setExceptionBreakpoints', 'body': None, 'seq': 6, 'type': 'response'}
2020-11-16 21:20:28,336 - DEBUG - Sending Message: {"command": "threads", "seq": 5, "type": "request"}
2020-11-16 21:20:28,336 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 3, 'command': 'setExceptionBreakpoints', 'body': None, 'seq': 6, 'type': 'response'}
2020-11-16 21:20:28,336 - INFO - User Msg: Protocol error: duplicate response for request 3
2020-11-16 21:20:28,336 - ERROR - Duplicate response: {'success': True, 'message': None, 'request_seq': 3, 'command': 'setExceptionBreakpoints', 'body': None, 'seq': 6, 'type': 'response'}
Traceback (most recent call last):
  File "/Users/ben/.vim/bundle/vimspector/python3/vimspector/debug_adapter_connection.py", line 245, in _OnMessageReceived
    request = self._outstanding_requests.pop( message[ 'request_seq' ] )
KeyError: 3
2020-11-16 21:20:28,341 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 1, 'command': 'launch', 'body': None, 'seq': 4, 'type': 'response'}
2020-11-16 21:20:28,341 - INFO - User Msg: Protocol error: duplicate response for request 1
2020-11-16 21:20:28,341 - ERROR - Duplicate response: {'success': True, 'message': None, 'request_seq': 1, 'command': 'launch', 'body': None, 'seq': 4, 'type': 'response'}
Traceback (most recent call last):
  File "/Users/ben/.vim/bundle/vimspector/python3/vimspector/debug_adapter_connection.py", line 245, in _OnMessageReceived
    request = self._outstanding_requests.pop( message[ 'request_seq' ] )
KeyError: 1
2020-11-16 21:20:28,350 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 5, 'command': 'threads', 'body': {'threads': []}, 'seq': 7, 'type': 'response'}
2020-11-16 21:20:28,350 - WARNING - User Msg: Server returned no threads. Is it running?
2020-11-16 21:20:28,350 - DEBUG - Message received: {'success': True, 'message': None, 'request_seq': 5, 'command': 'threads', 'body': {'threads': []}, 'seq': 7, 'type': 'response'}
2020-11-16 21:20:28,350 - INFO - User Msg: Protocol error: duplicate response for request 5
2020-11-16 21:20:28,352 - ERROR - Duplicate response: {'success': True, 'message': None, 'request_seq': 5, 'command': 'threads', 'body': {'threads': []}, 'seq': 7, 'type': 'response'}
Traceback (most recent call last):
  File "/Users/ben/.vim/bundle/vimspector/python3/vimspector/debug_adapter_connection.py", line 245, in _OnMessageReceived
    request = self._outstanding_requests.pop( message[ 'request_seq' ] )
KeyError: 5
2020-11-16 21:20:28,499 - DEBUG - Message received: {'seq': 8, 'type': 'event', 'event': 'terminated', 'body': None}
2020-11-16 21:20:28,499 - INFO - User Msg: Debugging was terminated by the server.
puremourning commented 3 years ago

Program.cs:

using System;

namespace csharp
{
  class Program
  {
    string toaster = "Making round of toast";
    static int max_bread = 100;
    int bread = max_bread;

    void PrintToast( int r ) {
      int this_round = ( max_bread - bread - r);
      Console.WriteLine( this.toaster + ": " + this_round );
    }

    void MakeToast( int rounds ) {
      if (this.bread - rounds < 0) {
        throw new Exception( "No moar bread!" );
      }

      this.bread -= rounds;
      for (int r = 0; r < rounds; ++r) {
        this.PrintToast( r );
      }

      Console.WriteLine( "Got only " + this.bread + " left" );
    }

    static void Main(string[] args)
    {
      Program p = new Program();
      for (int x = 1; x < 10; ++ x) {
        p.MakeToast( x );
      }
    }
  }
}

compiled with csc -debug Program.cs

OS: macOS Big Sur

ben@BenMBP csharp % csc -version
3.6.0-4.20224.5 (ec77c100)
ben@BenMBP csharp % mono --version
Mono JIT compiler version 6.12.0.90 (tarball Sun Oct 18 19:07:15 BST 2020)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
        TLS:
        SIGSEGV:       altstack
        Notification:  kqueue
        Architecture:  amd64
        Disabled:      none
        Misc:          softdebug
        Interpreter:   yes
        LLVM:          supported, not enabled.
        Suspend:       hybrid
        GC:            sgen (concurrent by default)
puremourning commented 3 years ago

with --log-file and --trace=response, this is the log:

21:43:05 waiting for debug protocol on stdin/stdout
21:43:06 C initialize: {
  "adapterID": "mono-debug",
  "clientID": "vimspector",
  "clientName": "vimspector",
  "linesStartAt1": true,
  "columnsStartAt1": true,
  "locale": "en_GB",
  "pathFormat": "path",
  "supportsVariableType": true,
  "supportsVariablePaging": false,
  "supportsRunInTerminalRequest": true
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 0,
  "command": "initialize",
  "body": {
    "supportsConfigurationDoneRequest": false,
    "supportsFunctionBreakpoints": false,
    "supportsConditionalBreakpoints": false,
    "supportsEvaluateForHovers": false,
    "exceptionBreakpointFilters": []
  },
  "seq": 1,
  "type": "response"
}
21:43:06 E initialized: null
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 0,
  "command": "initialize",
  "body": {
    "supportsConfigurationDoneRequest": false,
    "supportsFunctionBreakpoints": false,
    "supportsConditionalBreakpoints": false,
    "supportsEvaluateForHovers": false,
    "exceptionBreakpointFilters": []
  },
  "seq": 1,
  "type": "response"
}
21:43:06 C launch: {
  "request": "launch",
  "program": "/Users/ben/.vim/bundle/vimspector/support/test/csharp/Program.exe",
  "console": "integratedTerminal",
  "cwd": "/Users/ben/.vim/bundle/vimspector/support/test/csharp",
  "args": [],
  "env": {},
  "name": "test"
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 1,
  "command": "launch",
  "body": null,
  "seq": 4,
  "type": "response"
}
21:43:06 C setBreakpoints: {
  "source": {
    "name": "Program.cs",
    "path": "/Users/ben/.vim/bundle/vimspector/support/test/csharp/Program.cs"
  },
  "breakpoints": [
    {
      "line": 31
    }
  ]
}
21:43:06  R: {
  "success": false,
  "message": "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)",
  "request_seq": 2,
  "command": "setBreakpoints",
  "body": {
    "error": {
      "id": 1104,
      "format": "error while processing request '{_request}' (exception: {_exception})",
      "variables": {
        "_request": "setBreakpoints",
        "_exception": "Cannot perform runtime binding on a null reference"
      },
      "showUser": true,
      "sendTelemetry": false
    }
  },
  "seq": 5,
  "type": "response"
}
21:43:06  R: {
  "success": false,
  "message": "error while processing request 'setBreakpoints' (exception: Cannot perform runtime binding on a null reference)",
  "request_seq": 2,
  "command": "setBreakpoints",
  "body": {
    "error": {
      "id": 1104,
      "format": "error while processing request '{_request}' (exception: {_exception})",
      "variables": {
        "_request": "setBreakpoints",
        "_exception": "Cannot perform runtime binding on a null reference"
      },
      "showUser": true,
      "sendTelemetry": false
    }
  },
  "seq": 5,
  "type": "response"
}
21:43:06 C setExceptionBreakpoints: {
  "filters": []
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 3,
  "command": "setExceptionBreakpoints",
  "body": null,
  "seq": 6,
  "type": "response"
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 3,
  "command": "setExceptionBreakpoints",
  "body": null,
  "seq": 6,
  "type": "response"
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 1,
  "command": "launch",
  "body": null,
  "seq": 4,
  "type": "response"
}
21:43:06 C threads: null
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 5,
  "command": "threads",
  "body": {
    "threads": []
  },
  "seq": 7,
  "type": "response"
}
21:43:06  R: {
  "success": true,
  "message": null,
  "request_seq": 5,
  "command": "threads",
  "body": {
    "threads": []
  },
  "seq": 7,
  "type": "response"
}
21:43:06 E terminated: null
21:43:09 C disconnect: {}
21:43:09  R: {
  "success": true,
  "message": null,
  "request_seq": 6,
  "command": "disconnect",
  "body": null,
  "seq": 9,
  "type": "response"
}
21:43:09  R: {
  "success": true,
  "message": null,
  "request_seq": 6,
  "command": "disconnect",
  "body": null,
  "seq": 9,
  "type": "response"
}