Bug 1637377 Comment 12 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Original comment by
on 
I finally managed to reproduce the issue with gcc-7 and grizzly.
I added a little more logging in grizzly and here's what I get:
```
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54567 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54599 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54642 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54688 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54735 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54751 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54766 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54778 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54542 (parent)
D grizzly [2020-05-28 11:27:01] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:03] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:04] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:04] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:05] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:06] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:07] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:08] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:09] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:10] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:11] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:12] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:14] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:15] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:16] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:17] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
[popenfile(path='/tmp/ffplogs_kfw271gb/ffp_log_l9spp6c6.txt', fd=1, position=976, mode='w', flags=32769), popenfile(path='/tmp/ffplogs_kfw271gb/ffp_log_omb666ta.txt', fd=2, position=4745, mode='w', flags=32769), popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770)]
W grizzly [2020-05-28 11:27:17] gcda file open by pid 54642 after 15.34s
```
So according to position, process 54642 is waiting for a file lock and for any reason process 54778 is stucked.
Normally , because of https://searchfox.org/mozilla-central/source/tools/code-coverage/CodeCoverageHandler.cpp#47, we shouldn't have two processes (or maybe I'm misunderstanding what `CrossProcessMutexAutoLock` is) trying to flush at the same time: so for now I don't understand how we can be in such a situation.
Revision 1 by
on 
I finally managed to reproduce the issue with gcc-7 and grizzly.
I added a little more logging in grizzly and here's what I get:
```
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54567 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54599 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54642 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54688 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54735 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54751 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54766 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54778 (child)
D grizzly [2020-05-28 11:27:01] Sending SIGUSR1 to 54542 (parent)
D grizzly [2020-05-28 11:27:01] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:02] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:03] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:04] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:04] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:05] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:06] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:07] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:08] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:09] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:10] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:11] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:12] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:14] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:15] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:16] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
D grizzly [2020-05-28 11:27:17] {popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=31, position=0, mode='r+', flags=32770): 54642, popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770): 54778}
[popenfile(path='/tmp/ffplogs_kfw271gb/ffp_log_l9spp6c6.txt', fd=1, position=976, mode='w', flags=32769), popenfile(path='/tmp/ffplogs_kfw271gb/ffp_log_omb666ta.txt', fd=2, position=4745, mode='w', flags=32769), popenfile(path='/home/calixte/dev/mozilla/mozilla-central.hg/obj-x86_64-pc-linux-gnu/dom/html/Unified_cpp_dom_html4.gcda', fd=5, position=80188, mode='r+', flags=32770)]
W grizzly [2020-05-28 11:27:17] gcda file open by pid 54642 after 15.34s
```
So according to position, process 54642 is waiting for a file lock and for any reason process 54778 is stuck.
Normally , because of https://searchfox.org/mozilla-central/source/tools/code-coverage/CodeCoverageHandler.cpp#47, we shouldn't have two processes (or maybe I'm misunderstanding what `CrossProcessMutexAutoLock` is) trying to flush at the same time: so for now I don't understand how we can be in such a situation.

Back to Bug 1637377 Comment 12