patch 8.2.4742: there is no way to start logging very early in startup

Problem:    There is no way to start logging very early in startup.
Solution:   Add the --log argument.  Include the date in the start message in
            the log file.  Avoid a duplicate message when forking.  Log an
            executed shell command.

diff --git a/runtime/doc/channel.txt b/runtime/doc/channel.txt
index a306abb4888c24ed4834dc26a2c5bf34566e1e15..01756f1458534450a186983ae37e68309a42f9ed 100644 (file)
--- a/runtime/doc/channel.txt
+++ b/runtime/doc/channel.txt
@@ -633,8 +633,8 @@ ch_logfile({fname} [, {mode}])                                      *ch_logfile()*
                is going on in real time.
 
                To enable the log very early, to see what is received from a
-               terminal during startup, use |--cmd|: >
-                       vim --cmd "call ch_logfile('logfile', 'w')"
+               terminal during startup, use |--log|: >
+                       vim --log logfile
 <
                This function is not available in the |sandbox|.
                NOTE: the channel communication is stored in the file, be

diff --git a/runtime/doc/starting.txt b/runtime/doc/starting.txt
index 16004412adac89cddb304c0147c28613fe1fafbc..9a4014b045380b24cf39c6cfc8431d27116c92e1 100644 (file)
--- a/runtime/doc/starting.txt
+++ b/runtime/doc/starting.txt
@@ -344,6 +344,12 @@ a slash.  Thus "-R" means recovery and "-/R" readonly.
                Example: >
                        vim -V20vimlog foobar
 <
+--log {filename}                                       *--log*
+               Start logging and write entries to {filename}.
+               This works like calling `ch_logfile({filename}, 'a')` very
+               early during startup.
+               {only available with the +channel feature}
+
                                                        *-D*
 -D             Debugging.  Go to debugging mode when executing the first
                command from a script. |debug-mode|
@@ -564,6 +570,7 @@ a slash.  Thus "-R" means recovery and "-/R" readonly.
                {scriptout} cannot start with a digit.
                If you want to record what is typed in a human readable for
                you can use |ch_logfile()|, It adds "raw key input" lines.
+               Also see |--log|.
 
                                                        *-W*
 -W {scriptout} Like -w, but do not append, overwrite an existing file.

diff --git a/src/channel.c b/src/channel.c
index f8a8194374fa6d81c6ac96aec4d7c4135eb192e7..e971e17c09cdf98b929ed92cd2846425e991dff8 100644 (file)
--- a/src/channel.c
+++ b/src/channel.c
@@ -178,7 +178,10 @@ ch_logfile(char_u *fname, char_u *opt)
 
     if (log_fd != NULL)
     {
-       fprintf(log_fd, "==== start log session ====\n");
+       fprintf(log_fd, "==== start log session %s ====\n",
+                                                get_ctime(time(NULL), FALSE));
+       // flush now, if fork/exec follows it could be written twice
+       fflush(log_fd);
 #ifdef FEAT_RELTIME
        profile_start(&log_start);
 #endif

diff --git a/src/main.c b/src/main.c
index 036ab0a1f7aff87e6c623493ee30b60d346f5139..f9b1920733e632a5752ec3b1d34495ed019516d1 100644 (file)
--- a/src/main.c
+++ b/src/main.c
@@ -138,15 +138,23 @@ main
     atexit(vim_mem_profile_dump);
 #endif
 
-#ifdef STARTUPTIME
-    // Need to find "--startuptime" before actually parsing arguments.
+#if defined(STARTUPTIME) || defined(FEAT_JOB_CHANNEL)
+    // Need to find "--startuptime" and "--log" before actually parsing
+    // arguments.
     for (i = 1; i < argc - 1; ++i)
-       if (STRICMP(argv[i], "--startuptime") == 0)
+    {
+# ifdef STARTUPTIME
+       if (STRICMP(argv[i], "--startuptime") == 0 && time_fd == NULL)
        {
            time_fd = mch_fopen(argv[i + 1], "a");
            TIME_MSG("--- VIM STARTING ---");
-           break;
        }
+# endif
+# ifdef FEAT_JOB_CHANNEL
+       if (STRICMP(argv[i], "--log") == 0)
+           ch_logfile((char_u *)(argv[i + 1]), (char_u *)"a");
+# endif
+    }
 #endif
     starttime = time(NULL);
 
@@ -1997,6 +2005,8 @@ command_line_scan(mparm_T *parmp)
                                // "--version" give version message
                                // "--clean" clean context
                                // "--literal" take files literally
+                               // "--startuptime fname" write timing info
+                               // "--log fname" start logging early
                                // "--nofork" don't fork
                                // "--not-a-term" don't warn for not a term
                                // "--ttyfail" exit if not a term
@@ -2053,6 +2063,11 @@ command_line_scan(mparm_T *parmp)
                    want_argument = TRUE;
                    argv_idx += 11;
                }
+               else if (STRNICMP(argv[0] + argv_idx, "log", 3) == 0)
+               {
+                   want_argument = TRUE;
+                   argv_idx += 3;
+               }
 #ifdef FEAT_CLIENTSERVER
                else if (STRNICMP(argv[0] + argv_idx, "serverlist", 10) == 0)
                    ; // already processed -- no arg
@@ -2435,6 +2450,7 @@ command_line_scan(mparm_T *parmp)
                                                            (char_u *)argv[0];
                    }
                    // "--startuptime <file>" already handled
+                   // "--log <file>" already handled
                    break;
 
            //  case 'd':   -d {device} is handled in mch_check_win() for the
@@ -3539,6 +3555,9 @@ usage(void)
 #ifdef STARTUPTIME
     main_msg(_("--startuptime <file>\tWrite startup timing messages to <file>"));
 #endif
+#ifdef FEAT_JOB_CHANNEL
+    main_msg(_("--log <file>\tStart logging to <file> early"));
+#endif
 #ifdef FEAT_VIMINFO
     main_msg(_("-i <viminfo>\t\tUse <viminfo> instead of .viminfo"));
 #endif

diff --git a/src/os_unix.c b/src/os_unix.c
index 826c9c0db7f5004d0da08afc5f6ced6508289d00..d0675e8726c54da7dee9c84e48d11fca2173f5c0 100644 (file)
--- a/src/os_unix.c
+++ b/src/os_unix.c
@@ -5480,6 +5480,9 @@ mch_call_shell(
     char_u     *cmd,
     int                options)        // SHELL_*, see vim.h
 {
+#ifdef FEAT_JOB_CHANNEL
+    ch_log(NULL, "executing shell command: %s", cmd);
+#endif
 #if defined(FEAT_GUI) && defined(FEAT_TERMINAL)
     if (gui.in_use && vim_strchr(p_go, GO_TERMINAL) != NULL)
        return mch_call_shell_terminal(cmd, options);

diff --git a/src/os_win32.c b/src/os_win32.c
index fbf666598f6a454faa88f86f8b841c33458bd90c..e3a57fb11d589968ee9786f7ac9d96488592cb54 100644 (file)
--- a/src/os_win32.c
+++ b/src/os_win32.c
@@ -4767,6 +4767,9 @@ mch_call_shell(
     int                tmode = cur_tmode;
     WCHAR      szShellTitle[512];
 
+#ifdef FEAT_JOB_CHANNEL
+    ch_log(NULL, "executing shell command: %s", cmd);
+#endif
     // Change the title to reflect that we are in a subshell.
     if (GetConsoleTitleW(szShellTitle, ARRAY_LENGTH(szShellTitle) - 4) > 0)
     {

diff --git a/src/testdir/test_startup.vim b/src/testdir/test_startup.vim
index 6926ba313e34f0e505ce130b38922c37e28d4980..c580dd0e491d5b7433375179071769a114331270 100644 (file)
--- a/src/testdir/test_startup.vim
+++ b/src/testdir/test_startup.vim
@@ -726,6 +726,25 @@ func Test_startuptime()
   call delete('Xtestout')
 endfunc
 
+func Test_log()
+  CheckFeature channel
+
+  call assert_false(filereadable('Xlogfile'))
+  let after = ['qall']
+  if RunVim([], after, '--log Xlogfile')
+    call assert_equal(1, readfile('Xlogfile')
+          \ ->filter({i, l -> l =~ '==== start log session'})
+          \ ->len())
+    " second time appends to the log
+    if RunVim([], after, '--log Xlogfile')
+      call assert_equal(2, readfile('Xlogfile')
+            \ ->filter({i, l -> l =~ '==== start log session'})
+            \ ->len())
+    endif
+  endif
+  call delete('Xlogfile')
+endfunc
+
 func Test_read_stdin()
   let after =<< trim [CODE]
     write Xtestout

diff --git a/src/version.c b/src/version.c
index c07ae9dbe5520d3b58be90af4e4058f7becc6d5d..0c3b01c75e413ac7777259c01cc4a59f51abc84f 100644 (file)
--- a/src/version.c
+++ b/src/version.c
@@ -746,6 +746,8 @@ static char *(features[]) =
 
 static int included_patches[] =
 {   /* Add new patch number below this line */
+/**/
+    4742,
 /**/
     4741,
 /**/