Improve mapping of functions (#29)

This does not rely on the order of functions being listed in the profile
output anymore.

Author: blueyed

Makefile

@@ -20,6 +20,7 @@ fixtures: tests/fixtures/continued_lines.profile
 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: $(PROFILES_TO_MERGE_COND)
 
 # TODO: cleanup.  Should be handled by the generic rule at the bottom.

covimerage/__init__.py

@@ -354,65 +354,13 @@ def skip_to_count_header():
                     break
             return skipped
 
+        functions = []
         for line in file_object:
             plnum += 1
             line = line.rstrip('\r\n')
             if line == '':
                 if in_function:
-                    func_name = in_function.name
-                    script_line = self.find_func_in_source(in_function)
-                    if not script_line:
-                        LOGGER.error('Could not find source for function: %s',
-                                     func_name)
-                        in_function = False
-                        continue
-
-                    # Assign counts from function to script.
-                    script, script_lnum = script_line
-                    for [f_lnum, f_line] in in_function.lines.items():
-                        s_line = script.lines[script_lnum + f_lnum]
-
-                        # XXX: might not be the same, since function lines
-                        # are joined, while script lines might be spread
-                        # across several lines (prefixed with \).
-                        script_source = s_line.line
-                        if script_source != f_line.line:
-                            while True:
-                                try:
-                                    peek = script.lines[script_lnum +
-                                                        f_lnum + 1]
-                                except KeyError:
-                                    pass
-                                else:
-                                    m = re.match(RE_CONTINUING_LINE, peek.line)
-                                    if m:
-                                        script_source += peek.line[m.end():]
-                                        script_lnum += 1
-                                        # script_lines.append(peek)
-                                        continue
-                                if script_source == f_line.line:
-                                    break
-
-                                assert 0, 'Script line matches function line.'
-
-                        if f_line.count is not None:
-                            script.parse_function(script_lnum + f_lnum,
-                                                  f_line.line)
-                            if s_line.count:
-                                s_line.count += f_line.count
-                            else:
-                                s_line.count = f_line.count
-                        if f_line.self_time:
-                            if s_line.self_time:
-                                s_line.self_time += f_line.self_time
-                            else:
-                                s_line.self_time = f_line.self_time
-                        if f_line.total_time:
-                            if s_line.total_time:
-                                s_line.total_time += f_line.total_time
-                            else:
-                                s_line.total_time = f_line.total_time
-
+                    functions += [in_function]
                 in_script = False
                 in_function = False
                 continue
@@ -464,6 +412,72 @@ def skip_to_count_header():
                 LOGGER.debug('Parsing function %s', in_function)
                 plnum += skip_to_count_header()
                 lnum = 0
+        self.map_functions(functions)
+
+    def map_functions(self, functions):
+        while functions:
+            prev_count = len(functions)
+            for f in functions:
+                if self.map_function(f):
+                    functions.remove(f)
+            new_count = len(functions)
+            if prev_count == new_count:
+                break
+
+        for f in 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
+
+        # 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]
+
+            # XXX: might not be the same, since function lines
+            # are joined, while script lines might be spread
+            # across several lines (prefixed with \).
+            script_source = s_line.line
+            if script_source != f_line.line:
+                while True:
+                    try:
+                        peek = script.lines[script_lnum +
+                                            f_lnum + 1]
+                    except KeyError:
+                        pass
+                    else:
+                        m = re.match(RE_CONTINUING_LINE, peek.line)
+                        if m:
+                            script_source += peek.line[m.end():]
+                            script_lnum += 1
+                            # script_lines.append(peek)
+                            continue
+                    if script_source == f_line.line:
+                        break
+
+                    assert 0, 'Script line matches function line.'
+
+            if f_line.count is not None:
+                script.parse_function(script_lnum + f_lnum,
+                                      f_line.line)
+                if s_line.count:
+                    s_line.count += f_line.count
+                else:
+                    s_line.count = f_line.count
+            if f_line.self_time:
+                if s_line.self_time:
+                    s_line.self_time += f_line.self_time
+                else:
+                    s_line.self_time = f_line.self_time
+            if f_line.total_time:
+                if s_line.total_time:
+                    s_line.total_time += f_line.total_time
+                else:
+                    s_line.total_time = f_line.total_time
+        return True
 
 
 def parse_count_and_times(line):

tests/fixtures/function_in_function_with_ref.profile

@@ -0,0 +1,81 @@
+SCRIPT  tests/test_plugin/function_in_function_with_ref.vim
+Sourced 1 time
+Total time:   0.000103
+ Self time:   0.000052
+
+count  total (s)   self (s)
+                            " Test for dict function in function (local scope).
+                            "
+                            " This saves a ref to keep profiling information as a workaround for
+                            " https://github.com/vim/vim/issues/2350.
+                            " It causes the inner functions to appear before the outer in the output.
+                            
+    1              0.000011 let g:refs = []
+                            
+    1              0.000005 function! Outer()
+                              function! GetObj()
+                                let obj = {}
+                                function obj.func()
+                                  return 1
+                                endfunction
+                                return obj
+                              endfunction
+                            
+                              let obj = GetObj()
+                              call obj.func()
+                            
+                              let g:refs += [obj]
+                            endfunction
+    1   0.000061   0.000010 call Outer()
+
+FUNCTION  GetObj()
+Called 1 time
+Total time:   0.000014
+ Self time:   0.000014
+
+count  total (s)   self (s)
+    1              0.000004     let obj = {}
+    1              0.000002     function obj.func()
+                                  return 1
+                                endfunction
+    1              0.000002     return obj
+
+FUNCTION  1()
+Called 1 time
+Total time:   0.000003
+ Self time:   0.000003
+
+count  total (s)   self (s)
+    1              0.000002       return 1
+
+FUNCTION  Outer()
+Called 1 time
+Total time:   0.000051
+ Self time:   0.000034
+
+count  total (s)   self (s)
+    1              0.000002   function! GetObj()
+                                let obj = {}
+                                function obj.func()
+                                  return 1
+                                endfunction
+                                return obj
+                              endfunction
+                            
+    1   0.000023   0.000009   let obj = GetObj()
+    1   0.000008   0.000005   call obj.func()
+                            
+    1              0.000005   let g:refs += [obj]
+
+FUNCTIONS SORTED ON TOTAL TIME
+count  total (s)   self (s)  function
+    1   0.000051   0.000034  Outer()
+    1   0.000014             GetObj()
+    1   0.000003             1()
+
+FUNCTIONS SORTED ON SELF TIME
+count  total (s)   self (s)  function
+    1   0.000051   0.000034  Outer()
+    1              0.000014  GetObj()
+    1              0.000003  1()
+

tests/test_main.py

@@ -450,7 +450,7 @@ def test_function_in_function():
         (1, 'call obj.func()')]
 
 
-def test_function_in_function_count():
+def test_function_in_function_count(caplog):
     from covimerage import Profile
 
     fname = 'tests/fixtures/function_in_function_count.profile'
@@ -469,3 +469,53 @@ def test_function_in_function_count():
         (None, '  endfunction'),
         (None, 'endfunction'),
         (1, 'call Outer()')]
+    assert not caplog.records
+
+
+def test_function_in_function_with_ref(caplog):
+    from covimerage import Profile
+
+    fname = 'tests/fixtures/function_in_function_with_ref.profile'
+    p = Profile(fname)
+    p.parse()
+
+    assert len(p.scripts) == 1
+    s = p.scripts[0]
+
+    assert [(l.count, l.line) for l in s.lines.values()
+            if not l.line.startswith('"')] == [
+        (None, ''),
+        (1, 'let g:refs = []'),
+        (None, ''),
+        (1, 'function! Outer()'),
+        (1, '  function! GetObj()'),
+        (1, '    let obj = {}'),
+        (1, '    function obj.func()'),
+        (1, '      return 1'),
+        (None, '    endfunction'),
+        (1, '    return obj'),
+        (None, '  endfunction'),
+        (None, ''),
+        (1, '  let obj = GetObj()'),
+        (1, '  call obj.func()'),
+        (None, ''),
+        (1, '  let g:refs += [obj]'),
+        (None, 'endfunction'),
+        (1, 'call Outer()')]
+
+    assert not caplog.records
+
+
+def test_map_functions(caplog):
+    from covimerage import Function, Profile
+
+    p = Profile('fake')
+
+    p.map_functions([])
+    assert not caplog.records
+
+    funcs = [Function(name='missing')]
+    p.map_functions(funcs)
+    assert len(funcs) == 1
+    assert caplog.record_tuples == [
+        ('covimerage', 40, 'Could not find source for function: missing')]

tests/test_plugin/function_in_function_with_ref.vim

@@ -0,0 +1,23 @@
+" Test for dict function in function (local scope).
+"
+" This saves a ref to keep profiling information as a workaround for
+" https://github.com/vim/vim/issues/2350.
+" It causes the inner functions to appear before the outer in the output.
+
+let g:refs = []
+
+function! Outer()
+  function! GetObj()
+    let obj = {}
+    function obj.func()
+      return 1
+    endfunction
+    return obj
+  endfunction
+
+  let obj = GetObj()
+  call obj.func()
+
+  let g:refs += [obj]
+endfunction
+call Outer()