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.

Sign up for GitHub

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

Jump to bottom

NullPointerException occurs after another plugin fails #50

Closed
daveyarwood opened this issue Jul 17, 2019 · 9 comments
Closed

NullPointerException occurs after another plugin fails #50

daveyarwood opened this issue Jul 17, 2019 · 9 comments
Assignees
@Olical
Labels
bug Something isn't working
Milestone
v1.0.0

Comments

@daveyarwood
Copy link
Sponsor Contributor

Error

I ran into what looks like an edge case related to a different plugin (vista.vim) failing. Here's the :messages output:

2019-07-17-123252_1719x292_scrot

Conjure is working fine in general, I just run into this problem when vista fails. Here's the timeline that reliably produces the error condition:

  1. I have a prepl already started for my project. (Conjure will connect to it successfully if I don't attempt to open the vista.vim sidebar like I do below.)
  2. I start a Vim session, editing a .clj file in my project.
  3. I run :Vista!! to open the vista.vim sidebar.
  4. Vista throws an error. (the first error in the screenshot above)
  5. Conjure then does its usual startup routine where it tries to connect to prepls according to my conjure.edn settings.
  6. Conjure throws an error. (the second error in the screenshot above, starting with Error from thread 'RPC message handler')

Logs

19-07-17 16:29:59 moondog INFO [conjure.main:40] - Logging initialised
19-07-17 16:29:59 moondog INFO [conjure.main:42] - System versions
=== Conjure ===
v0.22.0-0-g0cbb94a56f

=== OS ===
Linux moondog 4.15.0-54-generic #58~16.04.1-Ubuntu SMP Mon Jun 24 13:21:41 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

=== Neovim ===
NVIM v0.4.0-dev
Build type: RelWithDebInfo
LuaJIT 2.0.4
Compilation: /usr/bin/x86_64-linux-gnu-gcc -g -O2 -fstack-protector-strong -Wformat -Werror=format-security -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1 -O2 -g -DMIN_LOG_LEVEL=3 -Og -g -Wall -Wextra -pedantic -Wno-unused-parameter -Wstrict-prototypes -std=gnu99 -Wshadow -Wconversion -Wmissing-prototypes -Wvla -fstack-protector-strong -fdiagnostics-color=auto -Wno-array-bounds -DINCLUDE_GENERATED_DECLARATIONS -D_GNU_SOURCE -DNVIM_MSGPACK_HAS_FLOAT32 -DNVIM_UNIBI_HAS_VAR_FROM -I/build/neovim-Vk_ngi/neovim-0.4.0+ubuntu3+git201907152022-5193826-f1ec5d7/build/config -I/build/neovim-Vk_ngi/neovim-0.4.0+ubuntu3+git201907152022-5193826-f1ec5d7/src -I/build/neovim-Vk_ngi/neovim-0.4.0+ubuntu3+git201907152022-5193826-f1ec5d7/.deps/usr/include -I/usr/include -I/build/neovim-Vk_ngi/neovim-0.4.0+ubuntu3+git201907152022-5193826-f1ec5d7/build/src/nvim/auto -I/build/neovim-Vk_ngi/neovim-0.4.0+ubuntu3+git201907152022-5193826-f1ec5d7/build/include
Compiled by buildd@lgw01-amd64-005

Features: +acl +iconv +tui 
See ":help feature-compile"

   system vimrc file: "$VIM/sysinit.vim"
  fall-back for $VIM: "/usr/share/nvim"

Run :checkhealth for more info

=== Java ===
openjdk version "11.0.4-ea" 2019-07-16
OpenJDK Runtime Environment (build 11.0.4-ea+9-post-Ubuntu-1ubuntu116.04.1)
OpenJDK 64-Bit Server VM (build 11.0.4-ea+9-post-Ubuntu-1ubuntu116.04.1, mixed mode, sharing)

19-07-17 16:29:59 moondog INFO [conjure.rpc:149] - Starting RPC TCP server on port 35339
19-07-17 16:29:59 moondog INFO [conjure.rpc:167] - Starting RPC loops
19-07-17 16:29:59 moondog INFO [conjure.prepl:196] - Started prepl server on port 38857
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :notify, :method :up, :params [""], :client :stdio}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-set-var, :params ["conjure_ready" 1]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 2, :method :nvim-get-current-buf, :params nil}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error nil, :result nil, :client :stdio}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 2, :error nil, :result #msgpack.core.Ext{:type 0, :data #object["[B" 0x5b37e33f "[B@5b37e33f"]}, :client :stdio}
19-07-17 16:29:59 moondog INFO [conjure.main:47] - Everything's ready! Let's perform some magic.
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 3, :method :nvim-call-atomic, :params [(["nvim_buf_get_name" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x5b37e33f "[B@5b37e33f"]}]] ["nvim_buf_line_count" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x5b37e33f "[B@5b37e33f"]}]] ["nvim_buf_get_lines" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x5b37e33f "[B@5b37e33f"]} 0 25 false]] ["nvim_get_current_win" []])]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 3, :error nil, :result [["/home/dave/code/api-proxy/src/adzerk/api_proxy_dev.clj" 13 ["(ns adzerk.api-proxy-dev" "  \"DEVELOPMENT-ONLY entrypoint that wraps the application with a wrap-reload handler.\"" "  (:require [adzerk.api-proxy :as api-proxy]" "            [ring.middleware.reload :refer [wrap-reload]]" "            [clojure.java.io :as io]))" "" "(def src-dirs" "  (filter #(not (.endsWith % \".jar\"))" "          (.split (System/getProperty \"fake.class.path\") \":\")))" "" "(def app" "  (-> #'api-proxy/app" "      (wrap-reload {:dirs src-dirs})))"] #msgpack.core.Ext{:type 1, :data #object["[B" 0x4101a8c5 "[B@4101a8c5"]}] nil], :client :stdio}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-call-function, :params ["getcwd" (0)]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error nil, :result "/home/dave/code/api-proxy", :client :stdio}
19-07-17 16:29:59 moondog INFO [conjure.prepl:121] - Adding :cwd 127.0.0.1 34829
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-get-var, :params ["conjure_log_auto_open"]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error nil, :result ["ret-multiline" "out" "err" "tap" "doc" "test"], :client :stdio}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-execute-lua, :params ["return require('conjure').upsert_log(...)" ("/tmp/conjure.cljc" "small" false false true)]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error [0 "Error executing lua: /home/dave/.vim/bundle/conjure//lua/conjure.lua:87: Vim(if):E482: Can't open file /tmp/user/10007d12eecc0088a7ae6e413b2dd9867a4f3aabb0807309eacc4899826f7042e53a.clj for writing: permission denied"], :result nil, :client :stdio}
19-07-17 16:29:59 moondog ERROR [conjure.nvim.api:12] - Error while making nvim call {:method :nvim-execute-lua, :params ["return require('conjure').upsert_log(...)" ("/tmp/conjure.cljc" "small" false false true)]} -> {:error [0 "Error executing lua: /home/dave/.vim/bundle/conjure//lua/conjure.lua:87: Vim(if):E482: Can't open file /tmp/user/10007d12eecc0088a7ae6e413b2dd9867a4f3aabb0807309eacc4899826f7042e53a.clj for writing: permission denied"], :result nil}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-buf-line-count, :params [nil]}
19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error [0 "Wrong type for argument 1, expecting Buffer"], :result nil, :client :stdio}
19-07-17 16:29:59 moondog ERROR [conjure.nvim.api:12] - Error while making nvim call {:method :nvim-buf-line-count, :params [nil]} -> {:error [0 "Wrong type for argument 1, expecting Buffer"], :result nil}
19-07-17 16:29:59 moondog ERROR [conjure.util:63] - Error while pretty printing java.lang.Exception: :parse-string-all? requires a string!
19-07-17 16:29:59 moondog ERROR [conjure.rpc:?] - Error from thread 'RPC message handler': java.lang.NullPointerException
19-07-17 16:30:24 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :notify, :method :stop, :params [0], :client :stdio}
19-07-17 16:30:24 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-get-current-buf, :params nil}
19-07-17 16:30:24 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error nil, :result #msgpack.core.Ext{:type 0, :data #object["[B" 0x75fc5f53 "[B@75fc5f53"]}, :client :stdio}
19-07-17 16:30:24 moondog ERROR [conjure.util:63] - Error while pretty printing java.lang.Exception: :parse-string-all? requires a string!
19-07-17 16:30:24 moondog TRACE [conjure.rpc:186] - Sending RPC message: {:type :request, :client :stdio, :id 1, :method :nvim-call-atomic, :params [(["nvim_buf_get_name" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x75fc5f53 "[B@75fc5f53"]}]] ["nvim_buf_line_count" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x75fc5f53 "[B@75fc5f53"]}]] ["nvim_buf_get_lines" [#msgpack.core.Ext{:type 0, :data #object["[B" 0x75fc5f53 "[B@75fc5f53"]} 0 25 false]] ["nvim_get_current_win" []])]}
19-07-17 16:30:24 moondog ERROR [conjure.rpc:?] - Error from thread 'RPC stdin handler': java.io.EOFException
19-07-17 16:30:24 moondog INFO [conjure.main:22] - Shutting down
@Olical
Copy link
Owner

Olical commented Jul 17, 2019 via email

@daveyarwood
Copy link
Sponsor Contributor Author

That Can't open file /tmp... error is from vista.vim, to clarify :)

@Olical Olical added the bug Something isn't working label Jul 17, 2019
@Olical Olical self-assigned this Jul 17, 2019
@Olical Olical added this to the v1.0.0 milestone Jul 17, 2019
@Olical
Copy link
Owner

Olical commented Jul 17, 2019

Also thank you for calling it an edge case rather than a bug, that's one step away from calling it an unintended feature 😄

@Olical
Copy link
Owner

Olical commented Jul 17, 2019

So this error is actually coming out of Conjure:

19-07-17 16:29:59 moondog TRACE [conjure.rpc:199] - Received RPC message: {:type :response, :id 1, :error [0 "Error executing lua: /home/dave/.vim/bundle/conjure//lua/conjure.lua:87: Vim(if):E482: Can't open file /tmp/user/10007d12eecc0088a7ae6e413b2dd9867a4f3aabb0807309eacc4899826f7042e53a.clj for writing: permission denied"], :result nil, :client :stdio}

More precisely, it's coming out of the Lua function, upsert_log. So it seems like there might be a race condition there somewhere 🤔

@Olical
Copy link
Owner

Olical commented Jul 17, 2019 •
edited

So the error is coming from this:

    if open then
      if focus ~= true then
        vim.api.nvim_command("wincmd p") -- <- this line
      end
    else
      vim.api.nvim_command("wincmd q")
    end

So it looks like as I try to go back to your original window it explodes. This case only happens on the initial load or if you've deleted Conjure's log buffer and it needs to make a new one.

@Olical
Copy link
Owner

Olical commented Jul 17, 2019

How's develop look for you now @daveyarwood? I basically wrapped that wincmd p in pcall which is kinda like a catch all? Because I think it's the act of going to the previous buffer that's causing this issue, which is weird.

I'm just kinda paving over this edge case since it's not something Conjure is causing directly... as far as I can tell.

@daveyarwood
Copy link
Sponsor Contributor Author

The changes on develop do not seem to fix this issue. The behavior seems to be the same, although I haven't dug into the logs to verify if anything has changed. Here they are, in case it's helpful.

Screenshot:

2019-07-18-105706_1719x374_scrot

Logs:

conjure.log

@Olical
Copy link
Owner

Olical commented Jul 18, 2019

Ah, that sucks 😭 okay, I'll have another dig, I'm not sure what could be causing it right now.

@Olical
Copy link
Owner

Olical commented Jul 21, 2019

Oh, did liuchengxu/vista.vim#124 fix the issue? Because I was beginning to see what vista was doing to check if it was conflicting with Conjure and it's log buffer upsert somehow. Basically that permission error was causing the log buffer to never get created which breaks all sorts of things.

Luckily the upsert is run every time, so that's why it works after you attempt something else.

@Olical Olical closed this as completed in 0a7d9bb Jul 28, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Olical Olical

Labels
bug Something isn't working
Projects
None yet
Milestone
v1.0.0
Development

No branches or pull requests
2 participants
@Olical @daveyarwood