1376143 - launching Nightly 56.0a1 (2017-06-23) (64-bit) on OS X 10.11.6 (15G1510) causes opendirectoryd and automountd to spin

Status: RESOLVED DUPLICATE of bug 1383841

(Firefox :: Untriaged, defect)

Description

[Michael Froman [:mjf]]

Opendirectoryd spins at about 57%, automountd spins at about 22% for some amount of time after launch under 10.11.6.  They immediately respawn if killed, and resume their workload.  I'll remeasure how long it lasts on the next launch.  This does not happen with release Firefox.

It does _not_ seem to happen under 10.12.5.

Comment 1

[Michael Froman [:mjf]]

Quitting Nightly doesn't cause the problem to go away, and logging out and logging back in does not cause the problem to go away.  This past run they've been spinning 10+ minutes.

Comment 2

[Cosmin Muntean [:cmuntean], Ecosystem QA]

User Agent  Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:56.0) Gecko/20100101 Firefox/56.0

I have managed to reproduce this issue on latest Nightly (56.0a1) build on Mac Os 10.11.6 and also on 10.10.5. After opening the Nightly browser the "opendirectoryd" process spins at ~55% and also the "automountd" process at ~22%. 
This issue is not reproducible on Mac Os 10.12.

Considering the fact that the issue is not reproducible on older Nightly builds, I have performed a regression using the mozregression tools . Here are the results:

Last good revision: 92eb911c35da48907d326604c4c92cf55e551895
First bad revision: 5456e68aafc268021815d220ad75ae304d4bd744
Pushlog: https://goo.gl/4RaqMY

Justin, can you please take a look at this issue? Is there a chance that one of the issues from the provided pusholg, caused this regression?
Also, do you know which component is more appropriate for this issue?

Comment 3

[Justin Wood (:Callek)]

This sounds very familiar. Mike?

Comment 4

[Michael Shal [:mshal]]

This is due to switching over to cross-OSX Taskcluster builds for nightly. The cross builds are built in a directory under /home, which for some odd reason causes automountd to spam searches like this:

Jun 28 15:40:49 t-yosemite-r7-0009.test.releng.scl3.mozilla.com automountd[895]: od_search for worker in auto_home failed
Jun 28 15:40:49 t-yosemite-r7-0009.test.releng.scl3.mozilla.com automountd[895]: od_search for * in auto_home failed

(I counted ~15k of these searches during a talos run.)

The activity does persist after firefox is closed, but on our test machines it dies down a few minutes later.

We're changing the path on the builders in bug 1338651, which should make this problem go away. Please re-test after that bug lands and confirm that it is no longer an issue.

Comment 5

[Michael Froman [:mjf]]

FYI: I just saw this behavior on my OS X laptop running 10.12.5.  It doesn't happen at every launch though.

Comment 6

[Eiichi]

I've just updated macOS Sierra 10.12.6, and this issue happens at every launch using latest Nightly 56.0a1.

Comment 7

[Eiichi]

I noticed that setting security.sandbox.content.level=0 fixed this issue.

Comment 8

[Mike Conley (:mconley) (:⚙️)]

ni?ing bobowen since this sounds at least tangentially sandbox related due to comment 7?

Comment 9

[Eiichi]

I tested with Firefox 56.0a1 (2017-07-20);
- security.sandbox.content.level=3 (default)
- security.sandbox.logging.enabled=false
This produces the same results.

Comment 10

[Haik Aftandilian [:haik]]

I'm looking at this, but haven't been able to reproduce it yet on 10.12. I'll test on 10.11.

mjf, could you clarify what you're seeing? I'm launching Nightly and looking at "top -o cpu" and Activity Monitor. So far, I haven't seen the spikes.

Comment 11

[Haik Aftandilian [:haik]]

I'm able to reproduce this on 10.11.6. Looking into it.

Comment 12

[Haik Aftandilian [:haik]]

(In reply to Mike Conley (:mconley) - Buried in needinfo / review backlog, eating my way out from comment #8)
> ni?ing bobowen since this sounds at least tangentially sandbox related due
> to comment 7?

This seem to be well explained in comment 147 <https://bugzilla.mozilla.org/show_bug.cgi?id=1338651#c147> on bug 1338651 :mshal referred to above in comment 4--at least if we know that launching the browser is causing all the object files to be opened, and those files have a path on /home, then that explains why opendirectoryd and automountd would spike. And it explains why sandboxd would be involved because those opens would cause sandbox violations. opendirectoryd/automountd spikes are easy to reproduce with something like

  $ while true ; do ls /home/foo ; done

I'll have to follow up on 1338651, but it's not clear to me if the fix will prevent us from opening all the Linux build paths, or just move those paths to a directory outside of /home. If they're just moved, we might need them to match what they would be on a real OS X install to avoid sandbox violations.

And it's not reliably reproducible for me. It was reproducible earlier today on 10.11.6 with a Jun22 Nightly build as well as the latest Jul21, but after coming back to work on this hours later, it is not reproducible. I have tried rebooting and using odutil to clear the opendirectory cache (which didn't seem to work).

I'm going to close this a duplicate of bug 1338651 because leaving it open seems to cause confusion. If others object, please re-open the bug.

Comment 14

[Aaron Kaluszka]

I am still seeing opendirectoryd/automountd go crazy with Firefox open in the Nightlies from the past two days (2017-07-29 and 2017-07-28) under macOS 10.13 Beta 4, but much less consistently -- whereas just running Firefox used to trigger it every time, now I'm not sure why it happens.

Comment 15

[danielwatson311]

I've also been seeing this on Nightlies I think since 57, currently with 57.0a1 (2017-08-08) (64-bit).
---
macOS: 10.12.4

Comment 16

[danielwatson311]

I haven't seen this happen since around when the Nightly icon switched to the red firebird.
---
macOS: 10.12.4
Firefox: 57.0a1 (2017-08-15) (64-bit)

Comment 17

[danielwatson311]

nevermind, it just happened again

Comment 18

[Haik Aftandilian [:haik]]

(In reply to danielwatson311 from comment #17)
> nevermind, it just happened again

Daniel, any chance you could retry with the latest Nightly? Bug 1338651 was the root cause of high opendirectoryd/automountd high CPU usage and that was recently fixed in build 57 Nightly.

If you can reproduce the problem, please make sure security.sandbox.logging=false in about:config. It's set to false by default, but that could explain explain the problem. Having the environment variable MOZ_SANDBOX_LOGGING set would also cause this problem.

Bug 1338651 was the root cause of high opendirectoryd/automountd high CPU usage which can be triggered by a few different things. Sandbox violations were triggering the problem at browser startup, but that was fixed by bug 1383841. You might have been hitting another issue caused by bug 1338651 that is now fixed.

If you can still reproduce it, please file a new bug.

Comment 19

[danielwatson311]

I've kept an eye on `top` for the past few days and I haven't seen opendirectoryd/automountd in the top ~10 since.