Something is filling up my system log files, to the point that console.app will only show the last half hour of each file. It looks like something is trying to escape its sandbox, but I'm not exactly sure what… I'm getting MANY repeated messages that look like:
Feb 3 00:29:57 Brians-mini sandboxd[16]: syslogd(15) deny file-read-data /private/var/log/asl/StoreData
Feb 3 00:29:57 Brians-mini sandboxd[16]: syslogd(15) deny mach-task-name
Feb 3 00:29:57 Brians-mini sandboxd[16]: syslogd(15) deny file-read-data /private/var/log/asl/StoreData
Feb 3 00:29:57 Brians-mini sandboxd[16]: syslogd(15) deny mach-task-name
Feb 3 00:29:59: --- last message repeated 1 time ---
Feb 3 00:29:57 Brians-mini sandboxd[16]: *** process 16 exceeded 500 log message per second limit - remaining messages this second discarded ***
Feb 3 00:29:57 Brians-mini sandboxd[16]: syslogd(15) deny mach-task-name
Feb 3 00:30:00: --- last message repeated 499 times ---
Feb 3 00:29:58 Brians-mini sandboxd[16]: *** process 16 exceeded 500 log message per second limit - remaining messages this second discarded ***
Feb 3 00:29:58 Brians-mini sandboxd[16]: syslogd(15) deny mach-task-name
Edit to add:
Activity monitor says that sandboxd is taking up 60% cpu, and syslogd is taking up 120%. Now, I assume that that's PER processor (I'm on a core 2 duo) But that's still an AWFUL lot of cpu for those two processes…
EDIT: var/log/asl as per request:
drwxr-xr-x 25 root wheel 850 Jan 6 06:41 ./
drwxr-xr-x 47 root wheel 1598 Feb 4 15:16 ../
-rw-r----- 1 root admin 11414 Jan 4 11:49 2010.01.04.U0.G80.asl
-rw------- 1 root wheel 874 Jan 4 09:41 2010.01.04.U0.asl
-rw------- 1 acordex wheel 43862 Jan 4 17:53 2010.01.04.U501.asl
-rw-r--r-- 1 root wheel 44614 Jan 4 23:42 2010.01.04.asl
-rw-r----- 1 root admin 10241494 Jan 5 16:53 2010.01.05.U0.G80.asl
-rw------- 1 acordex wheel 669585 Jan 5 18:11 2010.01.05.U501.asl
-rw-r--r-- 1 root wheel 772889 Jan 5 23:42 2010.01.05.asl
-rw-r----- 1 root admin 9731 Jan 6 18:54 2010.01.06.U0.G80.asl
-rw------- 1 acordex wheel 404532 Jan 6 18:50 2010.01.06.U501.asl
-rw-r--r-- 1 root wheel 838013 Jan 6 18:53 2010.01.06.asl
-rw-r----- 1 root admin 52896 Sep 24 18:20 BB.2010.09.30.U0.G80.asl
-rw-r--r-- 1 root wheel 50908 Sep 29 10:30 BB.2010.09.30.asl
-rw-r----- 1 root admin 58875 Oct 30 11:18 BB.2010.10.31.U0.G80.asl
-rw-r--r-- 1 root wheel 46188 Oct 30 17:41 BB.2010.10.31.asl
-rw-r----- 1 root admin 10322 Nov 5 18:21 BB.2010.11.29.U0.G80.asl
-rw-r--r-- 1 root wheel 2159 Nov 4 17:21 BB.2010.11.29.asl
-rw-r----- 1 root admin 6586 Nov 9 14:06 BB.2010.11.30.U0.G80.asl
-rw-r--r-- 1 root wheel 23147 Nov 25 16:36 BB.2010.11.30.asl
-rw-r----- 1 root admin 21686 Dec 16 19:06 BB.2010.12.31.U0.G80.asl
-rw-r--r-- 1 root wheel 36951 Dec 23 18:32 BB.2010.12.31.asl
-rw-r--r-- 1 root wheel 2584 Jan 6 16:49 BB.2011.01.31.asl
-rw-r--r-- 1 root wheel 12 Jan 6 18:54 StoreData
-rw-r--r-- 1 root wheel 8 Jan 6 16:59 SweepStore
Best Answer
Looks to me like it's
syslogd
itself causing the problem -- it's been sandboxed away from its data files, so when it tries to access them it generates a sandbox error, which gets handed tosyslogd
, which triggers it to try to get at its files again... and this repeats as fast assyslogd
andsandboxd
can go.Check the contents of
/System/Library/LaunchDaemons/com.apple.syslogd.plist
(the launchd item that controls how syslogd is launched). It should have a section like this:Note that in the above example (taken from my Mac), the sandbox wrapper around syslogd is commented out. Is the same true on your Mac? If not, re-add the comment markers, and restart
syslogd
(you can do this withlaunchctl
, but I'd just reboot the machine).Another note: I took a look in the sandbox profile,
/usr/share/sandbox/syslogd.sb
, and it looks (to my inexpert eyes) like it does denymach-task-name
and access to/private/var/log/asl/StoreData
-- apparently, Apple hasn't debugged (/updated) the profile to match whatsyslogd
actually needs...