Repository navigation
Incorrect coverage file from trace test_pickle.py #53563
Description
Activity
I am running the following command
$ python -m trace -C pickle-trace.d -c -m Lib/test/test_pickle.py
and getting attached file, pickle.cover, in the pickle-trace.d directory. This does not look right. From the very beginning, module level statements are marked as not executed:
>>>>>> __version__ = "$Revision: 82937 $" # Code version >>>>>> from types import FunctionType, BuiltinFunctionType >>>>>> from copyreg import dispatch_table >>>>>> from copyreg import _extension_registry, _inverted_registry, _extension_cache >>>>>> import marshal >>>>>> import sysThe method I was interested in, _instantiate, shows as if it was never executed even though if I add a failing assert, I do see test failure.
I suspect that this may have something to do with the import trickery that test_pickle does to test with and without _pickle.
- addedstdlibStandard Library Python modules in the Lib/ directoryStandard Library Python modules in the Lib/ directorytype-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error
on Jul 21, 2010 Does the trace module even work in 3.x?
I created attached trivial traceme.py file.
With python 2.7, I get
$ python2 -m trace -c -s traceme.py
lines cov% module (path)
1 100% threading (Lib/threading.py)
6 100% traceme (traceme.py)The first entry is clearly spurious, but traceme looks right. With py3k, however, I get
$ python3 -m trace -c -s traceme.py lines cov% module (path) 1 100% threading (Lib/threading.py)No traceme line at all.
Even the following simple test file:
----------------------
import pickle data = {'a' : [1, 2, 3], 'b': 5} ps = pickle.dumps(data) newdata = pickle.loads(ps) print(newdata)
When traced generates an empty trace file for the pickle module, so it's not test_pickle trickery, but rather something to do with the pickle module itself. Will investigate this further.
I didn't hit refresh before posting so didn't see your message, Alexander. The problem indeed seems to be deeper.
On Tue, Jul 20, 2010 at 11:28 PM, Eli Bendersky <report@bugs.python.org> wrote:
The problem indeed seems to be deeper.
.. or shallower. :-)
Here is another problem: with no file x in cwd,
$ ./python.exe -m trace -c -f x traceme.py Skipping counts file 'x': [Errno 2] No such file or directory: 'x'
This one seems to exist in both 2.7 and 3.x. Creating empty counts file helps.
Comparison of count files produced by 2.7 and 3.x suggests that the problem is in finding the source file for the module:
>>> pickle.load(open('x', 'rb')) ({('<string>', 2): 2, ('<string>', 1): 4, ('<string>', 8): 20, .. >>> pickle.load(open('y', 'rb')) ({('traceme.py', 1): 2, ('traceme.py', 2): 2, ('<string>', 1): 2, ('traceme.py', 8): 20, ..
In the above, x was produced by 3.x and y by 2.7.
trace.py uses settrace to do its heavy lifting. In the "local trace" function for counting, localtrace_count:
def localtrace_count(self, frame, why, arg): if why == "line": filename = frame.f_code.co_filename lineno = frame.f_lineno key = filename, lineno self.counts[key] = self.counts.get(key, 0) + 1 return self.localtrace
The line "filename = frame.f_code.co_filename" seems to work as expected in 2.x for the current file, returning its name. In 3.x it returns '<string>' for the current file.
This causes the trace module to filter out the results for the current file (traceme.py in Alexander's example).
I'm investigating further, but this may very well be caused by different behavior of
f_code.co_filenamebetween Python 2 and 3.On Wed, Jul 21, 2010 at 12:13 AM, Eli Bendersky report@bugs.python.org wrote:
..I'm investigating further, but this may very well be caused by different behavior
off_code.co_filenamebetween Python 2 and 3.I am afraid I am a step ahead of you. The culprit is
t.run('exec(%r)' % (script,))line in 3.x instead of
t.run('execfile(%r)' % (progname,))in 2.x
I am attaching a proof-of-concept patch, bpo-9317.diff, which fixes the file name problem at the expense of more spurious modules:
$ ./python.exe -m trace -c -s traceme.py lines cov% module (path) 7 100% codecs (Lib/codecs.py) 10 100% locale (Lib/locale.py) 4 100% pkgutil (Lib/pkgutil.py) 58 100% runpy (Lib/runpy.py) 6 100% traceme (traceme.py)Alexander,
I propose an alternative patch (attached bpo-9317.2.diff). It uses:
with open(progname) as fp: code = compile(fp.read(), progname, 'exec') t.run(code)
Since the
runmethod of Trace already accepts a code object and passes it toexec, I see no reason to do anotherexec.This also fixes your 'traceme' problem, without introducing new module imports:
$ py3d -m trace -c -s traceme.py lines cov% module (path) 1 100% threading (/home/eliben/python_src/eliben-py3k/Lib/threading.py) 6 100% traceme (traceme.py) [47526 refs]AlexanderBelopolsky commented
on Jul 21, 2010 AlexanderBelopolskymannequinMannequinMore actionsEli,
Your new patch makes perfect sense, but can you check of regular
python invocation uses runpy these days. If it does, it may make sense
to include it in trace at least optionally.Also, does this fix the original problem?
<<<<
Your new patch makes perfect sense, but can you check of regular
python invocation uses runpy these days. If it does, it may make sense
to include it in trace at least optionally.>>>
I'm not sure I understand what you mean by this. Could you please clarify?
<<<<
Also, does this fix the original problem?>>>
Alas, no.
AlexanderBelopolsky commented
on Jul 21, 2010 AlexanderBelopolskymannequinMannequinMore actionsOn Jul 21, 2010, at 9:22 AM, Eli Bendersky <report@bugs.python.org>
wrote:Eli Bendersky <eliben@gmail.com> added the comment:
<<<<
Your new patch makes perfect sense, but can you check of regular
python invocation uses runpy these days. If it does, it may make sense
to include it in trace at least optionally.
>>>>I'm not sure I understand what you mean by this. Could you please
clarify?Sorry, typing on the phone. s/of/if/ in my message above. What I mean
is that as far as I know, when you run a script from command line,
python loads it using functions in runpy. Arguably this means that
these functions should show up in coverage.Sorry, typing on the phone. s/of/if/ in my message above. What I mean
is that as far as I know, when you run a script from command line,
python loads it using functions in runpy. Arguably this means that
these functions should show up in coverage.As far as I understand, when you run:
py3d -m trace -C pickle-trace.d -c -m test_pickle.pyThe first -m flag applies to the trace module. Python uses
runpy.run_module to load it, and then passes it its arguments (-C and
onwards).Since runpy.run_module actually runs /before/ trace.py, trace.py has
no chance of setting its settrace hooks and trace runpy itself.Moreover, since runpy is only the machinery to execute trace.py, does
it even make sense to include it in coverage?What do you think?
AlexanderBelopolsky commented
on Jul 21, 2010 AlexanderBelopolskymannequinMannequinMore actionsOn Wed, Jul 21, 2010 at 9:45 AM, Eli Bendersky <report@bugs.python.org> wrote:
..As far as I understand, when you run:
py3d -m trace -C pickle-trace.d -c -m test_pickle.py
The first -m flag applies to the trace module. Python uses
runpy.run_module to load it, and then passes it its arguments (-C and
onwards).When I said "run from command line", I meant something like
$ python Lib/test/test_pickle.py
I am not sure if this uses runpy machinery, but I suspect it does.
The trace output should not include runpy calls that load the trace
module itself, but$ python -m trace <flags> Lib/test/test_pickle.py
might show the runpy calls that occur when you run
$ python Lib/test/test_pickle.py
without tracing. BTW, too bad that '-m' is taken, but I think
trace.py should grow a --run-module option so that you can trace
equivalents of python -m executions:$ python -m trace <flags> --run-module test.test_pickle
Moreover, since runpy is only the machinery to execute trace.py, does
it even make sense to include it in coverage?What do you think?
I think you should ask python-dev. :-) Note that most C/C++ coverage
tools do include pre-main calls in coverage. In case of C++, a lot
of things may happen before main().Whatever the solution is, it should be unified between trace, profile,
and pdb modules.Eli,
At this point, I think it will be best to focus on unittests. I am adding bpo-9315 as a dependency here and will add a comment there. I think once we have good unittest coverage the bug will become obvious.
Also, when you get a chance, please separate the __main__ coverage bug into a separate issue and bring it up on python-dev. We should get profile guys involved and I don't want them to be distracted by trace specific issues.
I have verified that the original issue is still present. I will try to narrow it down to a smaller test case.
I have found the cause of at least part of the issue. Apparently, module level statements for some of the modules such as pickle do not show up in trace because they are imported by trace itself. In other words, by the time traced script gets executed, pickle is already in sys.module and the code therein does not run.
Maybe we should consider clearing sys.modules in Trace.run, but this can cause problems if not done carefully.
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
bugs.python.org fields: