Recently when I run the test suite test_cprofile always produces some verbose info but won't fail. This is not the case before. I am not sure this is a bug or not. git bisect tells me https://github.com/python/cpython/commit/5566bbb8d563646d83e8172410fa0c085e8233b1 is responsible. I also see the verbose info on some buildbots.

[cpython]$ ./python -m test test_cprofile
Run tests sequentially
0:00:00 [1/1] test_cprofile
Stats.print_callers output for Profile doesn't fit expectation!
--- 

+++ 

@@ -1,15 +1,16 @@

-profilee.py:110(__getattr__)        <-      16    0.016    0.016  profilee.py:98(subhelper)
-profilee.py:25(testfunc)            <-       1    0.270    1.000  <string>:1(<module>)
-profilee.py:35(factorial)           <-       1    0.014    0.130  profilee.py:25(testfunc)
-                                          20/3    0.130    0.147  profilee.py:35(factorial)
-                                             2    0.006    0.040  profilee.py:84(helper2_indirect)
-profilee.py:48(mul)                 <-      20    0.020    0.020  profilee.py:35(factorial)
-profilee.py:55(helper)              <-       2    0.040    0.600  profilee.py:25(testfunc)
-profilee.py:73(helper1)             <-       4    0.116    0.120  profilee.py:55(helper)
-profilee.py:84(helper2_indirect)    <-       2    0.000    0.140  profilee.py:55(helper)
-profilee.py:88(helper2)             <-       6    0.234    0.300  profilee.py:55(helper)
-                                             2    0.078    0.100  profilee.py:84(helper2_indirect)
-profilee.py:98(subhelper)           <-       8    0.064    0.080  profilee.py:88(helper2)
-{built-in method builtins.hasattr}  <-       4    0.000    0.004  profilee.py:73(helper1)
-                                             8    0.000    0.008  profilee.py:88(helper2)
-{built-in method sys.exc_info}      <-       4    0.000    0.000  profilee.py:73(helper1)
+profilee.py:110(__getattr__)                      <-      16    0.016    0.016  profilee.py:98(subhelper)
+profilee.py:25(testfunc)                          <-       1    0.270    1.000  <string>:1(<module>)
+profilee.py:35(factorial)                         <-       1    0.014    0.130  profilee.py:25(testfunc)
+                                                        20/3    0.130    0.147  profilee.py:35(factorial)
+                                                           2    0.006    0.040  profilee.py:84(helper2_indirect)
+profilee.py:48(mul)                               <-      20    0.020    0.020  profilee.py:35(factorial)
+profilee.py:55(helper)                            <-       2    0.040    0.600  profilee.py:25(testfunc)
+profilee.py:73(helper1)                           <-       4    0.116    0.120  profilee.py:55(helper)
+profilee.py:84(helper2_indirect)                  <-       2    0.000    0.140  profilee.py:55(helper)
+profilee.py:88(helper2)                           <-       6    0.234    0.300  profilee.py:55(helper)
+                                                           2    0.078    0.100  profilee.py:84(helper2_indirect)
+profilee.py:98(subhelper)                         <-       8    0.064    0.080  profilee.py:88(helper2)
+{built-in method builtins.hasattr}                <-       4    0.000    0.004  profilee.py:73(helper1)
+                                                           8    0.000    0.008  profilee.py:88(helper2)
+{built-in method sys.exc_info}                    <-       4    0.000    0.000  profilee.py:73(helper1)
+{method 'append' of 'list' objects}               <-       4    0.000    0.000  profilee.py:73(helper1)
Stats.print_callees output for Profile doesn't fit expectation!
--- 

+++ 

@@ -1,16 +1,16 @@

-<string>:1(<module>)                ->       1    0.270    1.000  profilee.py:25(testfunc)
-profilee.py:110(__getattr__)        ->
-profilee.py:25(testfunc)            ->       1    0.014    0.130  profilee.py:35(factorial)
-                                             2    0.040    0.600  profilee.py:55(helper)
-profilee.py:35(factorial)           ->    20/3    0.130    0.147  profilee.py:35(factorial)
-                                            20    0.020    0.020  profilee.py:48(mul)
-profilee.py:48(mul)                 ->
-profilee.py:55(helper)              ->       4    0.116    0.120  profilee.py:73(helper1)
-                                             2    0.000    0.140  profilee.py:84(helper2_indirect)
-                                             6    0.234    0.300  profilee.py:88(helper2)
-profilee.py:73(helper1)             ->       4    0.000    0.004  {built-in method builtins.hasattr}
-profilee.py:84(helper2_indirect)    ->       2    0.006    0.040  profilee.py:35(factorial)
-                                             2    0.078    0.100  profilee.py:88(helper2)
-profilee.py:88(helper2)             ->       8    0.064    0.080  profilee.py:98(subhelper)
-profilee.py:98(subhelper)           ->      16    0.016    0.016  profilee.py:110(__getattr__)
-{built-in method builtins.hasattr}  ->      12    0.012    0.012  profilee.py:110(__getattr__)
+<string>:1(<module>)                              ->       1    0.270    1.000  profilee.py:25(testfunc)
+profilee.py:110(__getattr__)                      ->
+profilee.py:25(testfunc)                          ->       1    0.014    0.130  profilee.py:35(factorial)
+                                                           2    0.040    0.600  profilee.py:55(helper)
+profilee.py:35(factorial)                         ->    20/3    0.130    0.147  profilee.py:35(factorial)
+                                                          20    0.020    0.020  profilee.py:48(mul)
+profilee.py:48(mul)                               ->
+profilee.py:55(helper)                            ->       4    0.116    0.120  profilee.py:73(helper1)
+                                                           2    0.000    0.140  profilee.py:84(helper2_indirect)
+                                                           6    0.234    0.300  profilee.py:88(helper2)
+profilee.py:73(helper1)                           ->       4    0.000    0.004  {built-in method builtins.hasattr}
+profilee.py:84(helper2_indirect)                  ->       2    0.006    0.040  profilee.py:35(factorial)
+                                                           2    0.078    0.100  profilee.py:88(helper2)
+profilee.py:88(helper2)                           ->       8    0.064    0.080  profilee.py:98(subhelper)
+profilee.py:98(subhelper)                         ->      16    0.016    0.016  profilee.py:110(__getattr__)
+{built-in method builtins.hasattr}                ->      12    0.012    0.012  profilee.py:110(__getattr__)
1 test OK.

Total duration: 73 ms
Tests result: SUCCESS

thanks.
for summary, notable changes are:

(print_callers)
+{method 'append' of 'list' objects}               <-       4    0.000    0.000  profilee.py:73(helper1)
Stats.print_callees output for Profile doesn't fit expectation!

and

(print_callees)
-profilee.py:73(helper1)             ->       4    0.000    0.004  {built-in method builtins.hasattr}
-                                             4    0.000    0.000  {built-in method sys.exc_info}
+profilee.py:73(helper1)                           ->       4    0.000    0.004  {built-in method builtins.hasattr}

OK, now I found what caused this difference.

lsprof expect `func` is PyCFunction object.  But it can be PyMethodDescrObject when LOAD_METHOD is used to call C method.

In Modules/_lsprof.c (line 459):

    case PyTrace_C_CALL:
        if ((((ProfilerObject *)self)->flags & POF_BUILTINS)
            && PyCFunction_Check(arg)) {
            ptrace_enter_call(self,
                              ((PyCFunctionObject *)arg)->m_ml,
                              arg);
        }

Document says just it's "Function object being called."
https://docs.python.org/3.6/c-api/init.html#c.Py_tracefunc

If "function object" means "any C object having tp_call", most easy way to solve this issue is adding PyMethodDescrObject support to lsprof.
PyEval_GetFuncName() and PyEval_GetFuncDesc() should support it too.
As a bonus, `list.append(L, x)` will be profiled like `L.append(x)`.  It looks more consistent.

On the other hand, if it means it's PyCFunction, we can't call PyMethodDescrObject directly.

Since PyEval_SetProfile() is old function, I chose later way for now.

Oh wow, I didn't expect this issue with tracing when the commit 5566bbb8d563646d83e8172410fa0c085e8233b1 was merged: test_sys_settrace and test_lsprof passed. Would it be possible to add an unit test?

Actually the current test produces some noises, but it doesn't fail.

New changeset 93fac8dd358cd0e85e7b59115db226ce685d3f6f by INADA Naoki in branch 'master':
bpo-29676: fix lsprof can't profile C method call. (GH523)
https://github.com/python/cpython/commit/93fac8dd358cd0e85e7b59115db226ce685d3f6f