Highlighting sometimes disappears

[liquidev]

Sometimes, when editing, the dynamic syntax highlighting stops working for a block of code. When this happens, the code only has some barebones highlighting for keywords and literals, and most of it remains gray.

Sometimes, the highlighting disappears in the middle of a procedure and not just a block:

[alaviss]

So either we have a race condition in the plugin or nimsuggest just went dumb for a moment. This is gonna be hell to debug. I'm more convinced that it's the latter.

Can you try to make a reproducible case? (ie. a file in a project experience this problem after a defined editing sequence)

[liquidev]

@alaviss This is happening to me constantly while I'm writing euwren, but it's seemingly random, so making a reproducible case will be difficult.

This is the file where this occurs: https://github.com/liquid600pgm/euwren/blob/master/src/euwren.nim
The bug usually happens when there's a syntax error in my file for a while (>1 second), the highlighting usually disappears and comes back when I fix the error, but sometimes it doesn't.

[alaviss]

This plugin utilize nimsuggest to do the highlighting, so if your code is not accepted by the parser, nimsuggest might trip. Sometimes you can even crash nimsuggest. I guess this is even more likely as you're working with macros.

Can you check if nimsuggest died during one of the "no highlighting" session? The plugin reports every terminations and you can see them with :messages.

[liquidev]

@alaviss nimsuggest does seem to throw errors sometimes and they appear on the status bar, but the highlighting doesn't disappear. nimsuggest continues functioning.

The message that appears very often is

suggest-sug: error: unknown symbol kind 'skParam'

but it doesn't crash nimsuggest or stop the highlighting.

I only see the error described in #16 when I exit nvim, but only that. Other than that, nimsuggest does not seem to crash when this occurs (or the plugin doesn't report it correctly).

I have to admit though, there were a few times nimsuggest crashed completely and all the highlighting disappeared, but restarting nvim helped.

[liquidev]

The problem seems to occur reliably on this exact commit and these exact lines.

[liquidev]

I think I found the culprit.
It seems like error() calls is what causes the highlighting to disappear, see video.

[alaviss]

The message that appears very often is

suggest-sug: error: unknown symbol kind 'skParam'

but it doesn't crash nimsuggest or stop the highlighting.

That message means that some suggestions wouldn't be classified correctly, but it does no harm. Fixed though, thanks for letting me know.

I have to admit though, there were a few times nimsuggest crashed completely and all the highlighting disappeared, but restarting nvim helped.

That's odd, the plugin should restarts nimsuggest and make everything work again (on the next input, file saving, etc.). I'll have to investigate that one.

It seems like error() calls is what causes the highlighting to disappear, see video.

How can I reproduce this? It seems like this is a nimsuggest bug though.

[liquidev]

@alaviss I'm unsure how to reproduce this, it happened once but I'm unable to reproduce either. It seems like nimsuggest doesn't really like macros in general.

[sschwarzer]

I also (presumably) had crashes of nimsuggest. After that there was only basic syntax highlighting. Restarting nvim helped. There were no macros defined in the opened files.

These problems happen rarely for me. I didn't notice any pattern, but I'll try to remember/reproduce it the next time it happens. (However, with my (neo)vim usage it's likely that I already pressed more keys by the time I notice the problem.)

Apart from that, I really like the plugin. Thank you! :-)

[alaviss]

I also (presumably) had crashes of nimsuggest. After that there was only basic syntax highlighting. Restarting nvim helped. There were no macros defined in the opened files.

@sschwarzer @liquid600pgm
When something like this happen, can you record the outputs of the following for me?

:echo b:nimSugHighlight
:echo nim#suggest#FindInstance()

It'd help me a lot in debugging, thanks :)

[sschwarzer]

@sschwarzer @liquid600pgm
When something like this happen, can you record the outputs of the following for me?

:echo b:nimSugHighlight
:echo nim#suggest#FindInstance()

I'll try to remember. :-)

[liquidev]

:echo b:nimSugHighlight when a section stops being highlighted:

:echo nim#suggest#FindInstance()

I'd paste that in text form, but I'm not sure how I'd do that with set mouse=a.

[liquidev]

Found a weird instance of an untyped macro param's body being highlighted:

The file is not highlighted at all after this point, which suggests that it is in fact a nimsuggest bug.

Altering the file brings the highlighting back, this is only present right after the file is opened. Here's the file I was testing on.

[alaviss]

Reproduced. And this is definitely a nimsuggest bug. Here's how to instantly crash nimsuggest:

❯ nimsuggest src/euwren.nim
Hint: used config file '/etc/nim/nim.cfg' [Conf]
usage: sug|con|def|use|dus|chk|mod|highlight|outline|known|project file.nim[;dirtyfile.nim]:line:col
type 'quit' to quit
type 'debug' to toggle debug mode on/off
type 'terse' to toggle terse mode on/off
> highlight tests/teuwren.nim
fatal.nim(39)            sysFatal
Error: unhandled exception: 'intVal' is not accessible using discriminant 'kind' of type 'TFullReg' [FieldError]

This will be a PITA to debug :(

[sschwarzer]

@sschwarzer @liquid600pgm
When something like this happen, can you record the outputs of the following for me?

:echo b:nimSugHighlight
:echo nim#suggest#FindInstance()

It'd help me a lot in debugging, thanks :)

Ok, it happened. ;-) Here's the output of the two commands:

:echo b:nimSugHighlight
{'highlight': function('302'), 'locked': v:false, 'queued': v:false, 'ids': [1, 2], 'on_data': function('301'), 'buffer': 10, 'updated': v:true}

:echo nim#suggest#FindInstance()
{'addCallback': function('294'), 'job': 4424, 'start': function('291'), 'file': '/home/schwa/sd/nim/todoreport/tests/testparser.nim', 'stop': function('292'), 'cmd': 'nimsuggest', 'oneshots': [], 'on_exit': function('22943', {'bufCb': function('22943')}), 'on_stdo
ut': function('22941', {'bufCb': function('22941')}), 'isReady': function('290'), 'project': function('295'), 'isRunning': function('289'), 'cb': function('<SNR>76_onEvent'), 'query': function('297'), 'port': 53431, 'message': function('293'), 'contains': function
('296'), 'on_stderr': function('22942', {'bufCb': function('22942')}), 'args': ['--autobind', '--address:localhost']}

The latest commit of my clone is [83b5fd5].

[alaviss]

When something like this happen, can you record the outputs of the following for me?

:echo b:nimSugHighlight
:echo nim#suggest#FindInstance()

It'd help me a lot in debugging, thanks :)

Ok, it happened. ;-) Here's the output of the two commands:

:echo b:nimSugHighlight
{'highlight': function('302'), 'locked': v:false, 'queued': v:false, 'ids': [1, 2], 'on_data': function('301'), 'buffer': 10, 'updated': v:true}

:echo nim#suggest#FindInstance()
{'addCallback': function('294'), 'job': 4424, 'start': function('291'), 'file': '/home/schwa/sd/nim/todoreport/tests/testparser.nim', 'stop': function('292'), 'cmd': 'nimsuggest', 'oneshots': [], 'on_exit': function('22943', {'bufCb': function('22943')}), 'on_stdo
ut': function('22941', {'bufCb': function('22941')}), 'isReady': function('290'), 'project': function('295'), 'isRunning': function('289'), 'cb': function('<SNR>76_onEvent'), 'query': function('297'), 'port': 53431, 'message': function('293'), 'contains': function
('296'), 'on_stderr': function('22942', {'bufCb': function('22942')}), 'args': ['--autobind', '--address:localhost']}

The latest commit of my clone is 83b5fd5.

AFAICT, not a bug in nim.nvim (whew). I guess nimsuggest has some problems when being run for too long. You can try restarting nimsuggest by stopping it :call nim#suggest#ProjectStop(), then do any random editing and it should respawn. If highlighting don't return after that however, then I'll have to look deeper into nim.nvim.

[sschwarzer]

You can try restarting nimsuggest by stopping it :call nim#suggest#ProjectStop(), then do any random editing and it should respawn.

This actually worked, thank you! :-)

Could you possibly detect the failed nimsuggest and respawn it automatically?

[alaviss]

Could you possibly detect the failed nimsuggest and respawn it automatically?

That's really hard actually :(

The best way I could think of to debug this is to enable logging in nimsuggest, then use that information to pin point why it fails...

If you wanna help debugging this, add '--log' to the 'extraArgs' key in autoload/nim/suggest.vim. There should be a nimsuggest.log file in your home directory the next time nimsuggest is spawned, and should the same problem arise, please provide me with the log.

[sschwarzer]

That's really hard actually :(

That's what I suspected. :-/

The best way I could think of to debug this is to enable logging in nimsuggest, then use that information to pin point why it fails...

If you wanna help debugging this, add '--log' to the 'extraArgs' key in autoload/nim/suggest.vim. There should be a nimsuggest.log file in your home directory the next time nimsuggest is spawned, and should the same problem arise, please provide me with the log.

Ok, I activated the logging and made sure the log is written to after restarting nvim.

[alaviss]

Can you also add the '--debug' argument in? It's necessary to get detailed answer-response data from nimsuggest.

[sschwarzer]

Can you also add the '--debug' argument in? It's necessary to get detailed answer-response data from nimsuggest.

Done :-)

[sschwarzer]

I had some missing syntax highlighting today. However, nimsuggest still seems to be running and generates new output in the log file. Here's the data I could gather:

:echo b:nimSugHighlight
{'highlight': function('286'), 'locked': v:false, 'queued': v:false, 'ids': [2, 1], 'on_data': function('285'), 'buffer': 4, 'updated': v:true}

:echo nim#suggest#FindInstance()
{'addCallback': function('278'), 'job': 5, 'start': function('275'), 'file': '/home/schwa/sd/nim/todoreport/src/todoreport.nim', 'stop': function('276'), 'cmd': 'nimsuggest', 'oneshots': [], 'on_exit': function('284', {'bufCb': function('284')}), 'on_stdout': func
tion('282', {'bufCb': function('282')}), 'isReady': function('274'), 'project': function('279'), 'isRunning': function('273'), 'cb': function('<SNR>78_onEvent'), 'query': function('281'), 'port': 56573, 'message': function('277'), 'contains': function('280'), 'on_
stderr': function('283', {'bufCb': function('283')}), 'args': ['--autobind', '--address:localhost', '--log', '--debug']}

Here's the section from the log when I save the buffer (paths partially replaced):

cmd: highlight, file: src/todoreport.nim, dirtyFile: [0:-1]
Hint: todoreport [Processing]
.../nim/todoreport/src/todoreport.nim(74, 38) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(82, 7) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(104, 28) template/generic instantiation of `reversed` from here
.../.choosenim/toolchains/nim-1.0.4/lib/pure/algorithm.nim(166, 11) template/generic instantiation of `reversed` from here
.../.choosenim/toolchains/nim-1.0.4/lib/pure/algorithm.nim(146, 10) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(127, 9) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(228, 24) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(274, 11) Error: template instantiation too nested
.../nim/todoreport/src/todoreport.nim(31, 3) Hint: 'validGroupFields' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(71, 6) Hint: 'fieldsFromKeysString' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(115, 6) Hint: 'groupsFromTasks' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(217, 10) Hint: 'quitWithError' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(109, 6) Hint: 'addTask' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(90, 6) Hint: 'startsWith' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(76, 6) Hint: 'fieldsAreValid' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(97, 6) Hint: 'sortedTasks' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(12, 18) Warning: imported and not used: 'parser' [UnusedImport]
.../nim/todoreport/src/todoreport.nim(2, 8) Warning: imported and not used: 'os' [UnusedImport]
.../nim/todoreport/src/todoreport.nim(4, 8) Warning: imported and not used: 'sets' [UnusedImport]

I'll also attach the Nim files. The highlighting is reduced in the editor starting in line 80 (fieldsSet = ().

todoreport.zip

[sschwarzer]

After stopping nimsuggest from inside the editor, the nimsuggest log output upon saving becomes:

cmd: highlight, file: src/todoreport.nim, dirtyFile: [0:-1]
Hint: todoreport [Processing]
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: 'keys'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: '.'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: type mismatch
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: 'keys'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: '.'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: type mismatch
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: 'keys'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: attempting to call undeclared routine: '.'
.../nim/todoreport/src/todoreport.nim(213, 40) Error: type mismatch
.../nim/todoreport/src/todoreport.nim(241, 22) Hint: 'error' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(249, 22) Hint: 'error' is declared but not used [XDeclaredButNotUsed]
.../nim/todoreport/src/todoreport.nim(260, 40) template/generic instantiation of `toSeq` from here
.../.choosenim/toolchains/nim-1.0.4/lib/pure/collections/sequtils.nim(670, 23) Error: type mismatch

The message Error: template instantiation too nested doesn't appear anymore, but there's a message about undeclared routines. However, the program runs fine.

[timotheecour]

please check if nim-lang/Nim#17590 helps with this issue, given this comment:

I also suspect that it's linked to the nimsuggest crashed mentioned by @alaviss here #18 (comment)

(it could very well be an unrelated issue though)