fix(logging): skip recursion, fix crash #18764

Problem:
1. The main log routine does not protect itself against recursion.
   log_lock() doesn't guard against recursion, it would deadlock...
2. 22b52dd462e5 (#11501) regressed 6f27f5ef91b3 (#10172), because
   set_init_1..process_spawn tries to log (see backtrace below), but the
   mutex isn't initialized yet. Even if the mutex were valid, we don't
   want early logging to fallback to stderr because that can break
   embedders when stdio is used for RPC.

    frame 1: 0x00000001001d54f4 nvim`open_log_file at log.c:205:7
    frame 2: 0x00000001001d5390 nvim`logmsg(log_level=1, context="UI: ", func_name=0x0000000000000000, line_num=-1, eol=true, fmt="win_viewport") at log.c:150:20
    frame : 0x000000010039aea2 nvim`ui_call_win_viewport(grid=2, win=1000, topline=0, botline=1, curline=0, curcol=0, line_count=1) at ui_events_call.generated.h:321:3
    frame 4: 0x00000001003dfefc nvim`ui_ext_win_viewport(wp=0x0000000101816400) at window.c:939:5
    frame 5: 0x00000001003ec5b4 nvim`win_ui_flush at window.c:7303:7
    frame 6: 0x00000001003a04c0 nvim`ui_flush at ui.c:508:3
    frame 7: 0x00000001002966ba nvim`do_os_system(argv=0x0000600000c0c000, input=0x0000000000000000, len=0, output=0x0000000000000000, nread=0x00007ff7bfefe830, silent=false, forward_output=false) at shell.c:894:3
    frame 8: 0x0000000100295f68 nvim`os_call_shell(cmd="unset nonomatch; vimglob() { while [ $# -ge 1 ]; do echo \"$1\"; shift; done }; vimglob >/var/folders/gk/3tttv_md06987tlwpyp62jrw0000gn/T/nvimwwvwfD/0 ~foo", opts=kShellOptExpand | kShellOptSilent | kShellOptHideMess, extra_args=0x0000000000000000) at shell.c:663:18
    frame 9: 0x0000000100295845 nvim`call_shell(cmd="unset nonomatch; vimglob() { while [ $# -ge 1 ]; do echo \"$1\"; shift; done }; vimglob >/var/folders/gk/3tttv_md06987tlwpyp62jrw0000gn/T/nvimwwvwfD/0 ~foo", opts=kShellOptExpand | kShellOptSilent | kShellOptHideMess, extra_shell_arg=0x0000000000000000) at shell.c:712:14
    frame 10: 0x0000000100294c6f nvim`os_expand_wildcards(num_pat=1, pat=0x00007ff7bfefeb20, num_file=0x00007ff7bfefee58, file=0x00007ff7bfefee60, flags=43) at shell.c:328:7
    ...
    frame 23: 0x000000010028ccef nvim`expand_env_esc(srcp=",~foo", dst="~foo", dstlen=4094, esc=false, one=false, prefix=0x0000000000000000) at env.c:673:17
    frame 24: 0x000000010026fdd5 nvim`option_expand(opt_idx=29, val=",~foo") at option.c:1950:3
    frame 25: 0x000000010026f129 nvim`set_init_1(clean_arg=false) at option.c:558:19
    frame 26: 0x00000001001ea25e nvim`early_init(paramp=0x00007ff7bfeff5f0) at main.c:198:3
    frame 27: 0x00000001001ea6bf nvim`main(argc=1, argv=0x00007ff7bfeff848) at main.c:255:3

Solution:
1. Check for recursion, show "internal error" message.
    - FUTURE: when "remote TUI" is merged, can we remove log_lock()?
2. Skip logging if log_init wasn't called yet.

1 files changed, 7 insertions, 7 deletions

diff --git a/src/nvim/msgpack_rpc/channel.c b/src/nvim/msgpack_rpc/channel.c
index 79ecd9f827..287310cc34 100644
--- a/src/nvim/msgpack_rpc/channel.c
+++ b/src/nvim/msgpack_rpc/channel.c
@@ -31,7 +31,7 @@
 #include "nvim/ui.h"
 #include "nvim/vim.h"
 
-#if MIN_LOG_LEVEL > DEBUG_LOG_LEVEL
+#if MIN_LOG_LEVEL > LOGLVL_DBG
 # define log_client_msg(...)
 # define log_server_msg(...)
 #endif
@@ -62,7 +62,7 @@ void rpc_start(Channel *channel)
 
   if (channel->streamtype != kChannelStreamInternal) {
     Stream *out = channel_outstream(channel);
-#if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL
+#if MIN_LOG_LEVEL <= LOGLVL_DBG
     Stream *in = channel_instream(channel);
     DLOG("rpc ch %" PRIu64 " in-stream=%p out-stream=%p", channel->id,
          (void *)in, (void *)out);
@@ -209,7 +209,7 @@ static void receive_msgpack(Stream *stream, RBuffer *rbuf, size_t c, void *data,
     char buf[256];
     snprintf(buf, sizeof(buf), "ch %" PRIu64 " was closed by the client",
              channel->id);
-    call_set_error(channel, buf, INFO_LOG_LEVEL);
+    call_set_error(channel, buf, LOGLVL_INF);
     goto end;
   }
 
@@ -249,7 +249,7 @@ static void parse_msgpack(Channel *channel)
                  "ch %" PRIu64 " returned a response with an unknown request "
                  "id. Ensure the client is properly synchronized",
                  channel->id);
-        call_set_error(channel, buf, ERROR_LOG_LEVEL);
+        call_set_error(channel, buf, LOGLVL_ERR);
       }
       msgpack_unpacked_destroy(&unpacked);
     } else {
@@ -299,7 +299,7 @@ static void handle_request(Channel *channel, msgpack_object *request)
       snprintf(buf, sizeof(buf),
                "ch %" PRIu64 " sent an invalid message, closed.",
                channel->id);
-      call_set_error(channel, buf, ERROR_LOG_LEVEL);
+      call_set_error(channel, buf, LOGLVL_ERR);
     }
     api_clear_error(&error);
     return;
@@ -418,7 +418,7 @@ static bool channel_write(Channel *channel, WBuffer *buffer)
              "ch %" PRIu64 ": stream write failed. "
              "RPC canceled; closing channel",
              channel->id);
-    call_set_error(channel, buf, ERROR_LOG_LEVEL);
+    call_set_error(channel, buf, LOGLVL_ERR);
   }
 
   return success;
@@ -693,7 +693,7 @@ const char *rpc_client_name(Channel *chan)
   return NULL;
 }
 
-#if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL
+#if MIN_LOG_LEVEL <= LOGLVL_DBG
 # define REQ "[request]  "
 # define RES "[response] "
 # define NOT "[notify]   "