Editor crashes unexpectedly

[bunyk]

Please complete the following information:

• Operating System or distro: Ubuntu 20.04.3 LTS
• neoray version: 0.0.9 I would guess. :)

Steps to reproduce Not yet sure exactly, sorry. Maybe logs would help.

Two times this happened when I was trying to open new file in another tab (:tabe ...), but I tried it again, it did not happened, so there should be something else in play here.

Your neoray config in init.vim

call plug#begin('~/.vim/plugged')

Plug 'neoclide/coc.nvim', {'branch': 'release'}
Plug 'overcache/NeoSolarized'
Plug 'tpope/vim-fugitive'

Plug 'fatih/vim-go'

" Initialize plugin system
call plug#end()

set clipboard=unnamedplus
set number " show numbers of lines
set laststatus=2 " always display status line
set colorcolumn=80

set guifont=Ubuntu\ Mono:h9
colorscheme NeoSolarized

let neoray_key_toggle_fullscreen='<F11>'
let neoray_cursor_animation_time=0.03

" coc.nvim settings
" -------------------------------------------------------------------------------------------------

let g:coc_node_path = '/home/tbunyk/.nvm/versions/node/v16.8.0/bin/node'

" if hidden is not set, TextEdit might fail.
set hidden
" Better display for messages
set cmdheight=2
" Smaller updatetime for CursorHold & CursorHoldI
set updatetime=300
" don't give |ins-completion-menu| messages.
set shortmess+=c
" always show signcolumns
set signcolumn=yes

" Use tab for trigger completion with characters ahead and navigate.
" Use command ':verbose imap <tab>' to make sure tab is not mapped by other plugin.
inoremap <silent><expr> <TAB>
      \ pumvisible() ? "\<C-n>" :
      \ <SID>check_back_space() ? "\<TAB>" :
      \ coc#refresh()
inoremap <expr><S-TAB> pumvisible() ? "\<C-p>" : "\<C-h>"

function! s:check_back_space() abort
  let col = col('.') - 1
  return !col || getline('.')[col - 1]  =~# '\s'
endfunction

" Use <c-space> to trigger completion.
inoremap <silent><expr> <c-space> coc#refresh()

" Use `[c` and `]c` to navigate diagnostics
nmap <silent> [c <Plug>(coc-diagnostic-prev)
nmap <silent> ]c <Plug>(coc-diagnostic-next)

" Remap keys for gotos
nmap <silent> gd <Plug>(coc-definition)
nmap <silent> gy <Plug>(coc-type-definition)
nmap <silent> gi <Plug>(coc-implementation)
nmap <silent> gr <Plug>(coc-references)

" Use U to show documentation in preview window
nnoremap <silent> U :call <SID>show_documentation()<CR>

" Remap for rename current word
nmap <leader>rn <Plug>(coc-rename)

" Remap for format selected region
vmap <leader>f  <Plug>(coc-format-selected)
nmap <leader>f  <Plug>(coc-format-selected)
" Show all diagnostics
nnoremap <silent> <space>a  :<C-u>CocList diagnostics<cr>
" Manage extensions
nnoremap <silent> <space>e  :<C-u>CocList extensions<cr>
" Show commands
nnoremap <silent> <space>c  :<C-u>CocList commands<cr>
" Find symbol of current document
nnoremap <silent> <space>o  :<C-u>CocList outline<cr>
" Search workspace symbols
nnoremap <silent> <space>s  :<C-u>CocList -I symbols<cr>
" Do default action for next item.
nnoremap <silent> <space>j  :<C-u>CocNext<CR>
" Do default action for previous item.
nnoremap <silent> <space>k  :<C-u>CocPrev<CR>
" Resume latest coc list
nnoremap <silent> <space>p  :<C-u>CocListResume<CR>

" disable vim-go :GoDef short cut (gd)
" this is handled by LanguageClient [LC]
let g:go_def_mapping_enabled = 0

" Other useful stuff
" ---------------------------------------------------
let g:go_auto_type_info = 1

" Quickfix list navigation
noremap <A-j> :CocNext<Return>
noremap <A-k> :CocPrev<Return>

Crash log if available (may be generated by neoray after crash)

tbunyk@ZALANDO-33620:~/projects/neoray$ bin/neoray_debug 
[DEBUG] [NVIM] Neovim started with command: nvim --embed
[TRACE] [NVIM] Neovim version 0.5.0
[DEBUG] [NVIM] Attached to neovim as an ui client.
[TRACE] [NEORAY] Glfw version: 3.3.4 X11 GLX EGL OSMesa clock_gettime evdev
[DEBUG] [NEORAY] Video mode {Width:1920 Height:1080 RedBits:8 GreenBits:8 BlueBits:8 RefreshRate:60}
[DEBUG] [NEORAY] Creating window, width: 1152 height: 810
[DEBUG] [NEORAY] Glfw window created successfully.
[DEBUG] [NEORAY] Monitor diagonal: 13.94 dpi: 158.00
[DEBUG] [NEORAY] Input callbacks are initialized.
[DEBUG] [RENDERER] Initializing opengl.
[TRACE] [RENDERER] Opengl Version: 4.6 (Core Profile) Mesa 21.0.3
[DEBUG] [RENDERER] Vendor: Intel
[DEBUG] [RENDERER] Renderer: Mesa Intel(R) UHD Graphics 620 (KBL GT2)
[DEBUG] [RENDERER] GLSL: 4.60
[DEBUG] [NEORAY] Loading default font.
[DEBUG] [NVIM] Deprecated option neoray_cursor_animation_time is 0.03
[DEBUG] [NEORAY] Window is now visible.
[TRACE] [PERFORMANCE] Start time: 254.010736ms
[DEBUG] [NEORAY] Loading font Ubuntu Mono with size 9
[TRACE] [NEORAY] Regular: UbuntuMono-R.ttf
[TRACE] [NEORAY] Bold Italic: UbuntuMono-BI.ttf
[TRACE] [NEORAY] Italic: UbuntuMono-RI.ttf
[TRACE] [NEORAY] Bold: UbuntuMono-B.ttf
[TRACE] [NVIM] Neovim child process closed.
[WARNING] [NVIM] Failed to close neovim child process: signal: killed
[DEBUG] [NEORAY] Window destroyed.
[DEBUG] [NEORAY] Glfw terminated.
[DEBUG] [PERFORMANCE] CreateWindow                           Calls: 1   Time: 146.886609ms
[DEBUG] [PERFORMANCE] (*NvimProcess).requestApiInfo          Calls: 1   Time: 63.208417ms
[DEBUG] [PERFORMANCE] RefreshCallback                        Calls: 8   Time: 88.278312ms  Avg:11.034789ms  Max:25.730734ms
[DEBUG] [PERFORMANCE] CreateRenderer                         Calls: 1   Time: 9.266358ms
[DEBUG] [PERFORMANCE] (*Editor).initGlfw                     Calls: 1   Time: 7.5846ms
[DEBUG] [PERFORMANCE] CreateFont                             Calls: 1   Time: 7.190245ms
[DEBUG] [PERFORMANCE] rglInit                                Calls: 1   Time: 6.125807ms
[DEBUG] [PERFORMANCE] (*Renderer).createVertexData           Calls: 6   Time: 26.370344ms  Avg:4.395057ms   Max:7.209585ms
[DEBUG] [PERFORMANCE] (*Renderer).drawCells                  Calls: 100 Time: 363.038214ms Avg:3.630382ms   Max:37.75459ms
[DEBUG] [PERFORMANCE] (*Renderer).clearAtlas                 Calls: 1   Time: 2.263473ms
[DEBUG] [PERFORMANCE] CreateDefaultFont                      Calls: 1   Time: 1.943344ms
[DEBUG] [PERFORMANCE] (*NvimProcess).requestStartupVariables Calls: 1   Time: 1.102399ms
[DEBUG] [PERFORMANCE] CreateNvimProcess                      Calls: 1   Time: 861.517µs
[DEBUG] [PERFORMANCE] charCallback                           Calls: 49  Time: 25.12114ms   Avg:512.676µs    Max:1.001744ms
[DEBUG] [PERFORMANCE] keyCallback                            Calls: 141 Time: 13.798203ms  Avg:97.859µs     Max:780.863µs
[FATAL] [NEORAY] [PANIC!] runtime error: invalid memory address or nil pointer dereference
fatal error: unexpected signal during runtime execution
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x7ff4719dbfc4]

runtime stack:
runtime.throw({0x9af751, 0x73})
    /usr/local/go/src/runtime/panic.go:1198 +0x71
runtime.sigpanic()
    /usr/local/go/src/runtime/signal_unix.go:719 +0x396

goroutine 1 [syscall, locked to thread]:
runtime.cgocall(0x888300, 0xc0005b74d0)
    /usr/local/go/src/runtime/cgocall.go:156 +0x6e fp=0xc0005b74a8 sp=0xc0005b7470 pc=0x4396ce
github.com/sqweek/dialog._Cfunc_gtk_dialog_run(0x3c08330)
    _cgo_gotypes.go:236 +0x85 fp=0xc0005b74d0 sp=0xc0005b74a8 pc=0x541265
github.com/sqweek/dialog.runMsgDlg.func4(0x3a0f960)
    /home/tbunyk/go/pkg/mod/github.com/sqweek/dialog@v0.0.0-20210702151303-c326b49d3f01/dlgs_linux.go:39 +0x65 fp=0xc0005b7510 sp=0xc0005b74d0 pc=0x542705
github.com/sqweek/dialog.runMsgDlg({0x9694c3, 0x5}, 0x0, 0x0, 0x0, 0xc0005b7740)
    /home/tbunyk/go/pkg/mod/github.com/sqweek/dialog@v0.0.0-20210702151303-c326b49d3f01/dlgs_linux.go:39 +0x22c fp=0xc0005b7698 sp=0xc0005b7510 pc=0x5425ac
github.com/sqweek/dialog.(*MsgBuilder).error(...)
    /home/tbunyk/go/pkg/mod/github.com/sqweek/dialog@v0.0.0-20210702151303-c326b49d3f01/dlgs_linux.go:51
github.com/sqweek/dialog.(*MsgBuilder).Error(...)
    /home/tbunyk/go/pkg/mod/github.com/sqweek/dialog@v0.0.0-20210702151303-c326b49d3f01/dlgs.go:61
main.logMessage(0x4, 0x1, {0xc0005b7790, 0x2, 0x2})
    /home/tbunyk/projects/neoray/src/logger.go:170 +0x312 fp=0xc0005b7770 sp=0xc0005b7698 pc=0x860472
main.shutdownLogger()
    /home/tbunyk/projects/neoray/src/logger.go:77 +0x7f fp=0xc0005b77c0 sp=0xc0005b7770 pc=0x85faff
panic({0x914c60, 0xc526d0})
    /usr/local/go/src/runtime/panic.go:1047 +0x266 fp=0xc0005b7880 sp=0xc0005b77c0 pc=0x46bd46
runtime.panicmem(...)
    /usr/local/go/src/runtime/panic.go:221
runtime.sigpanic()
    /usr/local/go/src/runtime/signal_unix.go:735 +0x327 fp=0xc0005b78d0 sp=0xc0005b7880 pc=0x483e47
main.(*GridManager).hide(...)
    /home/tbunyk/projects/neoray/src/grid.go:201
main.win_hide({0xc000377240, 0x2, 0x2})
    /home/tbunyk/projects/neoray/src/redrawevents.go:390 +0x212 fp=0xc0005b7960 sp=0xc0005b78d0 pc=0x875bd2
main.handleRedrawEvents()
    /home/tbunyk/projects/neoray/src/redrawevents.go:76 +0x553e fp=0xc0005b7ab0 sp=0xc0005b7960 pc=0x86e49e
main.(*Editor).update(0xf83c80)
    /home/tbunyk/projects/neoray/src/editor.go:171 +0x2c fp=0xc0005b7ad0 sp=0xc0005b7ab0 pc=0x85838c
main.(*Editor).MainLoop(0xf83c80)
    /home/tbunyk/projects/neoray/src/editor.go:154 +0x617 fp=0xc0005b7cb8 sp=0xc0005b7ad0 pc=0x857f97
main.main()
    /home/tbunyk/projects/neoray/src/main.go:69 +0x411 fp=0xc0005b7f80 sp=0xc0005b7cb8 pc=0x860b71
runtime.main()
    /usr/local/go/src/runtime/proc.go:255 +0x227 fp=0xc0005b7fe0 sp=0xc0005b7f80 pc=0x46e9c7
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1581 +0x1 fp=0xc0005b7fe8 sp=0xc0005b7fe0 pc=0x4a0921

goroutine 20 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff470104ca0, 0x72)
    /usr/local/go/src/runtime/netpoll.go:229 +0x89
internal/poll.(*pollDesc).wait(0xc00039e198, 0x79b401, 0x0)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0xbd
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc00039e180)
    /usr/local/go/src/internal/poll/fd_unix.go:402 +0x425
net.(*netFD).accept(0xc00039e180)
    /usr/local/go/src/net/fd_unix.go:173 +0x4a
net.(*TCPListener).accept(0xc0003a6030)
    /usr/local/go/src/net/tcpsock_posix.go:140 +0x45
net.(*TCPListener).Accept(0xc0003a6030)
    /usr/local/go/src/net/tcpsock.go:262 +0x68
net/http.(*Server).Serve(0xc000380000, {0xa35290, 0xc0003a6030})
    /usr/local/go/src/net/http/server.go:3001 +0x5cf
net/http.(*Server).ListenAndServe(0xc000380000)
    /usr/local/go/src/net/http/server.go:2930 +0xbd
net/http.ListenAndServe(...)
    /usr/local/go/src/net/http/server.go:3184
main.start_pprof.func1()
    /home/tbunyk/projects/neoray/src/utils_debug.go:27 +0xfe
created by main.start_pprof
    /home/tbunyk/projects/neoray/src/utils_debug.go:26 +0x2c

goroutine 7 [chan send]:
main.(*NvimProcess).startUI.func2()
    /home/tbunyk/projects/neoray/src/nvimproc.go:245 +0x145
created by main.(*NvimProcess).startUI
    /home/tbunyk/projects/neoray/src/nvimproc.go:239 +0x4d4

[hismailbulut]

Hello @bunyk and thanks for the information. This is really unexpected because the hide function of the grids must only be called when multigrid enabled. And neoray doesn't call this function itself. This is most probably neovim issue. But I will look an try to reproduce when I find time.

[bunyk]

This morning it happened after I tried to switch the tab with gt in normal mode. The only difference I noticed was this part of the logs:

...
[TRACE] [NEORAY] Bold: UbuntuMono-B.ttf
[TRACE] [NVIM] Neovim child process closed.
[DEBUG] [NEORAY] Window destroyed.
[DEBUG] [NEORAY] Glfw terminated.
[DEBUG] [PERFORMANCE] CreateWindow                           Calls: 1    Time: 134.902162ms
...

Previously it had also [WARNING] [NVIM] Failed to close neovim child process: signal: killed

So maybe it indeed is some nvim bug that causes it exits unexpectedly. I tried to reproduce by killing nvim process while neoray is running, but it exited normally without any panics.

Stupid question from someone who does not know yet what is grid or multigrid. Are we allowed to call main.win_hide, after we logged [DEBUG] [NEORAY] Window destroyed.? I would assume that after such a log message there is nothing more to hide. :) Maybe it's some concurrency bug here?

[bunyk]

By the way, is there any way to see logs of nvim process? Maybe they should point to what is wrong with nvim, if there is bug there.

I maybe will try to work in console nvim today, and see if the same happens.

[hismailbulut]

Are we allowed to call main.win_hide, after we logged [DEBUG] [NEORAY] Window destroyed.

No you can't. And neoay doesn't call before or after it. The window destroy function is deferred and always be called whether program panics or exits successfully. The actual panic is happening before the 'Neovim child process closed' log.

By the way, is there any way to see logs of nvim process?

Yes, you can. Start neoray with -V[N][filename] option. This will passed to neovim and neovim starts to log the filename. Example: neoray --verbose -V9nvim.log This creates both neoray and neovims debug output in two different files.

I maybe will try to work in console nvim today, and see if the same happens.

This may not happen in console because actual issue is about External UI. Neovim needs an ui rpc connection to call hide().

I couldn't reproduce with Windows 10. Maybe this is a linux only issue of the neovim. But we need more information to say 'this is a neovim issue'.

[bunyk]

So, I was running ./bin/neoray_debug --verbose -V9nvim.log, and it crashed when I tried to do :tabe ~/.config/nvim/init.vim, while being in the tab with some go code. This is the end of nvim.log:

Executing BufReadPost Autocommands for "*"
autocommand call s:Autocmd('BufCreate', +expand('<abuf>'))

Executing BufReadPost Autocommands for "*"
autocommand call FugitiveDetect(expand('<amatch>:p'))

Executing BufEnter Autocommands for "*"
autocommand call s:Autocmd('BufEnter', +expand('<abuf>'))

Executing BufEnter Autocommands for "*"
autocommand sil call s:LocalBrowse(expand("<amatch>"))

Executing BufWinEnter Autocommands for "*"
autocommand call s:Autocmd('BufWinEnter', +expand('<abuf>'), win_getid())

Executing CursorMoved Autocommands for "*"
autocommand call coc#float#nvim_refresh_scrollbar(win_getid())

autocommand call s:Autocmd('CursorMoved', +expand('<abuf>'), [line('.'), col('.')])

Executing CursorMoved Autocommands for "*"
autocommand call s:Highlight_Matching_Pair()

Executing WinClosed Autocommands for "*"
autocommand call coc#float#close_related(+expand('<afile>'))

autocommand call s:Autocmd('WinClosed', +expand('<afile>'))

Executing BufWinLeave Autocommands for "*"
autocommand call s:Autocmd('BufWinLeave', +expand('<abuf>'), bufwinid(+expand('<abuf>')))

Executing BufHidden Autocommands for "*"
autocommand call s:Autocmd('BufHidden', +expand('<abuf>'))

Not sure what that means, I have not much experience in VimScript.

[hismailbulut]

Are there any error log in the log file? If not this may not be a neovim issue or there is a segfault in neovim which can not be printed. I can add a simple check to code and prevent neoray from crash, but this will not fix the issue, also even hide it. But I don't have any other choises. Thanks for all information.

[bunyk]

No, nothing that looks like error in log file.

I can add a simple check to code and prevent neoray from crash, but this will not fix the issue, also even hide it.

I added following check myself:

 func (gridManager *GridManager) hide(id int) {
        grid := gridManager.grids[id]
+       if grid == nil {
+               log.Fatalf("Called hide(%d) for nil grid. gridManager.grids: %#v", id, gridManager.grids)
+       }
        grid.hidden = true

And after working for some time got:

2021/09/02 23:44:21 Called hide(286) for nil grid. gridManager.grids: map[int]*main.Grid{1:(*main.Grid)(0xc0000692c0)}

So, something tries to hide grid with id that does not exist. While there is one grid in grids. I could add more checks and logs, but not yet know where to look.

[bunyk]

I believe I know the reproduction steps now. It happens when there is some hint displayed, like linter error. For example something like this, coming either from 'neoclide/coc.nvim', or 'fatih/vim-go':

If I see such popup, and then switch to or open another tab - this crash happens. Because it calls hide with some id > 1, while in grids map there is only id == 1.

[hismailbulut]

Maybe you should open an issue on neovim. The neovim itself must not sent this event even when called from a plugin without multigrid is on. This is not a plugin's responsibility.

[bunyk]

Opened issue here: https://github.com/neovim/neovim/issues/15589

Current patch fixes crashes, errors are logged. And it's possible to avoid errors by starting with --multigrid.

[hismailbulut]

What I understand from the issue, neoray always needs to check multigrid events. I will add checks for both is multigrid enabled and is grid id valid for every multigrid event soon.

[bunyk]

I'm not sure if https://github.com/neovim/neovim/issues/15589 is still a bug. Should I maybe close it if there are no expected actions from nvim devs?

[hismailbulut]

Dont close it, sometimes other devs are working on such issues. For now we will hardcode the issue.