Parse "Defined:" from profile output with functions (#52)

Requires Vim v8.1.0365.

Makefile

@@ -21,6 +21,7 @@ fixtures: tests/fixtures/conditional_function.profile
 fixtures: tests/fixtures/function_in_function.profile
 fixtures: tests/fixtures/function_in_function_count.profile
 fixtures: tests/fixtures/function_in_function_with_ref.profile
+fixtures: tests/fixtures/duplicate_s_function.profile
 fixtures: $(PROFILES_TO_MERGE_COND)
 
 # TODO: cleanup.  Should be handled by the generic rule at the bottom.
@@ -55,9 +56,11 @@ $(PROFILES_TO_MERGE_COND): tests/test_plugin/merged_conditionals.vim Makefile
 	done
 	sed -i 's:^SCRIPT  .*/test_plugin:SCRIPT  tests/test_plugin:' $(PROFILES_TO_MERGE_COND)
 
-tests/fixtures/%.profile: tests/test_plugin/%.vim Makefile
-	$(VIM) --noplugin -Nu tests/t.vim --cmd 'let g:prof_fname = "$@"' -c 'source $<' -c q
-	sed -i 's:^SCRIPT  .*/test_plugin:SCRIPT  tests/test_plugin:' $@
+tests/fixtures/%.profile: tests/test_plugin/%.vim Makefile tests/t.vim
+	$(VIM) --noplugin -Nu tests/t.vim --cmd 'let g:prof_fname = "$@"' -c 'source $<' \
+		-c 'exe empty(v:errmsg) ? "qall" : "echoerr v:errmsg"'
+	sed -Ei 's:^SCRIPT  .*/tests/test_plugin:SCRIPT  tests/test_plugin:' $@
+	sed -Ei 's~^    Defined: .*/tests/test_plugin~    Defined: tests/test_plugin~' $@
 
 
 # Helpers to generate (combined) coverage and show a diff {{{

covimerage/__init__.py

@@ -69,6 +69,7 @@ class Function(object):
     total_time = attr.ib(default=None)
     self_time = attr.ib(default=None)
     lines = attr.ib(default=attr.Factory(dict), repr=False)
+    source = None
 
 
 @attr.s
@@ -206,6 +207,7 @@ def write_coveragepy_data(self, data_file='.coverage'):
 @attr.s
 class Profile(object):
     fname = attr.ib()
+    # TODO: make this a dict?  (scripts_by_fname)
     scripts = attr.ib(default=attr.Factory(list))
     anonymous_functions = attr.ib(default=attr.Factory(dict))
     _fobj = None
@@ -214,6 +216,7 @@ class Profile(object):
     def __attrs_post_init__(self):
         self.fname, self._fobj, self._fstr = get_fname_and_fobj_and_str(
             self.fname)
+        self.scripts_by_fname = {}
 
     @property
     def scriptfiles(self):
@@ -396,6 +399,7 @@ def skip_to_count_header():
                 in_script = Script(fname)
                 logger.debug('Parsing script %s', in_script)
                 self.scripts.append(in_script)
+                self.scripts_by_fname[fname] = in_script
 
                 next_line = next(file_object)
                 m = RE_SOURCED_TIMES.match(next_line)
@@ -408,7 +412,18 @@ def skip_to_count_header():
                 func_name = line[10:-2]
                 in_function = Function(name=func_name)
                 logger.debug('Parsing function %s', in_function)
-                plnum += skip_to_count_header()
+                while True:
+                    next_line = next(file_object)
+                    if not next_line:
+                        break
+                    plnum += 1
+                    if next_line.startswith('count'):
+                        break
+                    if next_line.startswith('    Defined:'):
+                        fname, lnum = next_line[13:].rstrip().rsplit(' line ', 1)  # noqa: E501
+                        fname = os.path.expanduser(fname)
+                        in_function.source = (self.scripts_by_fname[fname],
+                                              int(lnum))
                 lnum = 0
         self.map_functions(functions)
 
@@ -426,12 +441,15 @@ def map_functions(self, functions):
             logger.error('Could not find source for function: %s', f.name)
 
     def map_function(self, f):
-        script_line = self.find_func_in_source(f)
-        if not script_line:
-            return False
+        if f.source:
+            script, script_lnum = f.source
+        else:
+            script_line = self.find_func_in_source(f)
+            if not script_line:
+                return False
+            script, script_lnum = script_line
 
         # Assign counts from function to script.
-        script, script_lnum = script_line
         for [f_lnum, f_line] in f.lines.items():
             s_line = script.lines[script_lnum + f_lnum]
 

tests/fixtures/duplicate_s_function.profile

@@ -0,0 +1,67 @@
+SCRIPT  tests/test_plugin/duplicate_s_function.vim
+Sourced 1 time
+Total time:   0.000180
+ Self time:   0.000083
+
+count  total (s)   self (s)
+                            " https://github.com/vim/vim/issues/3286
+    1              0.000008 function! s:function(name) abort
+                              echom a:name
+                            endfunction
+
+    1   0.000032   0.000013 call s:function('name')
+    1   0.000131   0.000053 call test_plugin#function#function('name')
+
+SCRIPT  tests/test_plugin/autoload/test_plugin/function.vim
+Sourced 1 time
+Total time:   0.000025
+ Self time:   0.000025
+
+count  total (s)   self (s)
+    1              0.000004 function! s:function(name) abort
+                              echom a:name
+                            endfunction
+
+    1              0.000002 function! test_plugin#function#function(name) abort
+                              call s:function(a:name)
+                            endfunction
+
+FUNCTION  test_plugin#function#function()
+    Defined: tests/test_plugin/autoload/test_plugin/function.vim line 5
+Called 1 time
+Total time:   0.000032
+ Self time:   0.000007
+
+count  total (s)   self (s)
+    1   0.000031   0.000006   call s:function(a:name)
+
+FUNCTION  <SNR>2_function()
+    Defined: tests/test_plugin/duplicate_s_function.vim line 2
+Called 1 time
+Total time:   0.000019
+ Self time:   0.000019
+
+count  total (s)   self (s)
+    1              0.000019   echom a:name
+
+FUNCTION  <SNR>3_function()
+    Defined: tests/test_plugin/autoload/test_plugin/function.vim line 1
+Called 1 time
+Total time:   0.000025
+ Self time:   0.000025
+
+count  total (s)   self (s)
+    1              0.000024   echom a:name
+
+FUNCTIONS SORTED ON TOTAL TIME
+count  total (s)   self (s)  function
+    1   0.000032   0.000007  test_plugin#function#function()
+    1   0.000025             <SNR>3_function()
+    1   0.000019             <SNR>2_function()
+
+FUNCTIONS SORTED ON SELF TIME
+count  total (s)   self (s)  function
+    1              0.000025  <SNR>3_function()
+    1              0.000019  <SNR>2_function()
+    1   0.000032   0.000007  test_plugin#function#function()
+

tests/t.vim

@@ -2,7 +2,8 @@ let prof_fname = get(g:, 'prof_fname')
 exe 'profile start '.prof_fname
 profile! file tests/test_plugin/**
 
-set runtimepath+=$PWD/test_plugin
+let sfile = expand('<sfile>')
+let &runtimepath = $PWD.'/tests/test_plugin,'.&runtimepath
 
 " call test_plugin#func1(1)
 

tests/test_main.py

@@ -521,3 +521,38 @@ def test_map_functions(caplog):
     assert len(funcs) == 1
     assert caplog.record_tuples == [
         ('covimerage', 40, 'Could not find source for function: missing')]
+
+
+def test_duplicate_s_function(caplog):
+    from covimerage import Profile
+
+    fname = 'tests/fixtures/duplicate_s_function.profile'
+    p = Profile(fname)
+    p.parse()
+
+    assert len(p.scripts) == 2
+
+    N = None
+    assert [(l.count, l.line)
+            for l in p.scripts[0].lines.values()
+            if not l.line.startswith('"')] == [
+                (1, 'function! s:function(name) abort'),
+                (1, '  echom a:name'),
+                (N, 'endfunction'),
+                (N, ''),
+                (1, "call s:function('name')"),
+                (1, "call test_plugin#function#function('name')"),
+            ]
+
+    assert [(l.count, l.line)
+            for l in p.scripts[1].lines.values()
+            if not l.line.startswith('"')] == [
+                (1, 'function! s:function(name) abort'),
+                (1, '  echom a:name'),
+                (N, 'endfunction'),
+                (N, ''),
+                (1, 'function! test_plugin#function#function(name) abort'),
+                (1, '  call s:function(a:name)'),
+                (N, 'endfunction')]
+
+    assert not caplog.records

tests/test_plugin/autoload/test_plugin/function.vim

@@ -0,0 +1,7 @@
+function! s:function(name) abort
+  echom a:name
+endfunction
+
+function! test_plugin#function#function(name) abort
+  call s:function(a:name)
+endfunction

tests/test_plugin/duplicate_s_function.vim

@@ -0,0 +1,7 @@
+" https://github.com/vim/vim/issues/3286
+function! s:function(name) abort
+  echom a:name
+endfunction
+
+call s:function('name')
+call test_plugin#function#function('name')