HIE reports garbled source code

[kfigiela]

This is really strange. Not sure if this is issue with VS Code plugin of HIE.

It looks like HIE under some conditions is working on malformed source. HIE stops working properly and reports strange parse errors for some files: source code in error message is garbled, some characters are repeated and sections are duplicated and reversed. Changing file (also emptying it and reverting previous content) does not help. Restarting HIE does not help too. Sometimes restart of VS Code helps. Source code in subject ofc is correct and compiles fine. Parse errors are reported both from ghc-mod and hlint sources of HIE.

the actual source was

type CheckoutEffs effs =
   ( LoggerEff effs
   , Member RestaurantL effs
   , Member AccountL effs
   , Member MenuL effs
   , ...

I am unable to provide reproducible steps, however it happens quite often for me. Are there any other logs I should look into?

Full log:

2018-04-27 14:36:58.567859 [ThreadId 7] - setTypecheckedModule: Didn't get typechecked module for: "[REDACTED].hs"
2018-04-27 14:36:58.568015 [ThreadId 7] - ghcDispatcher: top of loop
2018-04-27 14:36:58.568101 [ThreadId 7] - got request with id: Nothing
2018-04-27 14:36:58.568726 [ThreadId 5] - <--2--{"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file://[REDACTED].hs","diagnostics":[{"severity":1,"range":{"start":{"line":59,"character":11},"end":{"line":59,"character":12}},"source":"ghcmod","message":"parse error on input ‘,’"}]}}
2018-04-27 14:36:58.573423 [ThreadId 7] - ghcDispatcher: top of loop
2018-04-27 14:36:58.573527 [ThreadId 7] - got request with id: Nothing
2018-04-27 14:36:58.573967 [ThreadId 7] - ghcDispatcher: top of loop
2018-04-27 14:36:58.574173 [ThreadId 7] - got request with id: Nothing
2018-04-27 14:36:58.574251 [ThreadId 7] - Processing request as version matches
2018-04-27 14:36:58.698242 [ThreadId 7] - ghcDispatcher: top of loop
2018-04-27 14:36:58.698399 [ThreadId 7] - got request with id: Nothing
2018-04-27 14:36:58.6985 [ThreadId 7] - Processing request as version matches
2018-04-27 14:36:58.703254 [ThreadId 5] - <--2--{"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file://[REDACTED].hs","diagnostics":[{"severity":1,"range":{"start":{"line":59,"character":11},"end":{"line":59,"character":12}},"source":"ghcmod","message":"parse error on input ‘,’"},{"severity":3,"range":{"start":{"line":59,"character":11},"end":{"line":59,"character":100000}},"code":"parser","source":"hlint","message":"Parse error: ,\n  type CheckoutEffs effs ==\n     ( LoggerEff effssssffffffeee   ffffffEEErrreeeggggggoooLLL      \n>       ,    ,,,   ember RestaurantL effs\n     , Member AccountL effs\n     , Member MenuL effs\n\n"}]}}
2018-04-27 14:36:58.703698 [ThreadId 4] - ---> {"jsonrpc":"2.0","id":143,"method":"textDocument/codeAction","params":{"textDocument":{"uri":"file://[REDACTED].hs"},"range":{"start":{"line":27,"character":73},"end":{"line":27,"character":73}},"context":{"diagnostics":[]}}}
2018-04-27 14:36:58.7043 [ThreadId 8] - reactor:got CodeActionRequest:RequestMessage {_jsonrpc = "2.0", _id = IdInt 143, _method = TextDocumentCodeAction, _params = CodeActionParams {_textDocument = TextDocumentIdentifier {_uri = Uri {getUri = "file://[REDACTED].hs"}}, _range = Range {_start = Position {_line = 27, _character = 73}, _end = Position {_line = 27, _character = 73}}, _context = CodeActionContext {_diagnostics = List []}}}
2018-04-27 14:36:58.704609 [ThreadId 5] - <--2--{"result":[],"jsonrpc":"2.0","id":143}
2018-04-27 14:36:58.837856 [ThreadId 4] - ---> {"jsonrpc":"2.0","id":144,"method":"textDocument/codeAction","params":{"textDocument":{"uri":"file://[REDACTED].hs"},"range":{"start":{"line":27,"character":73},"end":{"line":27,"character":73}},"context":{"diagnostics":[]}}}
2018-04-27 14:36:58.83814 [ThreadId 8] - reactor:got CodeActionRequest:RequestMessage {_jsonrpc = "2.0", _id = IdInt 144, _method = TextDocumentCodeAction, _params = CodeActionParams {_textDocument = TextDocumentIdentifier {_uri = Uri {getUri = "file://[REDACTED].hs"}}, _range = Range {_start = Position {_line = 27, _character = 73}, _end = Position {_line = 27, _character = 73}}, _context = CodeActionContext {_diagnostics = List []}}}
2018-04-27 14:36:58.838558 [ThreadId 5] - <--2--{"result":[],"jsonrpc":"2.0","id":144}
2018-04-27 14:37:02.120167 [ThreadId 7] - setTypecheckedModule: Didn't get typechecked module for: "[REDACTED].hs"
2018-04-27 14:37:02.120338 [ThreadId 7] - ghcDispatcher: top of loop
2018-04-27 14:37:02.120601 [ThreadId 5] - <--2--{"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file://[REDACTED].hs","diagnostics":[{"severity":1,"range":{"start":{"line":59,"character":11},"end":{"line":59,"character":12}},"source":"ghcmod","message":"parse error on input ‘,’"}]}}
2018-04-27 14:37:02.252693 [ThreadId 4] - ---> {"jsonrpc":"2.0","id":145,"method":"textDocument/codeAction","params":{"textDocument":{"uri":"file://[REDACTED].hs"},"range":{"start":{"line":27,"character":73},"end":{"line":27,"character":73}},"context":{"diagnostics":[]}}}
2018-04-27 14:37:02.252957 [ThreadId 8] - reactor:got CodeActionRequest:RequestMessage {_jsonrpc = "2.0", _id = IdInt 145, _method = TextDocumentCodeAction, _params = CodeActionParams {_textDocument = TextDocumentIdentifier {_uri = Uri {getUri = "file://[REDACTED].hs"}}, _range = Range {_start = Position {_line = 27, _character = 73}, _end = Position {_line = 27, _character = 73}}, _context = CodeActionContext {_diagnostics = List []}}}
2018-04-27 14:37:02.253226 [ThreadId 5] - <--2--{"result":[],"jsonrpc":"2.0","id":145}

[alanz]

Yes, I noticed this myself recently, using vscode too. I think something has changed in the latest/current library in terms of managing changes.

[alanz]

And the log does not show the problem itself, which will be in prior DidChange message.

But I think I have a usable log locally too.

[alanz]

And this is a fragment of log from my incident observed in the wild

2018-04-20 10:35:44.606412 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}
2018-04-20 10:35:44.606831 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}
2018-04-20 10:35:44.607123 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}
2018-04-20 10:35:44.6073 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}
2018-04-20 10:35:44.6075 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}
2018-04-20 10:35:44.607674 [ThreadId 4] - ---> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"[Redacted]","version":13},"contentChanges":[{"range":{"start":{"line":13,"character":25},"end":{"line":13,"character":25}},"rangeLength":0,"text":"x"}]}}

The user is typing the x of the word Text, and it is coming through multiple times.

And I suspect that either the machine is heavily loaded. and gnome is sending repeat chars (which is something I have seen recently on my machine), or there is a bug in vscode.

@kfigiela, what operating system/distribution did you see this on?

[alanz]

And I just realised that the input in vscode is not garbled, so it is not extra UI events being injected by gnome etc.

[lukel97]

Could the duplicate didChange events be related to #531?

[kfigiela]

@alanz I am using macOS (10.13.4).

[alanz]

I think this problem has gone away? Can I close it?

[kfigiela]

Yup, haven't seen this for a long while. Will reopen if issue appears again. Thanks!