Created attachment 320808 [details] disable incredibly slow logging of sandbox violations Hello, after finally upgrading to Lion, I found that sandboxing using seatbelt got horribly slow. Upon further investigation I found lots of messages such as this in /var/log/system.log: Aug 9 17:24:47 dhcp-due-248 sandboxd[89060] ([4415]): bash(4415) deny file-write-data /dev/dtracehelper Aug 9 17:24:47 dhcp-due-248 sandboxd[89060] ([4415]): bash(4415) deny file-write-data /dev/tty Every single exec() seems to cause one set of these messages to be logged. After adjusting the sandboxing profile in pym/portage/const.py, as can be seen in the attached patch, performance went back to normal. Time of "emerge -1 portage": without patch: 44s with patch: 22s The patch does two things: 1. It allows access to /dev/tty and /dev/dtrachelper to silence these specific log messages and restore functionality possibly broken by denying access. The risk of /dev/tty and /dev/dtracehelper being corrupted by an ebuild seems negligible. 2. It disables logging of denies altogether. Ebuilds will most likely fail anyway if denied access to some path. This should restore behaviour as known from Leopard and Snow Leopard. The second patch attached adds a feature sandbox-debug that optionally re-enables logging of sandbox violations. Also attached is a corrected sandboxing patch for bootstrap-prefix.sh. The last patch, finally, removes some cruft left over from previous macossandbox patches in const.py. I'd greatly appreciate if these patches could be applied to prefix-portage. Maybe enabling sandboxing by default (as mentioned in http://git.overlays.gentoo.org/gitweb/?p=proj/portage.git;a=commit;h=df4a18b0) can be revisited with this patch applied. Thanks, Micha
Created attachment 320810 [details, diff] add an option to enable sandbox logging for debugging purposes
Created attachment 320812 [details, diff] add sandboxing to bootstrap prefix
Created attachment 320814 [details, diff] remove macossandbox cruft from const.py
(In reply to comment #0) > Time of "emerge -1 portage": > without patch: 44s > with patch: 22s Nice work!
http://prefix.gentooexperimental.org:8000/portage-prefix/rev/fdbb72747183 http://prefix.gentooexperimental.org:8000/portage-prefix/rev/d9be36d2df47 http://prefix.gentooexperimental.org:8000/portage-prefix/rev/6ba2223558ad applied I don't like your bootstrap-prefix.sh patch much, simply because it complicates the bootstrap environment further, which already is fragile in itself. It's a nice to have, but requires maintenance, and should only be used for a very small fraction of the entire lifetime of a Prefix, so not worth the investment, IMO.
(In reply to comment #0) > Time of "emerge -1 portage": > without patch: 44s > with patch: 22s On my system (Core i7 3.4GHz), with hot caches: Time of "emerge -1 portage" without seatbelt: 10s seatbelt/sandbox: 10s sandbox-debug: 10s I verified that it indeed seems to run sandbox-exec, although I never see it back in ps, so I'm wondering if it really runs. The overhead seems zero at this moment on Lion, which is nice, but hard to believe.
this is in 2.2.01.21165
Created attachment 325450 [details] small sandboxing test ebuild Thanks for applying the patches. I have this small ebuild for testing sandboxing. With sandbox and sandbox-debug it fails like this: >>> Install prefixtest-1.0 into /usr/local/gentoo/var/tmp/portage/sys-apps/prefixtest-1.0/image/ category sys-apps mkdir: cannot create directory ‘/direct’: Operation not permitted mkdir: cannot create directory ‘/usr/local/gentoo/direct’: Operation not permitted >>> Completed installing prefixtest-1.0 into /usr/local/gentoo/var/tmp/portage/sys-apps/prefixtest-1.0/image/ and seatbelt logs in system.log: Oct 1 09:43:20 box sandboxd[87048] ([87047]): mkdir(87047) deny file-write-create /direct Oct 1 09:43:20 box sandboxd[87048] ([87049]): mkdir(87049) deny file-write-create /usr/local/gentoo/direct So sandboxing works fine for me. I am also seeing no difference in execution time of emerge -1 portage (for me it's 26s for all three cases). But then I realized: Even with sandbox-debug enabled there is no slowdown because emerge -1 portage causes no violations and therefore no messages to be logged into system.log. A larger builds show the following behaviour: libxslt: no sandboxing: 46s sandbox: 48s sandbox-debug: 48s coreutils: no sandboxing: 2m12s sandbox: 2m14s sandbox-debug: 2m13s So it indeed seems that seatbelt does not cause any slowdown compared to unrestricted execution. Both ebuilds do not cause violation log messages either which explains the missing slowdown with sandbox-debug. Based on this, enabling sandbox on Mac OS X by default seems a real option to me. I agree that sandboxing the bootstrap is a bit of overkill. I'll keep the patch around just for my own paranoia then...
This is also on Lion, right? That means at least for Lion we can enable it (I like it). I'll have to test on my Leopard laptop to see if it is also working there, and without the overhead I've seen previously. The /dev/tty is most likely touched a lot, so would cause a lot of slowdowns. Maybe I've seen that in the past. If on Leopard it's fine now too, performance-wise, we enable it for all Darwin that have sandbox-exec. (10.5+?)
Yep, I'm on Lion. On (Snow) Leopard the slowdown shouldn't be due to slow logging because they're not logging by default (at least I never noticed). But perhaps even without logging, access violations are somehow expensive in older versions of seatbelt so that the two new rules might have a positive effect. Yes, seatbelt appeared in 10.5.
bad news, the code doesn't work on Leopard, because it dies with the message that (no-log) is an unbound variable
given the minimal overhead of the log thing (with the two added exceptions), perhaps we can just do away with it?
Performance with sandbox-debug on Leopard seems pretty much ok that this is ok to enable, though.
I just did an emerge -ateND world with sandbox-debug. After about 200 packages I haven't had a single log message. So, yeah, we might just leave logging on and drop the whole (no-log) thing. You decide. I see one possible snag: If at some future time for some reason a lot of violations occur, users might report performance degredation without an easily spottable reason. In such a case, we'd need to remember to ask them to have a look at their system.log. This could be aided by some message in emerge --info or to the console of a running emerge whenever a violation occurs. Unfortunately, normal users no longer have access to /var/log/system.log (this was new in 10.6, I think) and I have no idea how to intercept sandboxd messages before they're logged into system.log. Sadly, sandbox-exec has no option to make it log to stderr or suchlike either.
Yup, I think we have to take that "risk". In the end, if it slows down a lot, you (and now also me) will be noticing that, and probably decide what's best to do next.
FEATURES="sandbox" should be enabled by default now for 10.5+
