Conflicting formatters?

[ctranstrum]

I feel like I must be missing something obvious, but I'm trying to configure two javascript formatters to run, and I can't seem to get them both to run. I can run one, or I can run the other, but when I attempt to run them both, all formatters stop working. Then to top it off, adding "debug=true" to the null_ls setup doesn't seem to move the log level from "warn", either.

My setup is fairly simple:

null_ls = require('null-ls')
local lint = null_ls.builtins.diagnostics
local fix = null_ls.builtins.formatting
null_ls.setup {
  debug = true,
  sources = {
    -- all filetypes
    fix.trim_newlines,
    fix.trim_whitespace,

    -- javascript
    lint.standardjs,
    fix.prettier,
    fix.standardjs,

    -- python
    fix.black,
    lint.flake8,
    fix.reorder_python_imports,
  },
}

Working on python files, I see that both black and reorder-python-imports runs, as well as the trim-newlines and trim-whitespace.

However, on javascript files, no formatters run, not even trim-{newlines,whitespace}. Unless I comment out one or the other of fix.prettier or fix.standardjs. Then the everything else runs as expected.

Also, when I run NullLsInfo, it tells me that the current logging level is "warn" ... but shouldn't it be "debug"? I am not seeing anything helpful in the logs at the warn level.

The only thing I can think of is that standardjs is the name of both a formatter as well as a diagnostic, but since I can run both of those just fine when I have prettier commented out, I don't expect that's the problem.

Any advice?

[jose-elias-alvarez]

So the log level display is a bug that should be fixed by 6d90daf. Using your config, I can correctly see the debug output when running :NullLsLog or directly opening the file. That output is showing that all of your defined formatters are running in sequence on a JavaScript file. For example, given the following content (including the trailing newlines):

console.log( "hi" )      

Running vim.lsp.buf.formatting() with your config results in the following debug output:

[TRACE Tue Jan 25 17:30:56 2022] .../site/pack/packer/start/null-ls.nvim/lua/null-ls/rpc.lua:118: received LSP request for method textDocument/formatting
[TRACE Tue Jan 25 17:30:56 2022] ...ack/packer/start/null-ls.nvim/lua/null-ls/generators.lua:21: running generators for method NULL_LS_FORMATTING
[DEBUG Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:335: spawning command [awk] at /Users/jose/git/dotfiles with args { 'NF{print s $0; s=""; next} {s=s ORS}' }
[TRACE Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:224: error output: nil
[TRACE Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:225: output: console.log( "hi" )

[DEBUG Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:335: spawning command [awk] at /Users/jose/git/dotfiles with args { '{ sub(/[ \t]+$/, ""); print }' }
[TRACE Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:224: error output: nil
[TRACE Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:225: output: console.log( "hi" )

[DEBUG Tue Jan 25 17:30:56 2022] ...rt/null-ls.nvim/lua/null-ls/helpers/command_resolver.lua:18: attempting to find local executable node_modules/.bin/prettier
[DEBUG Tue Jan 25 17:30:56 2022] ...rt/null-ls.nvim/lua/null-ls/helpers/command_resolver.lua:40: Unable to resolve command [node_modules/.bin/prettier], skipping further lookups
[DEBUG Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:281: Using dynamic command for [prettier], got: prettier
[DEBUG Tue Jan 25 17:30:56 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:335: spawning command [prettier] at /Users/jose/git/dotfiles with args { "--stdin-filepath", "/Users/jose/git/dotfiles/test.js" }
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:224: error output: nil
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:225: output: console.log("hi");

[DEBUG Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:281: Using dynamic command for [standard], got: standard
[DEBUG Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:335: spawning command [standard] at /Users/jose/git/dotfiles with args { "--stdin", "--fix" }
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:224: error output: nil
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:225: output: console.log('hi')

[DEBUG Tue Jan 25 17:30:57 2022] ...ack/packer/start/null-ls.nvim/lua/null-ls/formatting.lua:87: received edits from generators
[TRACE Tue Jan 25 17:30:57 2022] ...ack/packer/start/null-ls.nvim/lua/null-ls/formatting.lua:88: {
  newText = "'hi')",
  range = {
    end = {
      character = 0,
      line = 4
    },
    start = {
      character = 12,
      line = 0
    }
  },
  rangeLength = 17
}
[TRACE Tue Jan 25 17:30:57 2022] .../site/pack/packer/start/null-ls.nvim/lua/null-ls/rpc.lua:143: received LSP notification for method textDocument/didChange
[TRACE Tue Jan 25 17:30:57 2022] ...ack/packer/start/null-ls.nvim/lua/null-ls/generators.lua:21: running generators for method NULL_LS_DIAGNOSTICS
[DEBUG Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:281: Using dynamic command for [standard], got: standard
[DEBUG Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:335: spawning command [standard] at /Users/jose/git/dotfiles with args { "--stdin" }
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:224: error output: nil
[TRACE Tue Jan 25 17:30:57 2022] ...t/null-ls.nvim/lua/null-ls/helpers/generator_factory.lua:225: output: nil
[TRACE Tue Jan 25 17:30:57 2022] ...ck/packer/start/null-ls.nvim/lua/null-ls/diagnostics.lua:156: received diagnostics from source 3
[TRACE Tue Jan 25 17:30:57 2022] ...ck/packer/start/null-ls.nvim/lua/null-ls/diagnostics.lua:157: {}

The end result correctly reflects the output from running cat test.js | prettier --stdin-filepath test.js | standard --stdin --fix from the command line. How are you concluding that the formatters are not running?

[ctranstrum]

Thanks for looking at this so quickly. I updated to the latest code, and was still seeing the incorrect log level, so I removed a portion of my config that I had omitted because it wasn't relevant, and that made the debug line work. So maybe that's another issue to investigate. But to the point, I got the trace output and can confirm that the formatters are indeed running, all of them in order, and the log is showing that the results of the "received edits from generators" trace line has what the file should be after formatting. However, the file content is not updated to that result, and there are no additional log lines afterward to help explain why it might not have replaced the contents of the buffer.

I tested with the same file you did. However, my trace log output did not include the line "received LSP notification for method textDocument/didChange" and instead included the line "received LSP notification for method $/cancelRequest" ... Any idea what would trigger that?

The very next line in the log is "received LSP notification for method textDocument/didSave" ... but shouldn't that wait until the formatting_sync has completed?

My auto-formatting is bound to a shortcut key that I use to save a file, so that format happens on save: :lua vim.lsp.buf.formatting_sync()<CR>:w<CR>

Ah. And when I add a new, dedicated keymap just to do a format: :lua vim.lsp.buf.formatting()<CR> ... then ... boom, formatting works, and I get the updates I expect. Is there a timeout happening? If so, is there a way I can increase that timeout?

[ctranstrum]

Just FYI. This is a bit off-topic for this conversation. Just an oddity I noticed while trying to figure out the formatting issue.

Minimal config to get debug to not work:

local null_ls = require('null-ls')
local lint = null_ls.builtins.diagnostics
local fix = null_ls.builtins.formatting
null_ls.setup {
  debug = true,
  sources = {
    -- ensure we attach to a buffer, otherwise :NullLsInfo may not work
    fix.trim_newlines,
    -- use a locally installed eslint, but only if we aren't using standard
    lint.eslint.with {
      filetypes = { 'javascript' },
      only_local = 'node_modules/.bin',
      condition = function(utils)
        return not utils.root_has_file('node_modules/.bin/standard')
      end,
    },
  },
}

When I use this config to edit a javascript file, I run ":NullLsInfo" and get "Logging * current level: warn" instead of the expected "trace".

[jose-elias-alvarez]

Take a look at this section of the FAQ. I don't know about standardjs, but vanilla prettier can get really slow, so timeouts are definitely a possibility.

I was able to replicate the log level issue and believe it should be fixed by c236fc7.

[ctranstrum]

Yes, that was it! Thanks so much! I probably should have found that myself without bothering you, but I never saw that error message, either on the screen or in the logs. If the message was only on the screen, it was probably immediately overwritten with the message that I had saved the file.

Changing my keymap to :lua vim.lsp.buf.formatting_sync(nil,2000)<CR>:w<CR> now allows all formatting to be applied on file save.

Also, I can confirm that the log level issue is now resolved. Thank you.