I removed some lines that say Tracing '/tmp/our-internal-product-stuff/foo'

Coverage is down at the bottom - it looks like it's being skipped. I do see multiprocessing in the list, though. Pure speculation, but that's one of the things I'm investigating to try to repro this in a smaller way.

EDIT I didn't include this at first - but the thing blows up right after the line

Not tracing '/usr/local/lib/python2.7/dist-packages/coverage/collector.py': is part of coverage.py at the end

I've edited the output below to include the stack trace when it blows up

Not tracing '/usr/lib/python2.7/threading.py': is in the stdlib
Tracing '/tmp/tmpKoLMLj/src/app/src/-----/__init__.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/registration.py'
Not tracing '/usr/lib/python2.7/unittest/loader.py': is in the stdlib
Not tracing '/usr/lib/python2.7/functools.py': is in the stdlib
Not tracing '/usr/lib/python2.7/unittest/case.py': is in the stdlib
Not tracing '/usr/lib/python2.7/unittest/suite.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/masterslave.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosunit/core.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/names.py'
Not tracing '/usr/lib/python2.7/posixpath.py': is in the stdlib
Not tracing '/usr/lib/python2.7/genericpath.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/topics.py'
Not tracing '/usr/lib/python2.7/stat.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosunit/xmlrunner.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/tcpros_pubsub.py'
Not tracing '/usr/lib/python2.7/logging/__init__.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/core.py'
Not tracing '/usr/lib/python2.7/urlparse.py': is in the stdlib
Not tracing '<string>': not a real file name
Not tracing '/usr/lib/python2.7/xmlrpclib.py': is in the stdlib
Not tracing '/usr/lib/python2.7/urllib.py': is in the stdlib
Not tracing '/usr/lib/python2.7/string.py': is in the stdlib
Not tracing '/usr/lib/python2.7/httplib.py': is in the stdlib
Not tracing '/usr/lib/python2.7/socket.py': is in the stdlib
Not tracing '/usr/lib/python2.7/unittest/result.py': is in the stdlib
Tracing '/tmp/tmpKoLMLj/src/app/test/integration/test_joint_states_service.py'
Tracing '/root/-----/app/test/integration/test_base.py'
Not tracing '/usr/lib/python2.7/Queue.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/names.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/statistics.py'
Not tracing '/usr/lib/python2.7/mimetools.py': is in the stdlib
Not tracing '/usr/lib/python2.7/rfc822.py': is in the stdlib
Not tracing '/build/python2.7-t6d6Zr/python2.7-2.7.6/Modules/pyexpat.c': pyexpat lies about itself
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/transport.py'
Not tracing '/usr/lib/python2.7/multiprocessing/process.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/client.py'
Not tracing '/usr/lib/python2.7/logging/handlers.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/msproxy.py'
Not tracing '/usr/lib/python2.7/UserDict.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/network.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/rosenv.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/tf2_ros/buffer.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/tf2_ros/buffer_interface.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/masterapi.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/msg.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph_msgs/msg/_Clock.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/genpy/rostime.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/simtime.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/tcpros_service.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/service.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/rostime.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/tf2_ros/transform_listener.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib/action_client.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryAction.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryActionGoal.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/std_msgs/msg/_Header.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib_msgs/msg/_GoalID.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryGoal.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/trajectory_msgs/msg/_JointTrajectory.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryActionResult.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib_msgs/msg/_GoalStatus.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryResult.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryActionFeedback.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/control_msgs/msg/_FollowJointTrajectoryFeedback.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/trajectory_msgs/msg/_JointTrajectoryPoint.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/tf2_msgs/msg/_TFMessage.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_TransformStamped.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Transform.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Vector3.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Quaternion.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/sensor_msgs/msg/_JointState.py'
Not tracing '/usr/lib/python2.7/abc.py': is in the stdlib
Not tracing '/usr/lib/python2.7/_weakrefset.py': is in the stdlib
Not tracing '/usr/lib/python2.7/_abcoll.py': is in the stdlib
Not tracing '/usr/lib/python2.7/SocketServer.py': is in the stdlib
Not tracing '/usr/lib/python2.7/BaseHTTPServer.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Pose.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Point.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Pose2D.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/cv_bridge/core.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/sensor_msgs/msg/_CameraInfo.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/sensor_msgs/msg/_RegionOfInterest.py'
Tracing '/tmp/tmpKoLMLj/src/app/src/app_bringup/params.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/__init__.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/loader.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/reader.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/scanner.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/error.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/tokens.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/parser.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/composer.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/constructor.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/resolver.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/events.py'
Tracing '/usr/local/lib/python2.7/dist-packages/yaml/nodes.py'
Not tracing '/usr/lib/python2.7/SimpleXMLRPCServer.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/validators.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/roslogging.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/impl/rosout.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph_msgs/msg/_Log.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/genpy/message.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslib/packages.py'
Not tracing '/usr/lib/python2.7/dist-packages/rospkg/rospack.py': is in the stdlib
Not tracing '/usr/lib/python2.7/dist-packages/rospkg/environment.py': is in the stdlib
Not tracing '/usr/lib/python2.7/os.py': is in the stdlib
Not tracing '/usr/lib/python2.7/xml/etree/ElementTree.py': is in the stdlib
Not tracing '/usr/lib/python2.7/xml/etree/ElementPath.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/catkin/find_in_workspaces.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/catkin/workspace.py'
Not tracing '/usr/lib/python2.7/dist-packages/catkin_pkg/packages.py': is in the stdlib
Not tracing '/usr/lib/python2.7/dist-packages/catkin_pkg/package.py': is in the stdlib
Not tracing '/usr/lib/python2.7/xml/dom/minidom.py': is in the stdlib
Not tracing '/usr/lib/python2.7/xml/dom/expatbuilder.py': is in the stdlib
Not tracing '/usr/lib/python2.7/StringIO.py': is in the stdlib
Not tracing '/usr/lib/python2.7/copy.py': is in the stdlib
Not tracing '/usr/lib/python2.7/copy_reg.py': is in the stdlib
Not tracing '/usr/lib/python2.7/re.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/rlutil.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/parent.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/config.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/core.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/xmlloader.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/loader.py'
Not tracing '/usr/lib/python2.7/shlex.py': is in the stdlib
Not tracing '/usr/lib/python2.7/subprocess.py': is in the stdlib
Not tracing '/usr/lib/python2.7/platform.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/pmon.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/server.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rosgraph/xmlrpc.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/launch.py'
Not tracing '/usr/lib/python2.7/gzip.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/nodeprocess.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/node_args.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslaunch/substitution_args.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/roslib/__init__.py'
Not tracing '/usr/lib/python2.7/atexit.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/std_msgs/msg/_String.py'
Not tracing '/usr/lib/python2.7/shutil.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/std_msgs/msg/_Empty.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/geometry_msgs/msg/_Twist.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib/simple_action_server.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib/server_goal_handle.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib/action_server.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib/goal_id_generator.py'
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/actionlib_msgs/msg/_GoalStatusArray.py'
Not tracing '/usr/local/lib/python2.7/dist-packages/coverage/control.py': is part of coverage.py
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rospy/timer.py'
Not tracing '/usr/lib/python2.7/traceback.py': is in the stdlib
Not tracing '/usr/lib/python2.7/linecache.py': is in the stdlib
Not tracing '/usr/lib/python2.7/unittest/util.py': is in the stdlib
Tracing '/opt/ros/indigo/lib/python2.7/dist-packages/rostest/__init__.py'
Not tracing '/usr/local/lib/python2.7/dist-packages/coverage/collector.py': is part of coverage.py
Traceback (most recent call last):
File "/tmp/tmpE4nq9m/src/app/test/integration/test_bagfile_recorder.py", line 83, in <module>
main()
File "/tmp/tmpE4nq9m/src/app/test/integration/test_bagfile_recorder.py", line 79, in main
rostest.rosrun(PKG, NAME, TestBagfileRecorder)
File "/opt/ros/indigo/lib/python2.7/dist-packages/rostest/__init__.py", line 148, in rosrun
_stop_coverage([package])
File "/opt/ros/indigo/lib/python2.7/dist-packages/rostest/__init__.py", line 228, in _stop_coverage
_cov.stop()
File "/usr/local/lib/python2.7/dist-packages/coverage/control.py", line 919, in analysis
f, s, _, m, mf = self.analysis2(morf)
File "/usr/local/lib/python2.7/dist-packages/coverage/control.py", line 940, in analysis2
analysis = self._analyze(morf)
File "/usr/local/lib/python2.7/dist-packages/coverage/control.py", line 955, in _analyze
self.get_data()
File "/usr/local/lib/python2.7/dist-packages/coverage/control.py", line 824, in get_data
if self.collector.save_data(self.data):
File "/usr/local/lib/python2.7/dist-packages/coverage/collector.py", line 382, in save_data
covdata.add_lines(abs_file_dict(self.data))
File "/usr/local/lib/python2.7/dist-packages/coverage/collector.py", line 377, in abs_file_dict
return dict((abs_file(k), v) for k, v in iitems(d))
File "/usr/local/lib/python2.7/dist-packages/coverage/collector.py", line 377, in <genexpr>
return dict((abs_file(k), v) for k, v in iitems(d))
RuntimeError: dictionary changed size during iteration

I'm taking my repro-case and cutting it down binary search style. I'm noticing that as I remove more stuff, the likelyhood that coverage blows up is going down. With everything in there, I can get it to blow up every time. With about half of the stuff removed, it's now to the point where it'll blow up about 1 in 3 times.

These all seem like legit files that might be getting coverage generated for them. There's also approx 22 python threads hanging around, most of them waiting to publish or receive something on a socket.

I don't think this is ROS specific - but using the ROS messages was a convenient way to quickly generate a very large list of modules and class names to import.

I think I can give you instructions to fully repro the issue using a docker container that has the ROS stuff in it. Again, I don't believe that ROS is necessary - it's just a convenient way for me to generate a large list of things to import.

Here is the program I'm using right now to reproduce the problem without the importlist:

_cov=None_run=Truedef_start_coverage():global_covimportcoverage_cov=coverage.coverage()_cov.start()def_stop_coverage():_cov.stop()print"YOU WILL NEVER GET HERE"# Mega strange. When the program blows up, it reports that _cov.stop() blows up.# The thing is, I see "YOU WILL NEVER GET HERE" printed to the console. Also the# program doesn't blow up without _cov.save()_cov.save()defrandom_load():global_runglobalimportlistwhile_run:candidate=random.choice(importlist)mod=importlib.import_module(candidate[0])# cls = getattr(mod, candidate[1]) # Not needed for repro_start_coverage()forninrange(20):tr=threading.Thread(target=random_load)tr.start()time.sleep(0.1)_stop_coverage()_run=False

repro.py is attached to this issue.
Steps to reproduce using a docker container are below. The ros-indigo-ros-base docker image is used because it contains already all of the classes that are imported to repro the issue. I believe it is possible to reproduce this issue without ROS, too, but do not have a good way of generating a big list of imports without ROS being installed:

@Peter Baughman Thanks so much for the test case, I am able to reproduce it. And it's nothing to do with your code. I replaced your imports with some synthetic ones, and could still cause the failure. This program does it without needing Docker, etc:

importimportlibimportrandomimportthreadingimporttime_cov=None_run=Trueforiinxrange(1000):withopen("m{:04d}.py".format(i),"w")asf:f.write("a = 1\n")def_start_coverage():global_covimportcoverage_cov=coverage.coverage()_cov.start()def_stop_coverage():_cov.stop()print"YOU WILL NEVER GET HERE!!"# Mega strange. When the program blows up, it reports that _cov.stop() blows up.# The thing is, I see "YOU WILL NEVER GET HERE" printed to the console. Also the# program doesn't blow up without _cov.save()_cov.save()defrandom_load():global_runwhile_run:candidate="m{:04d}".format(random.randint(0,999))mod=importlib.import_module(candidate)_start_coverage()forninrange(20):threading.Thread(target=random_load).start()time.sleep(0.1)_stop_coverage()_run=False

@Peter Baughman I did some work to investigate fixes, but got sidetracked. Copying the data dictionary makes the problem less likely, but does not fix it robustly. I'm sorry to say this, but for the time being, you should run with your fix from a fork of coverage.py.

I updated the minimal repro script to work in Python 3 with the print function and could therefore enable flush=True and I can see the print function output on stdout:

from__future__importprint_functionimportimportlibimportrandomimportthreadingimporttime_cov=None_run=Trueforiinrange(1000):withopen("m{:04d}.py".format(i),"w")asf:f.write("a = 1\n")def_start_coverage():global_covimportcoverage_cov=coverage.coverage()_cov.start()def_stop_coverage():_cov.stop()print("YOU WILL NEVER GET HERE!!",flush=True)# Mega strange. When the program blows up, it reports that _cov.stop() blows up.# The thing is, I see "YOU WILL NEVER GET HERE" printed to the console. Also the# program doesn't blow up without _cov.save()_cov.save()defrandom_load():global_runwhile_run:candidate="m{:04d}".format(random.randint(0,999))mod=importlib.import_module(candidate)_start_coverage()forninrange(20):threading.Thread(target=random_load).start()time.sleep(0.1)_stop_coverage()_run=False

I get the following output:

YOU WILL NEVER GET HERE!!
Traceback (most recent call last):
File "coverage_bug.py", line 38, in <module>
_stop_coverage()
File "coverage_bug.py", line 21, in _stop_coverage
_cov.stop()
File "/volatile/ogrisel/code/coveragepy/coverage/control.py", line 772, in save
self.get_data()
File "/volatile/ogrisel/code/coveragepy/coverage/control.py", line 824, in get_data
if self.collector.save_data(self.data):
File "/volatile/ogrisel/code/coveragepy/coverage/collector.py", line 382, in save_data
covdata.add_lines(abs_file_dict(self.data))
File "/volatile/ogrisel/code/coveragepy/coverage/collector.py", line 377, in abs_file_dict
return dict((abs_file(k), v) for k, v in iitems(d))
File "/volatile/ogrisel/code/coveragepy/coverage/collector.py", line 377, in <genexpr>
return dict((abs_file(k), v) for k, v in iitems(d))
RuntimeError: dictionary changed size during iteration

and then the program is waiting indefinitely (since the _run flag is never set to False).

I will have to get back to this soon. I am not just adding a list() call for a few reasons: first, it doesn't solve the race condition, it just narrows the window from the time to execute the entire line to the time to execute the list(). Adding a lock around this line might be a solution, but I think there's also technically a race condition in the trace function where we add keys to the data dictionary in the first place. That is an even narrower window for problems, but at least at an academic level, is still a problem. Locking on every line recorded doesn't seem feasible.

At the very least, I'd like to understand the scope of the problem before adding this simple pragmatic 99% solution.

<del>I think the fundamental problem comes from the fact that threading.settrace can only be used to enable tracing on future threads and cannot be used to enable or disable tracing on running threads.</del> Actually I am reading the source code of the PyTracer class and the stopped flag should be able to deal with this constraint.

The thread-safety of list() is something to consider. I don't understand your point about past vs future threads? I thought the problem here was one thread recording data into the shared dictionary while another thread was trying to save the data?

The traceback is about an exception in the main thread in the _cov.stop() call (in the _stop_coverage() function) while the print statement has already printed the "YOU WILL NEVER GET HERE!!" message which should only happen after the call to _cov.stop() based on the source code of the script...