Executed lines reported as missing in threads

[nedbat]

Originally reported by k3it (Bitbucket: k3it, GitHub: k3it)

---

I apologize for a cross post from http://stackoverflow.com/q/43991865/1653558 but it looks like this is a better place for the report

I'm getting some low coverage numbers on script with threads activated with a run() method. It seems that the coverage module is unable to keep track of all hits. Here is the code that demonstrates the problem. Running it should produce 100% coverage, but I'm getting 71.

#!python

from threading import Thread

class MyNestedThread(Thread):
        def run(self):
                print("hello from the nested thread!")

class MyThread(Thread):
        def run(self):
                print("Hello from thread")
                t = MyNestedThread()
                t.start()
                return

if __name__ == '__main__':
        for i in range(3):
                t = MyThread()
                t.start()

#!python


Hello from thread
hello from the nested thread!
Hello from thread
Hello from thread
hello from the nested thread!
hello from the nested thread!

Name     Stmts   Miss  Cover
----------------------------
foo.py      14      4    71%

re-running 'coverage run foo.py' sometimes gives a different %, and even 100% on occasion.

---

• Bitbucket: https://bitbucket.org/ned/coveragepy/issue/582

[nedbat]

Thanks for writing this up. When I run your code with Python 3.6, and coverage.py 4.4.1, I get 100% every time. Can you give me some details of your environment? The output of "coverage debug sys" will have information. Also, can you run "coverage report -m" to show what lines are being missed?

Thanks.

[nedbat]

Original comment by k3it (Bitbucket: k3it, GitHub: k3it)

---

#!shell

version: 4.4
python: 3.5.3 (v3.5.3:1880cb95a742, Jan 16 2017, 15:51:26) [MSC v.1900 32 bit (Intel)]
platform: Windows-7-6.1.7601-SP1
implementation: CPython

#!python

Name     Stmts   Miss  Cover   Missing
--------------------------------------
foo.py      14      4    71%   5, 10-12

I'm also getting missing coverage when deploying a python 3.5 project to Travis CI, which is linux based. so this does not look like a windows issue. I have not checked other releases of Python yet

[nedbat]

I'm sorry, I cannot reproduce what you are seeing. Can you provide a link to the failing travis builds?

[nedbat]

Original comment by k3it (Bitbucket: k3it, GitHub: k3it)

---

Hi Ned
Here is the travis build that does not cover the run() method in recording_loop(QThread) class. This method definitely runs many times during travis tests
https://travis-ci.org/k3it/qsorder/jobs/233002450
(note 51% coverage for qsorder.py, but it should be higher)
source repo: https://github.com/k3it/qsorder/tree/qtgui

coverage report
https://coveralls.io/builds/11518328/source?filename=pyQsorder%2Fqsorder.py#L622

you are right. it seems that in some environments the issue does not exist. but I don't see what triggers it.

[nedbat]

Original comment by Will S (Bitbucket: wsha, GitHub: wsha)

---

I came across this ticket searching for information on using coverage.py with Qt's QThreads and PyQt (nothing else really came up). I think a QThread is totally different from a Python Thread because QThread is a Qt C++ class that PyQt is binding (but I haven't tried to understand how PyQt runs Python code from different QThreads). So I think the qsorder coverage issue is different from the example in the opening post.

I am guessing there is no easy way for coverage.py to track code run in QThreads? Workarounds (for me) would be to refactor the application to have a single threaded testing mode or to use function-level tests for the functions that get run from QThreads.

[hhslepicka]

Hi @nedbat, I am facing the same issue as the previous comment.
Do you have news on the coverage for code in QThreads?
Thanks!

[nedbat]

@hhslepicka I don't have a way to reproduce the problem. Can you provide me with instructions? I need specific code, environment (OS, versions, etc), and step-by-step instructions.

[hhslepicka]

@nedbat I will prepare and send you a link. Thank you for your attention.

[hhslepicka]

@nedbat here is a gist file for the test:
https://gist.github.com/hhslepicka/3153c9c2ac27dee4398754dce6a11fea

Environment:

• macOS High Sierra - 10.13.5
• Tested with Python 2.7 and 3.6 (Anaconda)
• Coverage: 4.5.1 with C extension

Dependencies:

• Python 2.7 or 3.6 (I tested with both)
• PyQt5 & Qt5... any version...

Some useful information:

(py36) slepicka@public-81-101:~/sandbox/covtest  $ coverage --version
Coverage.py, version 4.5.1 with C extension
Documentation at https://coverage.readthedocs.io

(py36) slepicka@dhcp-swlan-public-81-101:~/sandbox/covtest  $ coverage run test.py
Counter:  56
(py36) slepicka@dhcp-swlan-public-81-101:~/sandbox/covtest  $ coverage report -m
Name      Stmts   Miss  Cover   Missing
---------------------------------------
test.py      24      4    83%   13-15, 18

Documentation for QThread in case it is useful: http://doc.qt.io/qt-5/qthread.html

Just let me know if you need additional info from my system.

[nedbat]

Thanks, this reproduces the issue. I have to learn more about what tools are available in Qt for hooking the creation of threads to enable coverage. Do you have any idea?

[nedbat]

BTW, this is the content of the gist:

import time

from PyQt5.QtCore import QThread


class Worker(QThread):

    def __init__(self):
        QThread.__init__(self)
        self.counter = 0

    def run(self):
        while not self.isInterruptionRequested():
            self.calculate()
            self.msleep(33) # 30Hz

    def calculate(self):
        self.counter += 1


def main():
    w = Worker()
    w.start()
    assert w.isRunning()
    time.sleep(2)    
    w.requestInterruption()
    w.wait()
    assert w.isFinished()
    assert w.counter > 0
    print("Counter: ", w.counter)


if __name__ == "__main__":
    main()

[nedbat]

Asked on the PyQt list: Any way to run code before each QThread?.

From there: an example of monkey-patching QThread to add debugging support: http://die-offenbachs.homelinux.org:48888/hg/eric/file/87b1626eb49b/DebugClients/Python/ThreadExtension.py#l361

[hhslepicka]

Thank you for the follow up @nedbat .
Do you need help adding it to coverage or at least testing?

[nedbat]

@hhslepicka I haven't tried this at all. I think the best approach would be to write a plugin for coverage that would apply the QThread monkeypatch at startup. Is that something you can take a stab at?

[hhslepicka]

@nedbat sure! I will take a look at that... do you happen to have some sort of guide/docs/sample for me to take a look?

[hhslepicka]

Found it in here: https://coverage.readthedocs.io/en/latest/api_plugin.html#api-plugin

[nedbat]

@hhslepicka Right. This is an unusual use case, since you don't need any events, just some code to run at startup. BTW: i'd like to make plugins use real entry points so that users can just install them without having to change their configuration file, but that is in the future.

Let me know if you make any progress on it.

[hhslepicka]

@nedbat sounds good! I will send an update next week...

[k3it]

Hello @nedbat
I just ran the original provided in the very first post and it produced 86% coverage. On the second attempt I got 100%. After a few more attempts the coverage went back to 86.

C:\temp>coverage run foo.py
Hello from thread
Hello from thread
hello from the nested thread!
Hello from thread
hello from the nested thread!
hello from the nested thread!

C:\temp>coverage report
Name     Stmts   Miss  Cover
----------------------------
foo.py      14      0   100%

C:\temp>coverage run foo.py
Hello from thread
Hello from thread
Hello from thread
hello from the nested thread!
hello from the nested thread!
hello from the nested thread!

C:\temp>coverage report
Name     Stmts   Miss  Cover
----------------------------
foo.py      14      2    86%

the problem seems to be reproducible here without adding the complexity of QT. Please let me know if can do anything to help debug.

[nedbat]

@k3it Thanks, but it still doesn't happen for me. I am on Mac 10.13.6, with Python 3.6.6, and coverage 4.5.1. How are you running it?

[k3it]

this time it was under anaconda virtual env on windows 10

Python 3.6.5 :: Anaconda, Inc.
coverage==4.5.1

[nedbat]

@k3it can you show the output of "coverage report -m" so we can see what lines are missed?

[k3it]

foo.py 14 2 86% 7, 14

also here is the annotated file

#!python
  
> from threading import Thread
  
> class MyNestedThread(Thread):
>         def run(self):
!                 print("hello from the nested thread!")
  
> class MyThread(Thread):
>         def run(self):
>                 print("Hello from thread")
>                 t = MyNestedThread()
>                 t.start()
!                 return
  
> if __name__ == '__main__':
>         for i in range(3):
>                 t = MyThread()
>                 t.start()

[nedbat]

@hhslepicka Would you do me a favor and write a new issue about the QThread problem? it's clearly separate from the original report here.

[hhslepicka]

Sure! 👍

…

On Thu, Jul 26, 2018 at 6:39 PM Ned Batchelder ***@***.***> wrote: @hhslepicka <https://github.com/hhslepicka> Would you do me a favor and write a new issue about the QThread problem? it's clearly separate from the original report here. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#582 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHzmUS4Yyr_N4VryeqMp8YHX5iAmn1XCks5uKm9AgaJpZM4VMGfA> .

[k3it]

The original issue I ran into was with QT threads coverage just like @hhslepicka . they must be at least related.. :)

I noticed that missed lines are reported when the parent "main" threads finish first, followed by the three "nested" threads.. But if at least one nested thread gets a chance to run ahead of the main thread, then the coverage is correct. ie it is very timing dependent. seems like a non thread safe structure is being overwritten somewhere.

Edit: adding a time.sleep(0.1) before "hello from the nested thread" makes coverage miss at least one line on every run

[hhslepicka]

@k3it, is there any reason why you can’t .join the Threads and only finish execution when they all finish?

…

On Thu, Jul 26, 2018 at 8:35 PM k3it ***@***.***> wrote: The original issue I ran into was with QT threads coverage just like @hhslepicka <https://github.com/hhslepicka> . they must be at least related.. :) I noticed that missed lines are reported when the parent "main" threads finish first, followed by the three "nested" threads.. But if at least one nested thread gets a chance to run ahead of the main thread, then the coverage is correct. ie it is very timing dependent. seems like a non thread safe structure is being overwritten somewhere. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#582 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHzmUVGrxSy_hSRADa5_JIy04KDtRr3lks5uKop2gaJpZM4VMGfA> .

[nedbat]

@k3it The QThread issue is that measurement is never started on QThreads. You can see that all of the lines that run in the thread are reported as missing. That problem is easily reproduced.

The original problem looks like a race condition, since it appears differently even for different runs by the same person. I don't understand exactly what is going wrong, but it does seem like joining the threads to remove race conditions might fix it. Can you give that a try?

[k3it]

not sure if I can use join. would join serialize execution and make the parent thread block?
the parent should be able to dispatch new threads and "forget" about them.

wonder if adding time.sleep as above makes the problem reproducible on your mac.

[nedbat]

@k3it Adding the sleep does show the problem, but adding join() fixes the problem. I'm using this code:

#!python

import time
from threading import Thread

class MyNestedThread(Thread):
        def run(self):
                time.sleep(.1)
                print("hello from the nested thread!")

class MyThread(Thread):
        def run(self):
                print("Hello from thread")
                t = MyNestedThread()
                t.start()
                t.join()
                return

if __name__ == '__main__':
        ts = [MyThread() for _ in range(3)]
        for t in ts:
            t.start()
        for t in ts:
            t.join()

I think starting threads and not joining them is a mistake: it causes a race condition that makes it impossible to know that the thread has completed.

[k3it]

I don't believe not using join is a mistake . in the real code "MyThread" monitors for an external event (arrival of a particular UDP packet) and dispatches a child thread for execution. The child thread then lives its own life. The next trigger for a new thread may and does often arrive before the previous child thread(s) have finished running. Putting a join there would totally break this logic. I believe join is used when threads have some sort of dependency and need to be serialized, but it's not the case here.

[nedbat]

OK. Another way to fix the problem is to add time.sleep(3) to the very end of the main clause. What in your program is ensuring that all of the worker threads have completely finished before the main program ends?

[k3it]

@nedbat this program runs in a loop and never exists, until keyboard interrupted or killed. Any remaining worker thread would die with the main process in that case. Each worker usually runs for 45 seconds and there could be more than one running at the same time. They are scheduled with the python thread Timer mechanism. but I don't mean to distract with the discussion of what my code does :). I was just thinking this problem may help with resolving some type of thread safety issue within coverall...

[nedbat]

@k3it I'm not trying to pester you about how your code works. I'm trying to understand the heart of the problem. So I have to ask you more about the code in which you've experienced the problem. Coverage only writes its data at the exit of the program. But your program never exits. How are you recording the coverage?

[k3it]

@nedbat at the end of each unit tests a special 'deadbeef' UDP packet is being sent which makes the main thread (and the whole program) exit instead of spawning another child thread. I think the code boils down to the example posted here if you remove all of the non-relevant parts ..

[nedbat]

@k3it I see, thanks. It sounds like you have a race condition: when the UDP packet arrives, the main program is ending before the worker thread is completely finished. Can you add synchronization to ensure that doesn't happen?

[k3it]

the main program is ending before the worker thread is completely finished

It's possible for MyThread to exit before MyNestedThread but it's not possible for the entire program to quit with some thread still hanging out there, since threads are part of the main process

In the QT app I'm calling QCoreApplication::Quit method which I believe waits for all threads to exit.

[nedbat]

@k3it the examples you showed earlier were not using QT. But it sounds like your real application is? If you could give me a reproducible example that we can agree on, it would make this a lot easier.

[nedbat]

If this is still a problem, and you can provide more information, feel free to re-open the issue.

[JannisNe]

Hi, I found this thread when looking for a solution to a problem I wrote up here.

I am also having trouble measuring coverage in threads. I do join() my threads as suggested in this thread so that does not seem to be the problem. You can see the link above for additional info on the environment. I'd be grateful for any help!

[nedbat]

Threads won't be measured unless you specify them as part of your concurrency setting:

concurrency = multiprocessing,thread