[New-bugs-announce] [issue29676] verbose output of test_cprofile

Xiang Zhang report at bugs.python.org
Tue Feb 28 06:34:24 EST 2017


New submission from Xiang Zhang:

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

----------
components: Tests
messages: 288707
nosy: inada.naoki, xiang.zhang
priority: normal
severity: normal
status: open
title: verbose output of test_cprofile
type: behavior
versions: Python 3.7

_______________________________________
Python tracker <report at bugs.python.org>
<http://bugs.python.org/issue29676>
_______________________________________


More information about the New-bugs-announce mailing list