patch 8.2.4712: only get profiling information after exitingv8.2.4712

Problem:    Only get profiling information after exiting.
Solution:   Add "profile dump" and "profile stop". (Marco Hinz, Yegappan
            Lakshmanan, closes #10107)

4 files changed, 211 insertions, 12 deletions

diff --git a/runtime/doc/repeat.txt b/runtime/doc/repeat.txt
index 42852219c..b06fcdb57 100644
--- a/runtime/doc/repeat.txt
+++ b/runtime/doc/repeat.txt
@@ -1043,18 +1043,24 @@ For example, to profile the one_script.vim script file: >
 
 
 :prof[ile] start {fname}			*:prof* *:profile* *E750*
-		Start profiling, write the output in {fname} upon exit.
+		Start profiling, write the output in {fname} upon exit or when
+		a `:profile stop` or `:profile dump` command is invoked.
 		"~/" and environment variables in {fname} will be expanded.
 		If {fname} already exists it will be silently overwritten.
 		The variable |v:profiling| is set to one.
 
+:prof[ile] stop
+		Write the collected profiling information to the logfile and
+		stop profiling. You can use the `:profile start` command to
+		clear the profiling statistics and start profiling again.
+
 :prof[ile] pause
-		Don't profile until the following ":profile continue".  Can be
+		Don't profile until the following `:profile continue`.  Can be
 		used when doing something that should not be counted (e.g., an
 		external command).  Does not nest.
 
 :prof[ile] continue
-		Continue profiling after ":profile pause".
+		Continue profiling after `:profile pause`.
 
 :prof[ile] func {pattern}
 		Profile function that matches the pattern {pattern}.
@@ -1071,11 +1077,17 @@ For example, to profile the one_script.vim script file: >
 		after this command.  A :profile command in the script itself
 		won't work.
 
+:prof[ile] dump
+		Write the current state of profiling to the logfile
+		immediately.  After running this command, Vim continues to
+		collect the profiling statistics.
 
 :profd[el] ...						*:profd* *:profdel*
 		Stop profiling for the arguments specified. See |:breakdel|
-		for the arguments.
-
+		for the arguments. Examples: >
+			profdel func MyFunc
+			profdel file MyScript.vim
+			profdel here
 
 You must always start with a ":profile start fname" command.  The resulting
 file is written when Vim exits.  For example, to profile one specific
diff --git a/src/profiler.c b/src/profiler.c
index f1b9a4069..8b6b810e7 100644
--- a/src/profiler.c
+++ b/src/profiler.c
@@ -299,6 +299,82 @@ static char_u	*profile_fname = NULL;
 static proftime_T pause_time;
 
 /*
+ * Reset all profiling information.
+ */
+    static void
+profile_reset(void)
+{
+    int		id;
+    int		todo;
+    hashtab_T	*functbl;
+    hashitem_T	*hi;
+
+    // Reset sourced files.
+    for (id = 1; id <= script_items.ga_len; id++)
+    {
+	scriptitem_T *si = SCRIPT_ITEM(id);
+	if (si->sn_prof_on)
+	{
+	    si->sn_prof_on      = FALSE;
+	    si->sn_pr_force     = FALSE;
+	    profile_zero(&si->sn_pr_child);
+	    si->sn_pr_nest      = 0;
+	    si->sn_pr_count     = 0;
+	    profile_zero(&si->sn_pr_total);
+	    profile_zero(&si->sn_pr_self);
+	    profile_zero(&si->sn_pr_start);
+	    profile_zero(&si->sn_pr_children);
+	    ga_clear(&si->sn_prl_ga);
+	    profile_zero(&si->sn_prl_start);
+	    profile_zero(&si->sn_prl_children);
+	    profile_zero(&si->sn_prl_wait);
+	    si->sn_prl_idx      = -1;
+	    si->sn_prl_execed   = 0;
+	}
+    }
+
+    // Reset functions.
+    functbl = func_tbl_get();
+    todo = (int)functbl->ht_used;
+
+    for (hi = functbl->ht_array; todo > 0; ++hi)
+    {
+	ufunc_T *fp;
+	int	i;
+
+	if (HASHITEM_EMPTY(hi))
+	    continue;
+
+	todo--;
+	fp = HI2UF(hi);
+	if (fp->uf_prof_initialized)
+	{
+	    fp->uf_profiling    = 0;
+	    fp->uf_prof_initialized = FALSE;
+	    fp->uf_tm_count     = 0;
+	    profile_zero(&fp->uf_tm_total);
+	    profile_zero(&fp->uf_tm_self);
+	    profile_zero(&fp->uf_tm_children);
+
+	    for (i = 0; i < fp->uf_lines.ga_len; i++)
+	    {
+		fp->uf_tml_count[i] = 0;
+		profile_zero(&fp->uf_tml_total[i]);
+		profile_zero(&fp->uf_tml_self[i]);
+	    }
+
+	    profile_zero(&fp->uf_tml_start);
+	    profile_zero(&fp->uf_tml_children);
+	    profile_zero(&fp->uf_tml_wait);
+	    fp->uf_tml_idx      = -1;
+	    fp->uf_tml_execed   = 0;
+	}
+    }
+
+    VIM_CLEAR(profile_fname);
+}
+
+/*
  * ":profile cmd args"
  */
     void
@@ -313,7 +389,7 @@ ex_profile(exarg_T *eap)
 
     if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL)
     {
-	vim_free(profile_fname);
+	VIM_CLEAR(profile_fname);
 	profile_fname = expand_env_save_opt(e, TRUE);
 	do_profiling = PROF_YES;
 	profile_zero(&prof_wait_time);
@@ -321,6 +397,13 @@ ex_profile(exarg_T *eap)
     }
     else if (do_profiling == PROF_NONE)
 	emsg(_(e_first_use_profile_start_fname));
+    else if (STRCMP(eap->arg, "stop") == 0)
+    {
+	profile_dump();
+	do_profiling = PROF_NONE;
+	set_vim_var_nr(VV_PROFILING, 0L);
+	profile_reset();
+    }
     else if (STRCMP(eap->arg, "pause") == 0)
     {
 	if (do_profiling == PROF_YES)
@@ -336,6 +419,8 @@ ex_profile(exarg_T *eap)
 	}
 	do_profiling = PROF_YES;
     }
+    else if (STRCMP(eap->arg, "dump") == 0)
+	profile_dump();
     else
     {
 	// The rest is similar to ":breakadd".
@@ -353,16 +438,20 @@ static enum
 static char *pexpand_cmds[] = {
 			"start",
 #define PROFCMD_START	0
+			"stop",
+#define PROFCMD_STOP	1
 			"pause",
-#define PROFCMD_PAUSE	1
+#define PROFCMD_PAUSE	2
 			"continue",
-#define PROFCMD_CONTINUE 2
+#define PROFCMD_CONTINUE 3
 			"func",
-#define PROFCMD_FUNC	3
+#define PROFCMD_FUNC	4
 			"file",
-#define PROFCMD_FILE	4
+#define PROFCMD_DUMP	5
+			"dump",
+#define PROFCMD_FILE	6
 			NULL
-#define PROFCMD_LAST	5
+#define PROFCMD_LAST	7
 };
 
 /*
diff --git a/src/testdir/test_profile.vim b/src/testdir/test_profile.vim
index d95cbddcb..340048e3c 100644
--- a/src/testdir/test_profile.vim
+++ b/src/testdir/test_profile.vim
@@ -428,9 +428,103 @@ func Test_profile_file_with_cont()
   call delete('Xprofile_file.log')
 endfunc
 
+" Test for ':profile stop' and ':profile dump' commands
+func Test_profile_stop_dump()
+  call delete('Xprof1.out')
+  call delete('Xprof2.out')
+  call delete('Xprof3.out')
+  func Xprof_test1()
+    return "Hello"
+  endfunc
+  func Xprof_test2()
+    return "World"
+  endfunc
+
+  " Test for ':profile stop'
+  profile start Xprof1.out
+  profile func Xprof_test1
+  call Xprof_test1()
+  profile stop
+
+  let lines = readfile('Xprof1.out')
+  call assert_equal(17, len(lines))
+  call assert_equal('FUNCTION  Xprof_test1()',                lines[0])
+  call assert_match('Defined:.*test_profile.vim:',            lines[1])
+  call assert_equal('Called 1 time',                          lines[2])
+  call assert_match('^Total time:\s\+\d\+\.\d\+$',            lines[3])
+  call assert_match('^ Self time:\s\+\d\+\.\d\+$',            lines[4])
+  call assert_equal('',                                       lines[5])
+  call assert_equal('count  total (s)   self (s)',            lines[6])
+  call assert_match('^\s*1\s\+.*\sreturn "Hello"$',           lines[7])
+  call assert_equal('',                                       lines[8])
+  call assert_equal('FUNCTIONS SORTED ON TOTAL TIME',         lines[9])
+  call assert_equal('count  total (s)   self (s)  function',  lines[10])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$',  lines[11])
+  call assert_equal('',                                       lines[12])
+  call assert_equal('FUNCTIONS SORTED ON SELF TIME',          lines[13])
+  call assert_equal('count  total (s)   self (s)  function',  lines[14])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$',  lines[15])
+  call assert_equal('',                                       lines[16])
+
+  " Test for ':profile stop' for a different function
+  profile start Xprof2.out
+  profile func Xprof_test2
+  call Xprof_test2()
+  profile stop
+  let lines = readfile('Xprof2.out')
+  call assert_equal(17, len(lines))
+  call assert_equal('FUNCTION  Xprof_test2()',                lines[0])
+  call assert_match('Defined:.*test_profile.vim:',            lines[1])
+  call assert_equal('Called 1 time',                          lines[2])
+  call assert_match('^Total time:\s\+\d\+\.\d\+$',            lines[3])
+  call assert_match('^ Self time:\s\+\d\+\.\d\+$',            lines[4])
+  call assert_equal('',                                       lines[5])
+  call assert_equal('count  total (s)   self (s)',            lines[6])
+  call assert_match('^\s*1\s\+.*\sreturn "World"$',           lines[7])
+  call assert_equal('',                                       lines[8])
+  call assert_equal('FUNCTIONS SORTED ON TOTAL TIME',         lines[9])
+  call assert_equal('count  total (s)   self (s)  function',  lines[10])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$',  lines[11])
+  call assert_equal('',                                       lines[12])
+  call assert_equal('FUNCTIONS SORTED ON SELF TIME',          lines[13])
+  call assert_equal('count  total (s)   self (s)  function',  lines[14])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$',  lines[15])
+  call assert_equal('',                                       lines[16])
+
+  " Test for ':profile dump'
+  profile start Xprof3.out
+  profile func Xprof_test1
+  profile func Xprof_test2
+  call Xprof_test1()
+  profile dump
+  " dump the profile once and verify the contents
+  let lines = readfile('Xprof3.out')
+  call assert_equal(17, len(lines))
+  call assert_match('^\s*1\s\+.*\sreturn "Hello"$',           lines[7])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$',  lines[11])
+  call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$',  lines[15])
+  " dump the profile again and verify the contents
+  call Xprof_test2()
+  profile dump
+  profile stop
+  let lines = readfile('Xprof3.out')
+  call assert_equal(28, len(lines))
+  call assert_equal('FUNCTION  Xprof_test1()',                lines[0])
+  call assert_match('^\s*1\s\+.*\sreturn "Hello"$',           lines[7])
+  call assert_equal('FUNCTION  Xprof_test2()',                lines[9])
+  call assert_match('^\s*1\s\+.*\sreturn "World"$',           lines[16])
+
+  delfunc Xprof_test1
+  delfunc Xprof_test2
+  call delete('Xprof1.out')
+  call delete('Xprof2.out')
+  call delete('Xprof3.out')
+endfunc
+
+" Test for :profile sub-command completion
 func Test_profile_completion()
   call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
-  call assert_equal('"profile continue file func pause start', @:)
+  call assert_equal('"profile continue dump file func pause start stop', @:)
 
   call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
   call assert_match('^"profile start.* test_profile\.vim', @:)
@@ -481,6 +575,8 @@ func Test_profile_errors()
   call assert_fails("profile func Foo", 'E750:')
   call assert_fails("profile pause", 'E750:')
   call assert_fails("profile continue", 'E750:')
+  call assert_fails("profile stop", 'E750:')
+  call assert_fails("profile dump", 'E750:')
 endfunc
 
 func Test_profile_truncate_mbyte()
diff --git a/src/version.c b/src/version.c
index 54efff406..cebb0d018 100644
--- a/src/version.c
+++ b/src/version.c
@@ -747,6 +747,8 @@ static char *(features[]) =
 static int included_patches[] =
 {   /* Add new patch number below this line */
 /**/
+    4712,
+/**/
     4711,
 /**/
     4710,