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

TypeScriptCodeFixProvider encountered an error and has been disabled #17486

Closed
NoelAbrahams opened this issue Jul 28, 2017 · 21 comments
Closed
Assignees
Labels
Bug A bug in TypeScript Visual Studio Integration with Visual Studio

Comments

@NoelAbrahams
Copy link

TypeScript Version: 2.4.0
Visual Studio: 15.3.0 Preview 3.0

Visual Studio printed this error in a header.
image

I believe the error was triggered by the following bit of code:

function // Started typing this. The "export class" bit below was already there 

export class Foo {
Newtonsoft.Json.JsonSerializationException : Unexpected end when deserializing object. Path '', line 2, position 0.
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.ThrowUnexpectedEndException(JsonReader reader,JsonContract contract,Object currentObject,String message)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject,JsonReader reader,JsonObjectContract contract,JsonProperty member,String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader,Type objectType,JsonContract contract,JsonProperty member,JsonContainerContract containerContract,JsonProperty containerMember,Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader,Type objectType,JsonContract contract,JsonProperty member,JsonContainerContract containerContract,JsonProperty containerMember,Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.Deserialize(JsonReader reader,Type objectType,Boolean checkAdditionalContent)
   at Newtonsoft.Json.JsonSerializer.DeserializeInternal(JsonReader reader,Type objectType)
   at Newtonsoft.Json.JsonSerializer.Deserialize[T](JsonReader reader)
   at Microsoft.CodeAnalysis.Editor.TypeScript.ScriptServices.TSServerProxy.Send[T](String commandName,Object arguments,Optional`1 defaultValue,Boolean isInitializationRequest)
   at Microsoft.CodeAnalysis.Editor.TypeScript.ScriptServices.TSServerProxy.GetCodeFixesAtPosition(Document document,TextSpan span,Int32[] errorCodes,CancellationToken cancellationToken)
   at Microsoft.CodeAnalysis.Editor.TypeScript.Features.CodeFixes.TypeScriptCodeFixProvider.<>c__DisplayClass8_0.<RegisterCodeFixesAsync>b__3(TSServerProxy proxy,CancellationToken operationToken)
   at Microsoft.CodeAnalysis.Editor.TypeScript.Features.TaskHandler.<>c__DisplayClass20_0`1.<InvokeTSServerViaSchedulerAsync>b__0(CancellationToken ct)
   at Microsoft.CodeAnalysis.Editor.TypeScript.Threading.PriorityWorkScheduler.<>c__DisplayClass6_0.<RunNextTaskAsync>b__0()
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
   at async Microsoft.CodeAnalysis.Editor.TypeScript.Features.TaskHandler.InvokeTSServerViaSchedulerAsync[T](<Unknown Parameters>)
   at async Microsoft.CodeAnalysis.Editor.TypeScript.Features.TaskHandler.InvokeTSServerAsync[T](<Unknown Parameters>)
   at async Microsoft.CodeAnalysis.Editor.TypeScript.Features.CodeFixes.TypeScriptCodeFixProvider.RegisterCodeFixesAsync(<Unknown Parameters>)
   at async Microsoft.CodeAnalysis.Extensions.IExtensionManagerExtensions.PerformActionAsync(<Unknown Parameters>)
@DanielRosenwasser DanielRosenwasser added Bug A bug in TypeScript Visual Studio Integration with Visual Studio labels Jul 28, 2017
@DanielRosenwasser DanielRosenwasser added this to the Visual Studio 15.4 milestone Jul 28, 2017
@amcasey
Copy link
Member

amcasey commented Jul 29, 2017

The stack suggests that the JSON returned by TSServer in response to the request for code fixes (getCodeFixes-full) was malformed (truncated?).

I'm guessing that the error is reported as being on line 2 because the content on line 1 (in a 1-based system?) is unterminated and end-of-stream is the first place we can conclude that it never will be. Otherwise, I can't explain it because I'm pretty sure all of our requests and responses occupy a single line.

@amcasey
Copy link
Member

amcasey commented Jul 29, 2017

Assuming that this is a problem with the JSON itself (rather than its contents), this is unlikely to be fixed by the hardening we've recently done in our deserialization code.

@amcasey
Copy link
Member

amcasey commented Jul 29, 2017

We don't support very many code fixes in 15.3, so it seems unlikely that the message was truncated for being too long. A TSServer crash seems like a more plausible explanation.

@NoelAbrahams, do you have an event log entry indicating a crash in node.exe?

@NoelAbrahams
Copy link
Author

@amcasey, sorry for the delay. No there is nothing in the logs for node.exe.

@amcasey
Copy link
Member

amcasey commented Jul 31, 2017

@NoelAbrahams are you able to reproduce the issue? I tried poking around with the code you provided but didn't have any problems. Even if you can't reproduce it deterministically, have you seen it more than once?

@NoelAbrahams
Copy link
Author

@amcasey, I am able to reproduce it deterministically via the following bit of code:

namespace foo {

    function 

    class Foo {

    }
}

It does not reproduce without the namespace.

@amcasey
Copy link
Member

amcasey commented Aug 1, 2017

Thanks, @NoelAbrahams, that's a big help! I tried it on our latest build and had no issues, so it might already be fixed. I'll confirm that I can repro it in an older build to ensure that I'm not just missing something.

@amcasey
Copy link
Member

amcasey commented Aug 2, 2017

@NoelAbrahams, I installed 15.3P3 and TS2.4, but was unable to repro the issue. Would you mind trying to grab a TSServer trace of the issue?

https://github.com/Microsoft/TypeScript/wiki/Standalone-Server-%28tsserver%29#logging

TL;DR: Create a directory like c:\tsslog and set TSS_LOG=-file C:/tsslog/tsserver.log -level verbose

Thanks!

@NoelAbrahams
Copy link
Author

@amcasey, here is the output from the normal verbosity. This is the additional output that was logged following the crash.

The following bit was added to the head (line 0, position 0) of file foo.ts

namespace foo {

    function  

    class Foo {

    }
}

I'm not able to send the verbose logging as it contains details on all files in our project system.

I hope this is sufficient. If not let me know.

Host file extension mappings updated
Err 386   

Exception on executing command {"seq":25183,"command":"documentHighlights-full","arguments": {"file":"c:\\foo.ts","position":0, "filesToSearch":["c:\\foo.ts"]}}:

Cannot read property 'kind' of undefined
TypeError: Cannot read property 'kind' of undefined
    
at Object.isJsxOpeningElement (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:9029:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:63482:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:74445:42)
at IOSession.Session.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79822:71)
at Session.handlers.ts.createMapFromTemplate._a.(anonymous function) (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79444:61)
at C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:88
at IOSession.Session.executeWithRequestId (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80648:28)
at IOSession.Session.executeCommand (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:33)
at IOSession.Session.onMessage (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80677:35)
at Interface.<anonymous> (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:81864:27)
Err 387   

Exception on executing command {"seq":25199,"command":"documentHighlights-full","arguments": {"file":"c:\\foo.ts","position":2,"filesToSearch":["c:\\foo.ts"]}}:
Cannot read property 'kind' of undefined
TypeError: Cannot read property 'kind' of undefined
at Object.isJsxOpeningElement (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:9029:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:63482:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:74445:42)
at IOSession.Session.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79822:71)
at Session.handlers.ts.createMapFromTemplate._a.(anonymous function) (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79444:61)
at C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:88
at IOSession.Session.executeWithRequestId (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80648:28)
at IOSession.Session.executeCommand (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:33)
at IOSession.Session.onMessage (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80677:35)
at Interface.<anonymous> (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:81864:27)
Err 388   

Exception on executing command {"seq":25201,"command":"documentHighlights-full","arguments": {"file":"c:\\foo.ts","position":0, "filesToSearch":["c:\\foo.ts"]}}:
Cannot read property 'kind' of undefined
TypeError: Cannot read property 'kind' of undefined
at Object.isJsxOpeningElement (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:9029:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:63482:20)
at Object.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:74445:42)
at IOSession.Session.getDocumentHighlights (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79822:71)
at Session.handlers.ts.createMapFromTemplate._a.(anonymous function) (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:79444:61)
at C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:88
at IOSession.Session.executeWithRequestId (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80648:28)
at IOSession.Session.executeCommand (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80657:33)
at IOSession.Session.onMessage (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:80677:35)
at Interface.<anonymous> (C:\Program Files (x86)\Microsoft SDKs\TypeScript\2.4\tsserver.js:81864:27)

@amcasey
Copy link
Member

amcasey commented Aug 3, 2017

Ah, that issue. That should be fixed by 587309d.

@amcasey
Copy link
Member

amcasey commented Aug 3, 2017

Looks like that change didn't make it into 2.4, but it should be available in the next release.

@amcasey amcasey closed this as completed Aug 3, 2017
@amcasey amcasey reopened this Aug 3, 2017
@amcasey
Copy link
Member

amcasey commented Aug 3, 2017

Actually, I guess there's a second issue here. While a TSServer crash is undesirable, VS is supposed to be resilient against that. Do you get anything useful when you click "Show Stack Trace" in the yellow warning bar?

Update: Oh, of course that's the stack you originally filed.

@amcasey
Copy link
Member

amcasey commented Aug 3, 2017

Alright, it sounds like I misunderstood our resiliency goals. We're fine with the unhandled exception here because it brings such issues to our attention. However, we'd still like to understand how a failure to process a documentHighlights-full request resulted in a failure in getCodeFixes-full. Are you able to share the last couple getCodeFixes-full request-response pairs from your log?

@NoelAbrahams
Copy link
Author

Here you go... these are the only references to getCodeFixes-full in the entire verbose log.

Info 25860request: {"seq":8470,"command":"getCodeFixes-full","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","startPosition":31,"endPosition":31,"errorCodes":[6133]}}
Perf 258618470::getCodeFixes-full: elapsed time (in milliseconds) 1.3657
Info 25862response: {"seq":0,"type":"response","command":"getCodeFixes-full","request_seq":8470,"success":true,"body":[null]}
Info 25863request: {"seq":8471,"command":"getApplicableRefactors","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","startPosition":32,"endPosition":32}}
Perf 258648471::getApplicableRefactors: elapsed time (in milliseconds) 0.1661
Info 25865response: {"seq":0,"type":"response","command":"getApplicableRefactors","request_seq":8471,"success":false,"message":"No content available."}
Info 25866request: {"seq":8472,"command":"brace-full","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","position":31}}
Perf 258678472::brace-full: elapsed time (in milliseconds) 0.5295
Info 25868response: {"seq":0,"type":"response","command":"brace-full","request_seq":8472,"success":true,"body":[]}
Info 25869request: {"seq":8473,"command":"encodedSemanticClassifications-full","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","start":0,"length":3659}}
Perf 258708473::encodedSemanticClassifications-full: elapsed time (in milliseconds) 12.1227
Info 25871response: {"seq":0,"type":"response","command":"encodedSemanticClassifications-full","request_seq":8473,"success":true,"body":{"spans":[10,3,14,46,3,11,79,2,14,82,7,14,152,11,11,175,10,14,186,11,13,199,10,13,280,10,14,291,14,13,344,10,14,355,9,13,404,10,14,415,10,13,1173,2,14,1176,3,16,1418,6,14,1425,18,16,1465,10,14,1476,5,13,1513,10,14,1524,7,13,2918,6,14,2925,6,11,2932,6,14,2939,15,13,2989,6,14,2996,6,11,3003,6,14,3010,10,13,3054,6,14,3061,6,11,3068,6,14,3075,10,13,3119,6,14,3126,6,11,3133,6,14,3140,12,16],"endOfLineState":0}}
Info 25872request: {"seq":8474,"command":"brace-full","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","position":30}}
Perf 258738474::brace-full: elapsed time (in milliseconds) 0.3628
Info 25874response: {"seq":0,"type":"response","command":"brace-full","request_seq":8474,"success":true,"body":[]}
Info 25875request: {"seq":8475,"command":"documentHighlights-full","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","position":31,"filesToSearch":["c:\\foo\\baz\\string\\inputString.ts"]}}
Perf 258768475::documentHighlights-full: elapsed time (in milliseconds) 0.8378
Info 25877response: {"seq":0,"type":"response","command":"documentHighlights-full","request_seq":8475,"success":false,"message":"No content available."}
Info 25878request: {"seq":8476,"command":"getApplicableRefactors","arguments":{"file":"c:\\foo\\baz\\string\\inputString.ts","startPosition":31,"endPosition":31}}
Perf 258798476::getApplicableRefactors: elapsed time (in milliseconds) 0.6550
Info 25880response: {"seq":0,"type":"response","command":"getApplicableRefactors","request_seq":8476,"success":false,"message":"No content available."}
Info 25881request: {"seq":8477,"command":"compilerOptionsDiagnostics-full","arguments":{"projectFileName":"c:/foo//baz/tsconfig.json"}}
Perf 258828477::compilerOptionsDiagnostics-full: elapsed time (in milliseconds) 0.2290
Info 25883response: {"seq":0,"type":"response","command":"compilerOptionsDiagnostics-full","request_seq":8477,"success":true,"body":[]}
Info 25884request: {"seq":8478,"command":"syntacticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\lib.d.ts","includeLinePosition":true}}
Perf 258858478::syntacticDiagnosticsSync: elapsed time (in milliseconds) 0.0988
Info 25886response: {"seq":0,"type":"response","command":"syntacticDiagnosticsSync","request_seq":8478,"success":true,"body":[]}
Info 25887request: {"seq":8479,"command":"semanticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\lib.d.ts","includeLinePosition":true,"projectFileName":"c:/foo//baz/tsconfig.json"}}
Perf 258888479::semanticDiagnosticsSync: elapsed time (in milliseconds) 28.9411
Info 25889response: {"seq":0,"type":"response","command":"semanticDiagnosticsSync","request_seq":8479,"success":true,"body":[]}
Info 25890request: {"seq":8480,"command":"syntacticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\events\\events.d.ts","includeLinePosition":true}}
Perf 258918480::syntacticDiagnosticsSync: elapsed time (in milliseconds) 0.0978
Info 25892response: {"seq":0,"type":"response","command":"syntacticDiagnosticsSync","request_seq":8480,"success":true,"body":[]}
Info 25893request: {"seq":8481,"command":"semanticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\events\\events.d.ts","includeLinePosition":true,"projectFileName":"c:/foo//baz/tsconfig.json"}}
Perf 258948481::semanticDiagnosticsSync: elapsed time (in milliseconds) 1.3878
Info 25895response: {"seq":0,"type":"response","command":"semanticDiagnosticsSync","request_seq":8481,"success":true,"body":[]}
Info 25896request: {"seq":8482,"command":"syntacticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\params\\route\\queryString.d.ts","includeLinePosition":true}}
Perf 258978482::syntacticDiagnosticsSync: elapsed time (in milliseconds) 0.0674
Info 25898response: {"seq":0,"type":"response","command":"syntacticDiagnosticsSync","request_seq":8482,"success":true,"body":[]}
Info 25899request: {"seq":8483,"command":"semanticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\params\\route\\queryString.d.ts","includeLinePosition":true,"projectFileName":"c:/foo//baz/tsconfig.json"}}
Perf 259008483::semanticDiagnosticsSync: elapsed time (in milliseconds) 0.4930
Info 25901response: {"seq":0,"type":"response","command":"semanticDiagnosticsSync","request_seq":8483,"success":true,"body":[]}
Info 25902request: {"seq":8484,"command":"syntacticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\params\\geo.d.ts","includeLinePosition":true}}
Perf 259038484::syntacticDiagnosticsSync: elapsed time (in milliseconds) 0.0641
Info 25904response: {"seq":0,"type":"response","command":"syntacticDiagnosticsSync","request_seq":8484,"success":true,"body":[]}
Info 25905request: {"seq":8485,"command":"semanticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\params\\geo.d.ts","includeLinePosition":true,"projectFileName":"c:/foo//baz/tsconfig.json"}}
Perf 259068485::semanticDiagnosticsSync: elapsed time (in milliseconds) 1.5925
Info 25907response: {"seq":0,"type":"response","command":"semanticDiagnosticsSync","request_seq":8485,"success":true,"body":[]}
Info 25908request: {"seq":8486,"command":"syntacticDiagnosticsSync","arguments":{"file":"c:\\foo\\bar\\params\\user.d.ts","includeLinePosition":true}}
Perf 259098486::syntacticDiagnosticsSync: elapsed time (in milliseconds) 0.0799

@amcasey
Copy link
Member

amcasey commented Aug 4, 2017

Thanks! I'm pretty suspicious of this bit: "body":[null]. I wouldn't have guessed the server could send that. I'll try to simulate such a message and see if I get the same failure you're seeing.

@amcasey
Copy link
Member

amcasey commented Aug 4, 2017

Per our request, newtonsoft drops the null and then we consume the ] as the beginning of an object, throwing off the remainder of the parse. Should be straightforward to fix.

I'd also like to understand why the null is sent.

Edit: The bit about newtonsoft dropping the null is inaccurate - it actually gets consumed by another call - but the effect is the same.

@amcasey
Copy link
Member

amcasey commented Aug 4, 2017

The parsing/deserialization fix is straightforward and should be available in a future release of VS.

That leaves how the server could have sent [null] as the remaining question.

@amcasey
Copy link
Member

amcasey commented Aug 7, 2017

For anyone reviewing this issue, the repro requires "noUnusedLocals": true.

I can hit the reported issue without seeing the documentHighlights-full exception, so the two issues are probably unrelated.

@amcasey
Copy link
Member

amcasey commented Aug 7, 2017

The [null] issue was fixed in commit 3915d46.

@amcasey
Copy link
Member

amcasey commented Aug 7, 2017

So, to summarize, there were three issues here:

  1. An exception in documentHighlights-full, fixed by 587309d;
  2. An undefined code fix returned by getCodeFixes-full, fixed by 3915d46; and
  3. Missing null parsing logic in VS, fixed internally.

@amcasey amcasey closed this as completed Aug 7, 2017
@NoelAbrahams
Copy link
Author

Impressive 👍

@microsoft microsoft locked and limited conversation to collaborators Jun 14, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Bug A bug in TypeScript Visual Studio Integration with Visual Studio
Projects
None yet
Development

No branches or pull requests

3 participants