Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Thread exited event ignored #1703

Closed
felixfbecker opened this issue Dec 30, 2015 · 22 comments
Closed

Thread exited event ignored #1703

felixfbecker opened this issue Dec 30, 2015 · 22 comments
Assignees
Labels
bug Issue identified by VS Code Team member as probable bug debug Debug viewlet, configurations, breakpoints, adapter issues verified Verification succeeded
Milestone

Comments

@felixfbecker
Copy link
Contributor

Even though clearly an thread event with reason: "exited" is sent, VS Code does not update the UI to remove the exited thread:

threads bug

last communication:

-> continueRequest
{ type: 'request',
  seq: 21,
  command: 'continue',
  arguments: { threadId: 2 } }

<- continueResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 21,
  command: 'continue',
  success: true }

<- threadEvent
ThreadEvent {
  seq: 0,
  type: 'event',
  event: 'thread',
  body: { reason: 'exited', threadId: 2 } }

When a stack frame inside the dead thread is clicked VS Code tries to request the variables inside a thread that doesn't exist anymore.

Even weirder, the threads even keep showing even after the debug session ended:
threads ui bug

@bpasero bpasero added bug Issue identified by VS Code Team member as probable bug debug Debug viewlet, configurations, breakpoints, adapter issues labels Dec 30, 2015
@bpasero bpasero added this to the Backlog milestone Dec 30, 2015
@isidorn
Copy link
Contributor

isidorn commented Jan 4, 2016

@felixfbecker I can not repro this issue on my side. Are you sure you are giving unique threadIds to your threads? What happens if you only use one thread, does it work nicely? What happens if send an exited event for the first thread?

@vadimcn
Copy link
Contributor

vadimcn commented Jan 4, 2016

Does the tread id need to be unique at any given moment or for the whole lifetime of the process?
In other words, if a thread id=3 exits, and then a new thread is started, can the new thread's id be 3?

@felixfbecker
Copy link
Contributor Author

@isidorn I'm pretty sure I'm giving 100% unique thread IDs, I just increment a counter for each new thread. I will look into it again.

@felixfbecker
Copy link
Contributor Author

@isidorn here are the full logs of a debug session where I trigger 2 threads and then continue one of them until it exits (btw, this is hard to get because you cannot do Ctrl+A in the debug console):
https://gist.github.com/felixfbecker/378a13c6306a4ed145cc

  • In line 111 I notify Code with Thread 1.
  • In line 201 I notify Code with Thread 2 (in the following ThreadResponse you can clearly see they have unique IDs)
  • In line 425 I notify Code that Thread 1 has exited. And directly after that, VS Code requests a stack frame for the thread that doesn't even exist anymore.

and of course, UI doesn't update at all besides the empty stack trace that I sent it.
image


EDIT: I have to apologize, the posted log does not contain the ThreadEvent. See below for a better example.

@isidorn
Copy link
Contributor

isidorn commented Jan 5, 2016

@vadimcn thread id needs to be unque at any given moment, not the whole lifetime
@felixfbecker thanks for more details, I will look into it

@felixfbecker
Copy link
Contributor Author

I could not reproduce this anymore.

@felixfbecker
Copy link
Contributor Author

Actually, it's still there. Just tried it again with a super simple setup, newest version of everything.

@felixfbecker felixfbecker reopened this Mar 8, 2016
@isidorn isidorn modified the milestones: March 2016, Backlog Mar 8, 2016
@felixfbecker
Copy link
Contributor Author

Ok, here another demo:

animation

As you can see, I have two threads running, and I continue one so it ends. The adapter is correctly sending a ThreadEvent with exited, but VS Code UI does not update, in fact, it still displays the old stack trace, it is impossible to control the second thread anymore (it shows pause instead of run icon) and even after stopping the stack trace is still displayed. When I click scopes in the variables section Code still tries to request variables for the exited thread.

Here the last piece of log:

-> continueRequest
{ type: 'request',
  seq: 23,
  command: 'continue',
  arguments: { threadId: 1 } }
<- continueResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 23,
  command: 'continue',
  success: true }
<- threadEvent
ThreadEvent {
  seq: 0,
  type: 'event',
  event: 'thread',
  body: { reason: 'exited', threadId: 1 } }

The IDs are correct, see this snippet:

<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 11,
  command: 'threads',
  success: true,
  body: 
   { threads: 
      [ Thread { id: 1, name: 'Request 1 (5:37:28 PM)' },
        Thread { id: 2, name: 'Request 2 (5:37:50 PM)' } ] } }

@isidorn isidorn modified the milestones: Backlog, March 2016 Mar 11, 2016
@isidorn
Copy link
Contributor

isidorn commented Mar 11, 2016

We will change how we handle threads mostly due to #3990
So putting this back on backlog, as I would like to first fix our thread handling and then look into this

@felixfbecker
Copy link
Contributor Author

That's unfortunate. PHP debugging involves multiple requests in most of the cases, I get bug report after bug report and cannot do anything about it because the Thread system in VS Code seems somehow broken itself :/

@isidorn
Copy link
Contributor

isidorn commented Mar 11, 2016

If we get a PR in time for March this issue should be addressed. If we do not get a PR in I can investigate into this explicit issue next week.

@felixfbecker
Copy link
Contributor Author

I read through #3650 but I don't understand how it is related to this issue?

@isidorn
Copy link
Contributor

isidorn commented Mar 11, 2016

It is not directly related but that issue will probably require a restructuring of how we handle threads in the vscode model. And that is very related to this issue.

@isidorn
Copy link
Contributor

isidorn commented Mar 24, 2016

@felixfbecker threads have underwent a refactoring, do you stil see this issue with the latest insiders build?

@felixfbecker
Copy link
Contributor Author

@isidorn It actually became worse. I am testing with 0.10.12-insider and latest 1.5.1 of my extension (same as last demo).

  • once the new thread comes in, the stack trace for the first disappears
  • running one thread to the end makes all stack traces disappear as if all threads ended

animation

I did the work to get the log again for you:

<- launchResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 2,
  command: 'launch',
  success: true }
new connection 1
<- threadEvent
ThreadEvent {
  seq: 0,
  type: 'event',
  event: 'thread',
  body: { reason: 'started', threadId: 1 } }
-> threadsRequest
{ type: 'request', seq: 3, command: 'threads' }
<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 3,
  command: 'threads',
  success: true,
  body: { threads: [ Thread { id: 1, name: 'Request 1 (1:23:19 PM)' } ] } }
<- initializedEvent
InitializedEvent { seq: 0, type: 'event', event: 'initialized' }
-> setBreakpointsRequest
{ type: 'request',
  seq: 4,
  command: 'setBreakpoints',
  arguments: 
   { source: { path: 'c:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\variables.php' },
     lines: [ 10 ],
     breakpoints: [ { line: 10 } ] } }
-> setBreakpointsRequest
{ type: 'request',
  seq: 5,
  command: 'setBreakpoints',
  arguments: 
   { source: { path: 'c:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\hello_world.php' },
     lines: [ 4 ],
     breakpoints: [ { line: 4 } ] } }
<- setBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 4,
  command: 'setBreakpoints',
  success: true,
  body: { breakpoints: [ { verified: true, line: 10, id: 51480001 } ] } }
<- setBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 5,
  command: 'setBreakpoints',
  success: true,
  body: { breakpoints: [ { verified: true, line: 4, id: 51480002 } ] } }
-> setFunctionBreakpointsRequest
{ type: 'request',
  seq: 6,
  command: 'setFunctionBreakpoints',
  arguments: { breakpoints: [] } }
<- setFunctionBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 6,
  command: 'setFunctionBreakpoints',
  success: true,
  body: { breakpoints: [] } }
-> setExceptionBreakpointsRequest
{ type: 'request',
  seq: 7,
  command: 'setExceptionBreakpoints',
  arguments: { filters: [] } }
<- setExceptionBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 7,
  command: 'setExceptionBreakpoints',
  success: true }
-> configurationDoneRequest
{ type: 'request', seq: 8, command: 'configurationDone' }
<- configurationDoneResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 8,
  command: 'configurationDone',
  success: true }
<- stoppedEvent
StoppedEvent {
  seq: 0,
  type: 'event',
  event: 'stopped',
  body: { reason: 'breakpoint', threadId: 1 } }
-> stackTraceRequest
{ type: 'request',
  seq: 9,
  command: 'stackTrace',
  arguments: { threadId: 1, levels: 20 } }
<- stackTraceResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 9,
  command: 'stackTrace',
  success: true,
  body: 
   { stackFrames: 
      [ StackFrame {
          id: 1,
          source: 
           Source {
             name: 'variables.php',
             path: 'C:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\variables.php',
             sourceReference: 0 },
          line: 10,
          column: 1,
          name: '{main}' } ] } }
-> scopesRequest
{ type: 'request',
  seq: 10,
  command: 'scopes',
  arguments: { frameId: 1 } }
<- scopesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 10,
  command: 'scopes',
  success: true,
  body: 
   { scopes: 
      [ Scope { name: 'Locals', variablesReference: 1, expensive: false },
        Scope { name: 'Superglobals', variablesReference: 2, expensive: false },
        Scope {
          name: 'User defined constants',
          variablesReference: 3,
          expensive: false } ] } }
-> variablesRequest
{ type: 'request',
  seq: 11,
  command: 'variables',
  arguments: { variablesReference: 1 } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 11,
  command: 'variables',
  success: true,
  body: 
   { variables: 
      [ Variable {
          name: '$aBoolean',
          value: 'uninitialized',
          variablesReference: 0 },
        Variable { name: '$aFloat', value: '1.23', variablesReference: 0 },
        Variable {
          name: '$aLargeArray',
          value: 'uninitialized',
          variablesReference: 0 },
        Variable { name: '$aString', value: '"123"', variablesReference: 0 },
        Variable { name: '$anArray', value: 'array(2)', variablesReference: 4 },
        Variable { name: '$anEmptyString', value: '""', variablesReference: 0 },
        Variable { name: '$anInt', value: '123', variablesReference: 0 },
        Variable {
          name: '$nullValue',
          value: 'uninitialized',
          variablesReference: 0 },
        Variable {
          name: '$variableThatsNotSet',
          value: 'uninitialized',
          variablesReference: 0 } ] } }
-> variablesRequest
{ type: 'request',
  seq: 12,
  command: 'variables',
  arguments: { variablesReference: 2 } }
-> variablesRequest
{ type: 'request',
  seq: 13,
  command: 'variables',
  arguments: { variablesReference: 3 } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 12,
  command: 'variables',
  success: true,
  body: 
   { variables: 
      [ Variable { name: '$_COOKIE', value: 'array(0)', variablesReference: 5 },
        Variable { name: '$_ENV', value: 'array(0)', variablesReference: 6 },
        Variable { name: '$_FILES', value: 'array(0)', variablesReference: 7 },
        Variable { name: '$_GET', value: 'array(0)', variablesReference: 8 },
        Variable { name: '$_POST', value: 'array(0)', variablesReference: 9 },
        Variable { name: '$_REQUEST', value: 'array(0)', variablesReference: 10 },
        Variable { name: '$_SERVER', value: 'array(61)', variablesReference: 11 } ] } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 13,
  command: 'variables',
  success: true,
  body: { variables: [ Variable { name: 'TEST_CONSTANT', value: '123', variablesReference: 0 } ] } }
new connection 2
<- threadEvent
ThreadEvent {
  seq: 0,
  type: 'event',
  event: 'thread',
  body: { reason: 'started', threadId: 2 } }
-> threadsRequest
{ type: 'request', seq: 14, command: 'threads' }
<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 14,
  command: 'threads',
  success: true,
  body: 
   { threads: 
      [ Thread { id: 1, name: 'Request 1 (1:23:19 PM)' },
        Thread { id: 2, name: 'Request 2 (1:23:27 PM)' } ] } }
<- initializedEvent
InitializedEvent { seq: 0, type: 'event', event: 'initialized' }
-> setBreakpointsRequest
{ type: 'request',
  seq: 15,
  command: 'setBreakpoints',
  arguments: 
   { source: { path: 'c:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\variables.php' },
     lines: [ 10 ],
     breakpoints: [ { line: 10 } ] } }
-> setBreakpointsRequest
{ type: 'request',
  seq: 16,
  command: 'setBreakpoints',
  arguments: 
   { source: { path: 'c:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\hello_world.php' },
     lines: [ 4 ],
     breakpoints: [ { line: 4 } ] } }
<- setBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 15,
  command: 'setBreakpoints',
  success: true,
  body: { breakpoints: [ { verified: true, line: 10, id: 51480003 } ] } }
<- setBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 16,
  command: 'setBreakpoints',
  success: true,
  body: { breakpoints: [ { verified: true, line: 4, id: 51480004 } ] } }
-> setFunctionBreakpointsRequest
{ type: 'request',
  seq: 17,
  command: 'setFunctionBreakpoints',
  arguments: { breakpoints: [] } }
<- setFunctionBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 17,
  command: 'setFunctionBreakpoints',
  success: true,
  body: { breakpoints: [] } }
-> setExceptionBreakpointsRequest
{ type: 'request',
  seq: 18,
  command: 'setExceptionBreakpoints',
  arguments: { filters: [] } }
<- setExceptionBreakpointsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 18,
  command: 'setExceptionBreakpoints',
  success: true }
-> configurationDoneRequest
{ type: 'request', seq: 19, command: 'configurationDone' }
<- configurationDoneResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 19,
  command: 'configurationDone',
  success: true }
<- stoppedEvent
StoppedEvent {
  seq: 0,
  type: 'event',
  event: 'stopped',
  body: { reason: 'breakpoint', threadId: 2 } }
-> stackTraceRequest
{ type: 'request',
  seq: 20,
  command: 'stackTrace',
  arguments: { threadId: 2, levels: 20 } }
<- stackTraceResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 20,
  command: 'stackTrace',
 success: true,
  body: 
   { stackFrames: 
      [ StackFrame {
          id: 2,
          source: 
           Source {
             name: 'hello_world.php',
             path: 'C:\\Users\\felix\\git\\opensource\\vscode-php-debug\\testproject\\hello_world.php',
             sourceReference: 0 },
          line: 4,
          column: 1,
          name: '{main}' } ] } }
-> scopesRequest
{ type: 'request',
  seq: 21,
  command: 'scopes',
  arguments: { frameId: 2 } }
<- scopesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 21,
  command: 'scopes',
  success: true,
  body: 
   { scopes: 
      [ Scope { name: 'Locals', variablesReference: 12, expensive: false },
        Scope {
          name: 'Superglobals',
          variablesReference: 13,
          expensive: false },
        Scope {
          name: 'User defined constants',
          variablesReference: 14,
          expensive: false } ] } }
-> variablesRequest
{ type: 'request',
  seq: 22,
  command: 'variables',
  arguments: { variablesReference: 12 } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 22,
  command: 'variables',
  success: true,
  body: { variables: [] } }
-> variablesRequest
{ type: 'request',
  seq: 23,
  command: 'variables',
  arguments: { variablesReference: 13 } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 23,
  command: 'variables',
  success: true,
  body: 
   { variables: 
      [ Variable { name: '$_COOKIE', value: 'array(0)', variablesReference: 15 },
        Variable { name: '$_ENV', value: 'array(0)', variablesReference: 16 },
        Variable { name: '$_FILES', value: 'array(0)', variablesReference: 17 },
        Variable { name: '$_GET', value: 'array(0)', variablesReference: 18 },
        Variable { name: '$_POST', value: 'array(0)', variablesReference: 19 },
        Variable { name: '$_REQUEST', value: 'array(0)', variablesReference: 20 },
        Variable { name: '$_SERVER', value: 'array(61)', variablesReference: 21 } ] } }
-> variablesRequest
{ type: 'request',
  seq: 24,
  command: 'variables',
  arguments: { variablesReference: 21 } }
<- variablesResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 24,
  command: 'variables',
  success: true,
  body: 
   { variables: 
      [ I omit these here because they are not important ] } }
-> continueRequest
{ type: 'request',
  seq: 25,
  command: 'continue',
  arguments: { threadId: 2 } }
<- continueResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 25,
  command: 'continue',
  success: true }
<- threadEvent
ThreadEvent {
  seq: 0,
  type: 'event',
  event: 'thread',
  body: { reason: 'exited', threadId: 2 } }

@isidorn isidorn modified the milestones: April 2016, Backlog Mar 29, 2016
@felixfbecker felixfbecker mentioned this issue Apr 4, 2016
68 tasks
@isidorn
Copy link
Contributor

isidorn commented Apr 20, 2016

@felixfbecker first of all, sorry for the slow response, this somehow went under my radar.
Can you please try to reproduce this issue with the latest alpha vscode available here that includes some of the potential fixes for this issue.

If you still see it, please attach a small php sample for which I can repro this. I will then switch to a windows machine and setup the php debugger to investigate further.

Thanks

@felixfbecker
Copy link
Contributor Author

felixfbecker commented Apr 20, 2016

@isidorn Tried the alpha release, but the problem described above still exists (stack disappears, exit ignored). When I try to continue the already-exited thread, my debug adapter sends an error response with "Unknown Thread ID". I also noticed another issue in the alpha build that is not in stable or insiders: the TerminatedEvent is ignored too.

Any PHP file will do for reproducing, like https://github.com/felixfbecker/vscode-php-debug/blob/master/testproject/hello_world.php. I would recommend you to use the whole testproject folder as it already includes a launch.json. Just set a breakpoint, select "Listen for XDebug" and start the same script twice from the command line, like in the demo GIF. I can assist you in setting up XDebug if you need help.

@isidorn
Copy link
Contributor

isidorn commented Apr 21, 2016

I could setup xcode using instructions for your extension - thanks!
Regarding the terminated event ignored, that is a dup of #5598 which is fixed now.

There have been multiple issues which have made the thread experience bad. These issues have been covered by the following commits:

66dcd04
e987744
05d8d9e
b1b0dd5
619f10e

Previosuly on Continue vscode would continue all the threads. This is now changed that only the current debugged thread is continued.
Some behavior has been changed with the allThreadsStopped, because I believe there was an issue.
@edumunoz please check commit 66dcd04 and please try the cpp thread scenarios with latest version of vscode
@felixfbecker I have checked PHP after all these fixes and it looks good to me, please check it on the alpha version of vscode (which should update in 10minutes) and let me know if you see more issues. Thanks for reporting this and sorry once again for the slow response.

@isidorn isidorn closed this as completed Apr 21, 2016
@isidorn
Copy link
Contributor

isidorn commented Apr 22, 2016

FYI @edumunoz also created #5643

@isidorn
Copy link
Contributor

isidorn commented Apr 22, 2016

FYI also created test plan item #5644, so let me know if you think of some scenarios that should be tested

@felixfbecker
Copy link
Contributor Author

@isidorn Tested, everything works as it should! Great work

@isidorn isidorn added the verified Verification succeeded label Apr 22, 2016
@andrewcrawley
Copy link

Tested cpptools on master, looks good. One possible regression from 0.10.13-insider, filed #5784.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Issue identified by VS Code Team member as probable bug debug Debug viewlet, configurations, breakpoints, adapter issues verified Verification succeeded
Projects
None yet
Development

No branches or pull requests

5 participants