Patch 8.2.4742

[Bram Moolenaar]

Patch 8.2.4742
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.
Files: runtime/doc/starting.txt, runtime/doc/channel.txt,
src/main.c, src/channel.c, src/os_unix.c, src/os_win32.c,
src/testdir/test_startup.vim


*** ../vim-8.2.4741/runtime/doc/starting.txt 2022-02-01 17:26:09.330119261 +0000
--- runtime/doc/starting.txt 2022-04-12 15:03:42.714568363 +0100
***************
*** 344,349 ****
--- 344,355 ----
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|
***************
*** 562,567 ****
--- 568,576 ----
":source!". When the "scriptout" file already exists, new
characters are appended. See also |complex-repeat|.
{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.
*** ../vim-8.2.4741/runtime/doc/channel.txt 2022-04-04 15:46:37.602126829 +0100
--- runtime/doc/channel.txt 2022-04-12 15:05:53.245900599 +0100
***************
*** 633,640 ****
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')"
<
This function is not available in the |sandbox|.
NOTE: the channel communication is stored in the file, be
--- 633,640 ----
is going on in real time.

To enable the log very early, to see what is received from a
! 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
*** ../vim-8.2.4741/src/main.c 2022-04-12 11:32:41.428327316 +0100
--- src/main.c 2022-04-12 13:14:54.965156879 +0100
***************
*** 138,152 ****
atexit(vim_mem_profile_dump);
#endif

! #ifdef STARTUPTIME
! // Need to find "--startuptime" before actually parsing arguments.
for (i = 1; i < argc - 1; ++i)
! if (STRICMP(argv[i], "--startuptime") == 0)
{
time_fd = mch_fopen(argv[i + 1], "a");
TIME_MSG("--- VIM STARTING ---");
- break;
}
#endif
starttime = time(NULL);

--- 138,160 ----
atexit(vim_mem_profile_dump);
#endif

! #if defined(STARTUPTIME) || defined(FEAT_JOB_CHANNEL)
! // Need to find "--startuptime" and "--log" before actually parsing
! // arguments.
for (i = 1; i < argc - 1; ++i)
! {
! # ifdef STARTUPTIME
! if (STRICMP(argv[i], "--startuptime") == 0 && time_fd == NULL)
{
time_fd = mch_fopen(argv[i + 1], "a");
TIME_MSG("--- VIM STARTING ---");
}
+ # 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,2002 ****
--- 2005,2012 ----
// "--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,2058 ****
--- 2063,2073 ----
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,2440 ****
--- 2450,2456 ----
(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,3544 ****
--- 3555,3563 ----
#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
*** ../vim-8.2.4741/src/channel.c 2022-04-05 22:03:26.170738960 +0100
--- src/channel.c 2022-04-12 13:33:28.751701004 +0100
***************
*** 178,184 ****

if (log_fd != NULL)
{
! fprintf(log_fd, "==== start log session ====\n");
#ifdef FEAT_RELTIME
profile_start(&log_start);
#endif
--- 178,187 ----

if (log_fd != NULL)
{
! 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
*** ../vim-8.2.4741/src/os_unix.c 2022-03-30 10:57:36.739346189 +0100
--- src/os_unix.c 2022-04-12 13:41:27.298612443 +0100
***************
*** 5480,5485 ****
--- 5480,5488 ----
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);
*** ../vim-8.2.4741/src/os_win32.c 2022-02-12 11:18:32.318462415 +0000
--- src/os_win32.c 2022-04-12 13:44:01.026326767 +0100
***************
*** 4767,4772 ****
--- 4767,4775 ----
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)
{
*** ../vim-8.2.4741/src/testdir/test_startup.vim 2022-04-03 18:01:39.659574455 +0100
--- src/testdir/test_startup.vim 2022-04-12 15:02:48.018885903 +0100
***************
*** 726,731 ****
--- 726,750 ----
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
*** ../vim-8.2.4741/src/version.c 2022-04-12 14:22:46.894838163 +0100
--- src/version.c 2022-04-12 14:47:11.500926868 +0100
***************
*** 748,749 ****
--- 748,751 ----
{ /* Add new patch number below this line */
+ /**/
+ 4742,
/**/

--
FIRST VILLAGER: We have found a witch. May we burn her?
"Monty Python and the Holy Grail" PYTHON (MONTY) PICTURES LTD

/// Bram Moolenaar -- Br...@Moolenaar.net -- http://www.Moolenaar.net \\\
/// \\\
\\\ sponsor Vim, vote for features -- http://www.Vim.org/sponsor/ ///
\\\ help me help AIDS victims -- http://ICCF-Holland.org ///